Performance issue on huge dashboard (bottleneck not in source)

[timka-s]

IDLE - 4 cpu (free 99%), 16 gb (free 12gb)

commit a0de726a471d8662f9841d8c8768c1ef2a31ddb8 (HEAD -> main, tag: v1.9.0, origin/main, origin/HEAD)
Author: github-actions[bot] <41898282+github-actions[bot]@users.noreply.github.com>
Date:   Thu Aug 15 12:48:37 2024 +0300

    Release DataLens v1.9.0 (#184)

Very slowly (2-3 seconds) interaction between data-api and us, when opened huge dashboard with many selectors and charts
When I open a single chart view - interaction takes 0.1 - 0.3 seconds

Dockets stats after opening the dashboard

CONTAINER ID   NAME                          CPU %     MEM USAGE / LIMIT     MEM %     NET I/O           BLOCK I/O         PIDS
be4216c996e2   datalens-ui                   2.14%     503MiB / 15.62GiB     3.14%     44.4GB / 40.1GB   6.63MB / 471MB    17
dbad662175c1   datalens-data-api             341.74%   1.203GiB / 15.62GiB   7.70%     21.7GB / 31.9GB   142MB / 0B        88
63fdef7156f9   datalens-control-api          0.00%     934.2MiB / 15.62GiB   5.84%     7.51GB / 3.68GB   99MB / 0B         17
f11668141432   datalens-us                   29.40%    134.1MiB / 15.62GiB   0.84%     129GB / 14.3GB    25.9MB / 32.8kB   17
6caf303d8b4c   datalens-pg-us                11.98%    86.25MiB / 15.62GiB   0.54%     2.74GB / 128GB    13.1MB / 10.2GB   12
93516adcee45   datalens-pg-demo-connection   0.00%     22.47MiB / 15.62GiB   0.14%     489kB / 213kB     13MB / 4.04GB     7
b237f25be7b7   datalens-pg-compeng           0.00%     23.36MiB / 15.62GiB   0.15%     199MB / 82.6MB    3.71MB / 7.31GB   7
92313952a237   node-exporter                 3.26%     29.02MiB / 15.62GiB   0.18%     0B / 0B           5.07MB / 0B       32
8c42248ededc   consul-agent                  0.12%     53.07MiB / 15.62GiB   0.33%     0B / 0B           17MB / 1.11GB     12

Data-api log:

1728480240.6345317 Received request. method: GET, path: /api/data/v1/datasets/1wygq55d1j6wo/fields, headers: {...}, pid: 185227
1728480240.69302 Setting service USM as user USM
1728480240.693407 Asking UnitedStorage: method: get, url: /entries/1wygq55d1j6wo, params:({'includePermissionsInfo': 1, 'includeLinks': 1})
1728480242.3229325 Profiling results: us-client-request in 1.6293s
1728480242.3231127 Got 200 from UnitedStorage (get /entries/1wygq55d1j6wo), content length: 345121, request-id: dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028, elapsed: 1.6294822692871094
1728480242.5296807 Profiling results: us-fetch-entity in 1.8363s
1728480242.5300138 Asking UnitedStorage: method: get, url: /entries/a57pzee7becex, params:({'includePermissionsInfo': 1, 'includeLinks': 1})
1728480245.0983663 Profiling results: us-client-request in 2.5682s
1728480245.098527 Got 200 from UnitedStorage (get /entries/a57pzee7becex), content length: 1100, request-id: dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028, elapsed: 2.5683499574661255
1728480245.0993426 Profiling results: us-fetch-entity in 2.5693s
1728480245.2399743 Response. method: GET, path: /api/data/v1/datasets/1wygq55d1j6wo/fields, status: 200

But, in UC log we can see very fast (30ms) response

1728480241562 [Express GET] Request started [dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028]
1728480241563 [Express GET] [resolveSpecialTokens middleware] PRIVATE_API_CALL [dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028]
1728480241563 [Express GET] [resolveSpecialTokens middleware] PRIVATE_API_CALL_AUTHORIZED [dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028]
1728480241563 [Express GET] [getEntry] GET_ENTRY_REQUEST [dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028]
1728480241583 [Express GET] [getEntry] GET_ENTRY_SUCCESS [dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028]
1728480241590 [Express GET] Request completed [dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028]

941 ms later:

1728480242531 [Express GET] Request started [dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028]
1728480242532 [Express GET] [resolveSpecialTokens middleware] PRIVATE_API_CALL [dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028]
1728480242532 [Express GET] [resolveSpecialTokens middleware] PRIVATE_API_CALL_AUTHORIZED [dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028]
1728480242532 [Express GET] [getEntry] GET_ENTRY_REQUEST [dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028]
1728480242534 [Express GET] [getEntry] GET_ENTRY_SUCCESS [dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028]
1728480242535 [Express GET] Request completed [dl.0729e_ck.ipaiv8knsg--y.95f31699781d45d080416b5bd758f028]

[goshander]

@timka-s hi, thank you for detailed issue. Can you check performance with increased postgres connections pool to zitadel?

PR with fix already merged
#227