Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

UI hangs sporadically #2404

Closed
Tracked by #2323
tpurschke opened this issue May 7, 2024 · 4 comments
Closed
Tracked by #2323

UI hangs sporadically #2404

tpurschke opened this issue May 7, 2024 · 4 comments
Labels
bug Something isn't working not reproducible

Comments

@tpurschke
Copy link
Contributor

tpurschke commented May 7, 2024 •
edited
Loading

sporadically, when entering the settings modelling page, the system hangs for several minutes (7:58-8:16) and in the log we constantly (78231 lines) get "2024-02-16T08:05:28.798433+01:00 lxma635 fworch-ui: 2024-02-16T08:05:28+01:00 Debug - Load Global Config Items" followed by a single "2024-02-16T08:05:28.955576+01:00 lxma635 fworch-ui: 2024-02-16T08:05:28+01:00 Debug - API call (GraphQlApiConnection.cs in line 122), Sending API call : query getStates { state_list: request_state (or..." and then the page is rendered correctly. Could this be a schedule job running in the background blocking the UI? This is probably related to a config value change just before which caused all the schedulers to start at the same time.

Latest occurrences (as admin user on fwodemo.cactus.de):

now also switching to monitoring page causes UI to hang for several minutes:

2024-05-07T09:23:43.022386+02:00 fwodemo fworch-ui:  Exception thrown:
2024-05-07T09:23:43.022401+02:00 fwodemo fworch-ui:   Exception
2024-05-07T09:23:43.022414+02:00 fwodemo fworch-ui:  Message:
2024-05-07T09:23:43.022426+02:00 fwodemo fworch-ui:   field 'import_credential' not found in type: 'management'
2024-05-07T09:23:43.022439+02:00 fwodemo fworch-ui:   
2024-05-07T09:23:43.022452+02:00 fwodemo fworch-ui:  Stack Trace:
2024-05-07T09:23:43.022491+02:00 fwodemo fworch-ui:   at FWO.Api.Client.GraphQlApiConnection.SendQueryAsync[QueryResponseType](String query, Object variables, String operationName) in /usr/local/fworch/lib/files/FWO.Api.Client/GraphQlApiConnection.cs:line 142
2024-05-07T09:23:43.022507+02:00 fwodemo fworch-ui:     at FWO.Ui.Pages.Monitoring.MonitoringMain.OnInitializedAsync() in /usr/local/fworch/ui/files/FWO.UI/Pages/Monitoring/MonitoringMain.razor:line 129
2024-05-07T09:23:43.022941+02:00 fwodemo fworch-ui:  FWORCHAlert - source: "ui", userId: "3", title: "Unspecified Error", description: "Unclassified error: : field 'import_credential' not found in type: 'management'
2024-05-07T09:23:43.022975+02:00 fwodemo fworch-ui:   . See log for details!", alertCode: "UiError"

Revived by browser reload:

==> api.log <==
2024-05-07T09:26:20+02:00 localhost fworch-api:  {"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"GET","status":200,"url":"/healthz"},"operation":{"query":{"type":null},"request_id":"64015aff-e636-4c03-9181-ee8b9dfb5c90","request_mode":"non-graphql","response_size":2,"uncompressed_response_size":2},"request_id":"64015aff-e636-4c03-9181-ee8b9dfb5c90"},"level":"info","timestamp":"2024-05-07T07:26:19.952+0000","type":"http-log"}
2024-05-07T09:26:20.678324+02:00 fwodemo fworch-api:  {"detail":{"http_info":{"content_encoding":null,"http_version":"HTTP/1.1","ip":"127.0.0.1","method":"GET","status":200,"url":"/healthz"},"operation":{"query":{"type":null},"request_id":"64015aff-e636-4c03-9181-ee8b9dfb5c90","request_mode":"non-graphql","response_size":2,"uncompressed_response_size":2},"request_id":"64015aff-e636-4c03-9181-ee8b9dfb5c90"},"level":"info","timestamp":"2024-05-07T07:26:19.952+0000","type":"http-log"}
2024-05-07T09:26:33+02:00 localhost fworch-api:  {"detail":{"num_cron_events_fetched":0,"num_fetches":60,"num_one_off_scheduled_events_fetched":0},"level":"info","timestamp":"2024-05-07T07:26:32.959+0000","type":"scheduled-trigger-process"}
2024-05-07T09:26:33.807706+02:00 fwodemo fworch-api:  {"detail":{"num_cron_events_fetched":0,"num_fetches":60,"num_one_off_scheduled_events_fetched":0},"level":"info","timestamp":"2024-05-07T07:26:32.959+0000","type":"scheduled-trigger-process"}

==> ui.log <==
2024-05-07T09:26:46.859792+02:00 fwodemo fworch-ui:  2024-05-07T09:26:46+02:00 Audit - Session of "admin" closed (CircuitHandlerService.cs in line 20), Session of user "admin" (last logged in) with DN: "uid=admin,ou=tenant0,ou=operator,ou=user,dc=fworch,dc=internal" was closed.

==> audit.log <==
2024-05-07T09:26:46.859792+02:00 fwodemo fworch-ui:  2024-05-07T09:26:46+02:00 Audit - Session of "admin" closed (CircuitHandlerService.cs in line 20), Session of user "admin" (last logged in) with DN: "uid=admin,ou=tenant0,ou=operator,ou=user,dc=fworch,dc=internal" was closed.

==> api.log <==
2024-05-07T09:26:46+02:00 localhost fworch-api:  {"detail":{"connection_info":{"msg":null,"token_expiry":"2024-05-07T18:25:59Z","websocket_id":"c81f9613-daf6-4386-a961-5b8093feac8d"},"event":{"type":"closed"},"user_vars":{"x-hasura-editable-owners":"{ 0 }","x-hasura-role":"admin","x-hasura-tenant-id":"1","x-hasura-user-id":"3","x-hasura-uuid":"uid=admin,ou=tenant0,ou=operator,ou=user,dc=fworch,dc=internal","x-hasura-visible-devices":"{ 1,2 }","x-hasura-visible-managements":"{ 2,1 }"}},"level":"info","timestamp":"2024-05-07T07:26:45.970+0000","type":"websocket-log"}
  • Defaults - set language to German
  • switched to settings modelling - page hangs for 1-2 min and the following errors can be seen:
UI Error: Read Config - Error reading Config for default language: taking default English . See log for details!

==> ui.log <==
2024-05-07T08:47:49.622966+02:00 fwodemo fworch-ui:  2024-05-07T08:47:49+02:00 Error - API Connection (GraphQlApiConnection.cs in line 138), Error while sending query to GraphQL API. Caught by GraphQL client library.
2024-05-07T08:47:49.622999+02:00 fwodemo fworch-ui:  Message: field 'modelling_nwgroup' not found in type: 'query_root'
2024-05-07T08:47:49.623054+02:00 fwodemo fworch-ui:  2024-05-07T08:47:49+02:00 Error - API Connection (GraphQlApiConnection.cs in line 173), Error while sending query to GraphQL API. Query: query getNwGroupObjects ($grpType: Int!){
2024-05-07T08:47:49.623104+02:00 fwodemo fworch-ui:    modelling_nwgroup (where: { group_type: { _eq: $grpType }, is_deleted: { _eq: false } } order_by: { name: asc }){
2024-05-07T08:47:49.623170+02:00 fwodemo fworch-ui:      id
2024-05-07T08:47:49.623227+02:00 fwodemo fworch-ui:      name
2024-05-07T08:47:49.623246+02:00 fwodemo fworch-ui:      id_string
2024-05-07T08:47:49.623277+02:00 fwodemo fworch-ui:      app_id
2024-05-07T08:47:49.623326+02:00 fwodemo fworch-ui:      group_type
2024-05-07T08:47:49.623374+02:00 fwodemo fworch-ui:    }
2024-05-07T08:47:49.623408+02:00 fwodemo fworch-ui:  }
2024-05-07T08:47:49.623422+02:00 fwodemo fworch-ui:  , variables: {"grpType":23}
2024-05-07T08:47:49.623452+02:00 fwodemo fworch-ui:   ---
2024-05-07T08:47:49.623499+02:00 fwodemo fworch-ui:  Exception thrown:
2024-05-07T08:47:49.623543+02:00 fwodemo fworch-ui:   Exception
2024-05-07T08:47:49.623577+02:00 fwodemo fworch-ui:  Message:
2024-05-07T08:47:49.623597+02:00 fwodemo fworch-ui:   field 'modelling_nwgroup' not found in type: 'query_root'
2024-05-07T08:47:49.623632+02:00 fwodemo fworch-ui:   
2024-05-07T08:47:49.623649+02:00 fwodemo fworch-ui:  Stack Trace:
2024-05-07T08:47:49.623698+02:00 fwodemo fworch-ui:   at FWO.Api.Client.GraphQlApiConnection.SendQueryAsync[QueryResponseType](String query, Object variables, String operationName) in /usr/local/fworch/lib/files/FWO.Api.Client/GraphQlApiConnection.cs:line 142
2024-05-07T08:47:49.623753+02:00 fwodemo fworch-ui:  2024-05-07T08:47:49+02:00 Error - Read Config (MainLayout.razor in line 311), User: admin, Role: admin, Error reading Config for default language: taking default English
2024-05-07T08:47:49.623826+02:00 fwodemo fworch-ui:   ---
2024-05-07T08:47:49.623842+02:00 fwodemo fworch-ui:  Exception thrown:
2024-05-07T08:47:49.623856+02:00 fwodemo fworch-ui:   Exception
2024-05-07T08:47:49.623975+02:00 fwodemo fworch-ui:  Message:
2024-05-07T08:47:49.623996+02:00 fwodemo fworch-ui:   field 'modelling_nwgroup' not found in type: 'query_root'
2024-05-07T08:47:49.624028+02:00 fwodemo fworch-ui:   
2024-05-07T08:47:49.624075+02:00 fwodemo fworch-ui:  Stack Trace:
2024-05-07T08:47:49.624090+02:00 fwodemo fworch-ui:   at FWO.Api.Client.GraphQlApiConnection.SendQueryAsync[QueryResponseType](String query, Object variables, String operationName) in /usr/local/fworch/lib/files/FWO.Api.Client/GraphQlApiConnection.cs:line 142
2024-05-07T08:47:49.624297+02:00 fwodemo fworch-ui:     at FWO.Ui.Pages.Settings.SettingsModelling.OnInitializedAsync() in /usr/local/fworch/ui/files/FWO.UI/Pages/Settings/SettingsModelling.razor:line 276
2024-05-07T08:47:49.625727+02:00 fwodemo fworch-ui:  FWORCHAlert - source: "ui", userId: "3", title: "Read Config", description: "Error reading Config for default language: taking default English . See log for details!", alertCode: "UiError"

==> alert.log <==
2024-05-07T08:47:49.625727+02:00 fwodemo fworch-ui:  FWORCHAlert - source: "ui", userId: "3", title: "Read Config", description: "Error reading Config for default language: taking default English . See log for details!", alertCode: "UiError"
@tpurschke tpurschke mentioned this issue May 7, 2024
Closed
46 tasks
@tpurschke tpurschke changed the title sporadically, when entering the settings modelling page, the system hangs for several minutes (7:58-8:16) and in the log we constantly (78231 lines) get "2024-02-16T08:05:28.798433+01:00 lxma635 fworch-ui: 2024-02-16T08:05:28+01:00 Debug - Load Global Config Items" followed by a single "2024-02-16T08:05:28.955576+01:00 lxma635 fworch-ui: 2024-02-16T08:05:28+01:00 Debug - API call (GraphQlApiConnection.cs in line 122), Sending API call : query getStates { state_list: request_state (or..." and then the page is rendered correctly. Could this be a schedule job running in the background blocking the UI? This is probably related to a config value change just before which caused all the schedulers to start at the same time. settings modelling hangs sporadically May 7, 2024
@tpurschke tpurschke changed the title settings modelling hangs sporadically UI hangs sporadically May 7, 2024
@tpurschke tpurschke added the bug Something isn't working label Jun 13, 2024
@tpurschke
Copy link
Contributor Author

related to #2450 ?

@tpurschke tpurschke mentioned this issue Jun 17, 2024
Open
@tpurschke
Copy link
Contributor Author

Debug output looking better after v8.3 PR @abarz722 and also could not reproduce issue at first try:

1305 apps, 11 failed. Deactivated 0 apps, 0 failed

@tpurschke
Copy link
Contributor Author

tpurschke commented Jun 28, 2024 •
edited
Loading

we were able to narrow the issue down (still exists with latest PR #2467):

  • issue seems to be a pure UI issue - >4096 userConfigs are created which all need to be updated.
  • when updating more than one config value in parallel it takes longer and longer before the UI becomes responsive
  • this is probably due to the fact that we update config values via API separately (but still does not explain the massive number of configs)
  • The problem with debugging this is that after a fresh start of the server (here install) we cannot reproduce the error.
    We normally only have 3 subscribers for the GlobalConfig, Plus 2 subscribers (nav layout, settings layout).
  • each reload of a UI session in a browser creates 2 more subscriptions - why 2?
  • could network connection issues cause multiple subscriptions?
  • these stale subscriptions should be cleaned up: OnCircuitCloseAsync and OnConnectionDownAsync should both dispose of the subscriptions

@tpurschke
Copy link
Contributor Author

Seems to be fixed now.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working not reproducible
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@tpurschke