vaadin / flow

Vaadin Flow is a Java framework binding Vaadin web components to Java. This is part of Vaadin 10+.
Apache License 2.0
619 stars 167 forks source link

UI freezes with client error (similar but different to #7399) #7553

Closed Kivinaama closed 4 years ago

Kivinaama commented 4 years ago

We had issue #7399 After taking 14.1.17 with Flow 2.1.5 into use, the case where 7399 manifested now sometimes still ends up with a client-side error (Assertion error: undefined) and UI becomes non-responsive.

We have MPR but 7399 and this issue manifested with pure Flow views as well.

Client-side: image

Server-side: Resynchronizing UI by client's request. Under normal operations this should not happen and may indicate a bug in Vaadin platform. If you see this message regularly please open a bug report at

This indicates that the fix for 7399 works as it notices the out-of-synch and starts to resynchronize.

-- Same as in 7399 I can reproduce this easier if:

-- Suggestion: as 7399 and this are a result of messaging getting out of synch, would it make sense to try to find the root cause for that?

johannest commented 4 years ago

When running with flow-client-2.1.5 with DETAILED widgetset compilation, there are some more details in the assertion error.

This seems to happen more easily when running the application with super slow network (e.g. HEARTBEAT request taking ~40s) got the error below when filtering a combobox and the Heartbeat request happened about the same time

Postponing UIDL handling due to lock...
client-3C59107ECE567…334A.cache.js:10227 Scheduling heartbeat in 60 seconds
client-3C59107ECE567…334A.cache.js:10235 Sending xhr message to server: {"csrfToken":"61189fed-30bf-4bb4-adea-e907e6df945c","rpc":[{"type":"navigation","location":"overview","state":{"historyIndex":4,"historyResetToken":1581515949428}},{"type":"publishedEventHandler","node":145,"templateEventMethodName":"setRequestedRange","templateEventMethodArgs":[0,50,""]},{"type":"mSync","node":145,"feature":1,"property":"opened","value":true},{"type":"mSync","node":145,"feature":1,"property":"filter","value":"hsy"},{"type":"publishedEventHandler","node":145,"templateEventMethodName":"setRequestedRange","templateEventMethodArgs":[0,50,"hsy"]}],"syncId":13,"clientId":11}
client-3C59107ECE567…7334A.cache.js:5080 WARNING: reponse handling was never resumed, forcibly removing locks...
client-3C59107ECE567…7334A.cache.js:5132 Handling message from server
client-3C59107ECE567…7334A.cache.js:5095 Handling dependencies
client-3C59107ECE567…334A.cache.js:10235 Server visit took 190.225ms
client-3C59107ECE567…334A.cache.js:10235 JSON parsing took 0.635ms
client-3C59107ECE567…334A.cache.js:10235 Received xhr message: for(;;);[{"syncId":15,"clientId":12,"changes":[{"node":73,"type":"put","key":"visible","feat":0,"value":true},{"node":146,"type":"clear","feat":2},{"node":146,"type":"put","key":"innerHTML","feat":1,"value":"Overview"},{"node":70,"type":"splice","feat":2,"index":0,"remove":1},{"node":70,"type":"splice","feat":2,"index":0,"addNodes":[69]},{"node":305,"type":"detach"},{"node":338,"type":"detach"},{"node":339,"type":"detach"},{"node":306,"type":"detach"},{"node":307,"type":"detach"},{"node":308,"type":"detach"},{"node":309,"type":"detach"},{"node":310,"type":"detach"},{"node":311,"type":"detach"},{"node":312,"type":"detach"},{"node":313,"type":"detach"},{"node":314,"type":"detach"},{"node":315,"type":"detach"},{"node":316,"type":"detach"},{"node":317,"type":"detach"},{"node":318,"type":"detach"},{"node":319,"type":"detach"},{"node":320,"type":"detach"},{"node":321,"type":"detach"},{"node":322,"type":"detach"},{"node":323,"type":"detach"},{"node":324,"type":"detach"},{"node":325,"type":"detach"},{"node":326,"type":"detach"},{"node":327,"type":"detach"},{"node":328,"type":"detach"},{"node":329,"type":"detach"},{"node":330,"type":"detach"},{"node":331,"type":"detach"},{"node":332,"type":"detach"},{"node":333,"type":"detach"},{"node":334,"type":"detach"},{"node":335,"type":"detach"},{"node":336,"type":"detach"},{"node":337,"type":"detach"},{"node":41,"type":"attach"},{"node":41,"type":"put","key":"tag","feat":0,"value":"div"},{"node":41,"type":"empty","featType":true,"feat":19},{"node":41,"type":"splice","feat":11,"index":0,"add":["abstract-view__footer"]},{"node":42,"type":"attach"},{"node":42,"type":"put","key":"tag","feat":0,"value":"div"},{"node":42,"type":"empty","featType":true,"feat":19},{"node":42,"type":"splice","feat":11,"index":0,"add":["overview__map-wrapper","v-app","xxx"]},{"node":42,"type":"put","key":"display","feat":12,"value":"inline-block"},{"node":42,"type":"put","key":"width","feat":12,"value":"100%"},{"node":42,"type":"put","key":"height","feat":12,"value":"100%"},{"node":43,"type":"attach"},{"node":44,"type":"attach"},{"node":45,"type":"attach"},{"node":46,"type":"attach"},{"node":47,"type":"attach"},{"node":47,"type":"put","key":"visible","feat":0,"value":false},{"node":47,"type":"put","key":"tag","feat":0,"value":"vaadin-vertical-layout"},{"node":48,"type":"attach"},{"node":48,"type":"put","key":"tag","feat":0,"value":"iron-icon"},{"node":48,"type":"empty","featType":true,"feat":19},{"node":48,"type":"put","key":"icon","feat":3,"value":"xxx:filter"},{"node":48,"type":"put","key":"slot","feat":3,"value":"prefix"},{"node":49,"type":"attach"},{"node":49,"type":"put","key":"text","feat":7,"value":"Filter"},{"node":50,"type":"attach"},{"node":50,"type":"put","key":"tag","feat":0,"value":"vaadin-button"},{"node":50,"type":"splice","feat":2,"index":0,"addNodes":[49,48]},{"node":50,"type":"empty","featType":true,"feat":19},{"node":50,"type":"splice","feat":11,"index":0,"add":["expandable-filter__toggle","hide-button-label-mobile"]},{"node":50,"type":"put","key":"theme","feat":3,"value":"tertiary"},{"node":50,"type":"put","key":"click","feat":4,"value":"F8oCtNArLiI="},{"node":51,"type":"attach"},{"node":51,"type":"put","key":"tag","feat":0,"value":"div"},{"node":51,"type":"empty","featType":true,"feat":19},{"node":51,"type":"splice","feat":11,"index":0,"add":["margin-a-s"]},{"node":51,"type":"put","key":"background-color","feat":12,"value":"var(--lumo-contrast-20pct)"},{"node":51,"type":"put","key":"align-self","feat":12,"value":"stretch"},{"node":51,"type":"put","key":"flex","feat":12,"value":"0 0 1px"},{"node":52,"type":"attach"},{"node":52,"type":"put","key":"tag","feat":0,"value":"div"},{"node":52,"type":"splice","feat":2,"index":0,"addNodes":[51]},{"node":52,"type":"empty","featType":true,"feat":19},{"node":52,"type":"splice","feat":11,"index":0,"add":["divider"]},{"node":52,"type":"put","key":"align-self","feat":12,"value":"stretch"},{"node":52,"type":"put","key":"flex-direction","feat":12,"value":"inherit"},{"node":52,"type":"put","key":"display","feat":12,"value":"flex"},{"node":53,"type":"attach"},{"node":53,"type":"put","key":"tag","feat":0,"value":"iron-icon"},{"node":53,"type":"empty","featType":true,"feat":19},{"node":53,"type":"put","key":"icon","feat":3,"value":"xxx:map-marker-solid"},{"node":53,"type":"put","key":"slot","feat":3,"value":"prefix"},{"node":54,"type":"attach"},{"node":54,"type":"put","key":"tag","feat":0,"value":"vaadin-button"},{"node":54,"type":"splice","feat":2,"index":0,"addNodes":[53]},{"node":54,"type":"empty","featType":true,"feat":19},{"node":54,"type":"splice","feat":11,"index":0,"add":["icon-blue"]},{"node":54,"type":"put","key":"theme","feat":3,"value":"icon tertiary"},{"node":54,"type":"put","key":"click","feat":4,"value":"F8oCtNArLiI="},{"node":55,"type":"attach"},{"node":55,"type":"put","key":"tag","feat":0,"value":"iron-icon"},{"node":55,"type":"empty","featType":true,"feat":19},{"node":55,"type":"put","key":"icon","feat":3
client-3C59107ECE567…7334A.cache.js:5115 Postponing UIDL handling due to lock...
client-3C59107ECE567…7334A.cache.js:5080 WARNING: reponse handling was never resumed, forcibly removing locks...
client-3C59107ECE567…7334A.cache.js:5132 Handling message from server
client-3C59107ECE567…7334A.cache.js:5095 Handling dependencies
client-3C59107ECE567…334A.cache.js:10235 Sending xhr message to server: {"csrfToken":"61189fed-30bf-4bb4-adea-e907e6df945c","rpc":[{"type":"mSync","node":145,"feature":1,"property":"filter","value":""},{"type":"mSync","node":145,"feature":1,"property":"opened","value":false}],"syncId":15,"clientId":12}
client-3C59107ECE567…7334A.cache.js:4934 Sending heartbeat request...
client-3C59107ECE567…334A.cache.js:10193 GET https://xxx/frontend/gridConnector.js net::ERR_CONNECTION_RESET 200
client-3C59107ECE567…334A.cache.js:10231 Error loading https://xxx/frontend/gridConnector.js
client-3C59107ECE567…334A.cache.js:10231 'https://xxx/frontend/gridConnector.js' could not be loaded.
client-3C59107ECE567…334A.cache.js:10235 Loaded https://xxx/frontend/noscroll-grid.js
client-3C59107ECE567…334A.cache.js:10231 Assertion error: undefined
elemental_js_html_JsConsole_$error__Lelemental_js_html_JsConsole_2Ljava_lang_Object_2V  @   client-3C59107ECE567…334A.cache.js:10231
com_vaadin_client_SystemErrorHandler_$handleError__Lcom_vaadin_client_SystemErrorHandler_2Ljava_lang_String_2Ljava_lang_String_2Ljava_lang_String_2Lelemental_dom_Element_2 @   client-3C59107ECE567…7334A.cache.js:3785
com_vaadin_client_SystemErrorHandler_$handleError__Lcom_vaadin_client_SystemErrorHandler_2Ljava_lang_String_2V  @   client-3C59107ECE567…7334A.cache.js:3764
com_vaadin_client_SystemErrorHandler_$handleError__Lcom_vaadin_client_SystemErrorHandler_2Ljava_lang_Throwable_2V   @   client-3C59107ECE567…7334A.cache.js:3799
com_vaadin_client_ApplicationConnection$0methodref$handleError$Type_onUncaughtException__Ljava_lang_Throwable_2V    @   client-3C59107ECE567…7334A.cache.js:1791
com_google_gwt_core_client_impl_Impl_reportUncaughtException__Ljava_lang_Throwable_2ZV  @   client-3C59107ECE567…7334A.cache.js:1050
com_google_gwt_core_client_impl_Impl_entry0__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2   @   client-3C59107ECE567…57334A.cache.js:961
(anonymous) @   client-3C59107ECE567…57334A.cache.js:943
load (async)        
com_vaadin_client_ResourceLoader_addOnloadHandler__Lelemental_dom_Element_2Lcom_vaadin_client_ResourceLoader$ResourceLoadListener_2Lcom_vaadin_client_ResourceLoader$ResourceLoadEvent_2V   @   client-3C59107ECE567…7334A.cache.js:3485
com_vaadin_client_ResourceLoader_$loadScript__Lcom_vaadin_client_ResourceLoader_2Ljava_lang_String_2Lcom_vaadin_client_ResourceLoader$ResourceLoadListener_2ZZLjava_lang_String_2V  @   client-3C59107ECE567…7334A.cache.js:3421
com_vaadin_client_DependencyLoader$lambda$3$Type_accept__Ljava_lang_Object_2Ljava_lang_Object_2V    @   client-3C59107ECE567…7334A.cache.js:2387
com_vaadin_client_DependencyLoader_$loadDependencyEagerly__Lcom_vaadin_client_DependencyLoader_2Ljava_lang_String_2Ljava_util_function_BiConsumer_2V    @   client-3C59107ECE567…7334A.cache.js:2220
com_vaadin_client_DependencyLoader_$extractLazyDependenciesAndLoadOthers__Lcom_vaadin_client_DependencyLoader_2Lcom_vaadin_flow_shared_ui_LoadMode_2Lelemental_json_JsonArray_2Lcom_vaadin_client_flow_collection_JsMap_2   @   client-3C59107ECE567…7334A.cache.js:2148
com_vaadin_client_DependencyLoader_$lambda$0__Lcom_vaadin_client_DependencyLoader_2Lcom_vaadin_client_flow_collection_JsMap_2Lelemental_json_JsonArray_2Lcom_vaadin_flow_shared_ui_LoadMode_2V  @   client-3C59107ECE567…7334A.cache.js:2199
com_vaadin_client_DependencyLoader$lambda$0$Type_accept__Ljava_lang_Object_2Ljava_lang_Object_2V    @   client-3C59107ECE567…7334A.cache.js:2356
lambda  @   client-3C59107ECE567…57334A.cache.js:330
com_vaadin_client_DependencyLoader_$loadDependencies__Lcom_vaadin_client_DependencyLoader_2Lcom_vaadin_client_flow_collection_JsMap_2V  @   client-3C59107ECE567…7334A.cache.js:2214
com_vaadin_client_communication_MessageHandler_$handleDependencies__Lcom_vaadin_client_communication_MessageHandler_2Lelemental_json_JsonObject_2V  @   client-3C59107ECE567…7334A.cache.js:5101
com_vaadin_client_communication_MessageHandler_$handleJSON__Lcom_vaadin_client_communication_MessageHandler_2Lcom_vaadin_client_ValueMap_2V @   client-3C59107ECE567…7334A.cache.js:5147
com_vaadin_client_communication_MessageHandler_$handleMessage__Lcom_vaadin_client_communication_MessageHandler_2Lcom_vaadin_client_ValueMap_2V  @   client-3C59107ECE567…7334A.cache.js:5168
com_vaadin_client_communication_XhrConnection$XhrResponseHandler_onSuccess__Lcom_google_gwt_xhr_client_XMLHttpRequest_2V    @   client-3C59107ECE567…7334A.cache.js:6108
com_vaadin_client_gwt_elemental_js_util_Xhr$Handler_onReadyStateChange__Lcom_google_gwt_xhr_client_XMLHttpRequest_2V    @   client-3C59107ECE567…7334A.cache.js:9734
(anonymous) @   client-3C59107ECE567…7334A.cache.js:1583
com_google_gwt_core_client_impl_Impl_apply__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2    @   client-3C59107ECE567…57334A.cache.js:916
com_google_gwt_core_client_impl_Impl_entry0__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2   @   client-3C59107ECE567…57334A.cache.js:955
(anonymous) @   client-3C59107ECE567…57334A.cache.js:943
XMLHttpRequest.send (async)     
com_vaadin_client_gwt_elemental_js_util_Xhr_request__Lcom_google_gwt_xhr_client_XMLHttpRequest_2Ljava_lang_String_2Ljava_lang_String_2Ljava_lang_String_2Ljava_lang_String_2Lcom_vaadin_client_gwt_elemental_js_util_Xhr$Callback_2Lcom_google_gwt_xhr_client_XMLHttpRequest_2  @   client-3C59107ECE567…7334A.cache.js:9710
com_vaadin_client_gwt_elemental_js_util_Xhr_post__Ljava_lang_String_2Ljava_lang_String_2Ljava_lang_String_2Lcom_vaadin_client_gwt_elemental_js_util_Xhr$Callback_2Lcom_google_gwt_xhr_client_XMLHttpRequest_2   @   client-3C59107ECE567…7334A.cache.js:9700
com_vaadin_client_communication_XhrConnection_$send__Lcom_vaadin_client_communication_XhrConnection_2Lelemental_json_JsonObject_2V  @   client-3C59107ECE567…7334A.cache.js:6037
com_vaadin_client_communication_MessageSender_$send__Lcom_vaadin_client_communication_MessageSender_2Lelemental_json_JsonArray_2Lelemental_json_JsonObject_2V   @   client-3C59107ECE567…7334A.cache.js:5537
com_vaadin_client_communication_MessageSender_$doSendInvocationsToServer__Lcom_vaadin_client_communication_MessageSender_2V @   client-3C59107ECE567…7334A.cache.js:5504
com_vaadin_client_communication_MessageSender_$sendInvocationsToServer__Lcom_vaadin_client_communication_MessageSender_2V   @   client-3C59107ECE567…7334A.cache.js:5552
com_vaadin_client_communication_ServerRpcQueue_$doFlush__Lcom_vaadin_client_communication_ServerRpcQueue_2V @   client-3C59107ECE567…7334A.cache.js:5979
com_vaadin_client_communication_ServerRpcQueue$0methodref$doFlush$Type_run__V   @   client-3C59107ECE567…7334A.cache.js:6008
com_vaadin_client_communication_ServerRpcQueue$lambda$1$Type_execute__V @   client-3C59107ECE567…7334A.cache.js:6027
com_google_gwt_core_client_impl_SchedulerImpl_runScheduledTasks__Lcom_google_gwt_core_client_JsArray_2Lcom_google_gwt_core_client_JsArray_2Lcom_google_gwt_core_client_JsArray_2    @   client-3C59107ECE567…7334A.cache.js:1211
com_google_gwt_core_client_impl_SchedulerImpl_$flushPostEventPumpCommands__Lcom_google_gwt_core_client_impl_SchedulerImpl_2V    @   client-3C59107ECE567…7334A.cache.js:1111
com_google_gwt_core_client_impl_SchedulerImpl$Flusher_execute__Z    @   client-3C59107ECE567…7334A.cache.js:1258
com_google_gwt_core_client_impl_SchedulerImpl_execute__Lcom_google_gwt_core_client_Scheduler$RepeatingCommand_2Z    @   client-3C59107ECE567…7334A.cache.js:1189
com_google_gwt_core_client_impl_Impl_apply__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2    @   client-3C59107ECE567…57334A.cache.js:916
com_google_gwt_core_client_impl_Impl_entry0__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2   @   client-3C59107ECE567…57334A.cache.js:955
(anonymous) @   client-3C59107ECE567…57334A.cache.js:943
callback    @   client-3C59107ECE567…7334A.cache.js:1230
setTimeout (async)      
com_google_gwt_core_client_impl_SchedulerImpl_scheduleFixedDelayImpl__Lcom_google_gwt_core_client_Scheduler$RepeatingCommand_2IV    @   client-3C59107ECE567…7334A.cache.js:1234
com_google_gwt_core_client_impl_SchedulerImpl_$maybeSchedulePostEventPumpCommands__Lcom_google_gwt_core_client_impl_SchedulerImpl_2V    @   client-3C59107ECE567…7334A.cache.js:1124
com_vaadin_client_TrackingScheduler_$scheduleDeferred__Lcom_vaadin_client_TrackingScheduler_2Lcom_google_gwt_core_client_Scheduler$ScheduledCommand_2V  @   client-3C59107ECE567…7334A.cache.js:3870
com_vaadin_client_communication_ServerRpcQueue_$flush__Lcom_vaadin_client_communication_ServerRpcQueue_2V   @   client-3C59107ECE567…7334A.cache.js:5988
com_vaadin_client_communication_ServerConnector_$sendMessage__Lcom_vaadin_client_communication_ServerConnector_2Lelemental_json_JsonObject_2V   @   client-3C59107ECE567…7334A.cache.js:5904
com_vaadin_client_communication_ServerConnector_$sendNodeSyncMessage__Lcom_vaadin_client_communication_ServerConnector_2Lcom_vaadin_client_flow_StateNode_2ILjava_lang_String_2Ljava_lang_Object_2V @   client-3C59107ECE567…7334A.cache.js:5928
com_vaadin_client_flow_StateTree_$sendNodePropertySyncToServer__Lcom_vaadin_client_flow_StateTree_2Lcom_vaadin_client_flow_nodefeature_MapProperty_2V   @   client-3C59107ECE567…7334A.cache.js:6831
com_vaadin_client_flow_nodefeature_MapProperty_$lambda$3__Lcom_vaadin_client_flow_nodefeature_MapProperty_2Lcom_vaadin_client_flow_StateTree_2V @   client-3C59107ECE567…7334A.cache.js:8920
com_vaadin_client_flow_nodefeature_MapProperty$lambda$3$Type_run__V @   client-3C59107ECE567…7334A.cache.js:9065
com_vaadin_client_flow_binding_SimpleElementBindingStrategy_$syncPropertyIfNeeded__Lcom_vaadin_client_flow_binding_SimpleElementBindingStrategy_2Ljava_lang_String_2Lcom_vaadin_client_flow_binding_SimpleElementBindingStrategy$BindingContext_2V  @   client-3C59107ECE567…7334A.cache.js:7864
com_vaadin_client_flow_binding_SimpleElementBindingStrategy_$handlePropertySyncDomEvent__Lcom_vaadin_client_flow_binding_SimpleElementBindingStrategy_2Lcom_vaadin_client_flow_binding_SimpleElementBindingStrategy$BindingContext_2V   @   client-3C59107ECE567…7334A.cache.js:7749
com_vaadin_client_flow_binding_SimpleElementBindingStrategy$lambda$14$Type_handleEvent__Lelemental_events_Event_2V  @   client-3C59107ECE567…7334A.cache.js:8351
elemental_js_dom_JsElementalMixinBase_handleEvent__Lelemental_events_EventListener_2Lelemental_events_Event_2V  @   client-3C59107ECE567…334A.cache.js:10177
(anonymous) @   client-3C59107ECE567…334A.cache.js:10167
com_google_gwt_core_client_impl_Impl_apply__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2    @   client-3C59107ECE567…57334A.cache.js:916
com_google_gwt_core_client_impl_Impl_entry0__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2   @   client-3C59107ECE567…57334A.cache.js:955
(anonymous) @   client-3C59107ECE567…57334A.cache.js:943
dispatchNotifyEvent @   property-effects.html.js:286
runNotifyEffect @   property-effects.html.js:311
runEffectsForProperty   @   property-effects.html.js:142
runNotifyEffects    @   property-effects.html.js:229
_propertiesChanged  @   property-effects.html.js:1645
element._propertiesChanged  @   client-3C59107ECE567…7334A.cache.js:8160
_flushProperties    @   properties-changed.html.js:327
_flushProperties    @   property-effects.html.js:1490
_invalidateProperties   @   property-effects.html.js:1462
_setProperty    @   property-effects.html.js:1447
Object.defineProperty.set   @   properties-changed.html.js:136
_onClick    @   vaadin-list-mixin.html.js:121
(anonymous) @   vaadin-list-mixin.html.js:78
client-3C59107ECE567…57334A.cache.js:942 [Violation] 'load' handler took 8370ms
client-3C59107ECE567…334A.cache.js:10235 Server visit took 47341.485ms
client-3C59107ECE567…334A.cache.js:10235 JSON parsing took 0.255ms
client-3C59107ECE567…334A.cache.js:10235 Received xhr message: for(;;);[{"syncId":16,"clientId":13,"timings":[1166,46]}]
client-3C59107ECE567…7334A.cache.js:5115 Postponing UIDL handling due to lock...
client-3C59107ECE567…334A.cache.js:10227 Scheduling heartbeat in 60 seconds
client-3C59107ECE567…7334A.cache.js:5080 WARNING: reponse handling was never resumed, forcibly removing locks...
client-3C59107ECE567…7334A.cache.js:5132 Handling message from server
client-3C59107ECE567…7334A.cache.js:5095 Handling dependencies
client-3C59107ECE567…334A.cache.js:10235 handleUIDLMessage: 0 ms
client-3C59107ECE567…334A.cache.js:10235  Processing time was 1ms
client-3C59107ECE567…334A.cache.js:10231 endRequest called when no request is active
elemental_js_html_JsConsole_$error__Lelemental_js_html_JsConsole_2Ljava_lang_Object_2V  @   client-3C59107ECE567…334A.cache.js:10231
com_vaadin_client_SystemErrorHandler_$handleError__Lcom_vaadin_client_SystemErrorHandler_2Ljava_lang_String_2Ljava_lang_String_2Ljava_lang_String_2Lelemental_dom_Element_2 @   client-3C59107ECE567…7334A.cache.js:3785
com_vaadin_client_SystemErrorHandler_$handleError__Lcom_vaadin_client_SystemErrorHandler_2Ljava_lang_String_2V  @   client-3C59107ECE567…7334A.cache.js:3764
com_vaadin_client_SystemErrorHandler_$handleError__Lcom_vaadin_client_SystemErrorHandler_2Ljava_lang_Throwable_2V   @   client-3C59107ECE567…7334A.cache.js:3799
com_vaadin_client_ApplicationConnection$0methodref$handleError$Type_onUncaughtException__Ljava_lang_Throwable_2V    @   client-3C59107ECE567…7334A.cache.js:1791
com_google_gwt_core_client_impl_Impl_reportUncaughtException__Ljava_lang_Throwable_2ZV  @   client-3C59107ECE567…7334A.cache.js:1050
com_google_gwt_core_client_impl_Impl_entry0__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2   @   client-3C59107ECE567…57334A.cache.js:961
(anonymous) @   client-3C59107ECE567…57334A.cache.js:943
setTimeout (async)      
com_google_gwt_user_client_Timer_setTimeout__Lcom_google_gwt_core_client_JavaScriptObject_2II   @   client-3C59107ECE567…7334A.cache.js:1558
com_google_gwt_user_client_Timer_$schedule__Lcom_google_gwt_user_client_Timer_2IV   @   client-3C59107ECE567…7334A.cache.js:1523
com_vaadin_client_communication_MessageHandler_$handleJSON__Lcom_vaadin_client_communication_MessageHandler_2Lcom_vaadin_client_ValueMap_2V @   client-3C59107ECE567…7334A.cache.js:5126
com_vaadin_client_communication_MessageHandler_$handleMessage__Lcom_vaadin_client_communication_MessageHandler_2Lcom_vaadin_client_ValueMap_2V  @   client-3C59107ECE567…7334A.cache.js:5168
com_vaadin_client_communication_XhrConnection$XhrResponseHandler_onSuccess__Lcom_google_gwt_xhr_client_XMLHttpRequest_2V    @   client-3C59107ECE567…7334A.cache.js:6108
com_vaadin_client_gwt_elemental_js_util_Xhr$Handler_onReadyStateChange__Lcom_google_gwt_xhr_client_XMLHttpRequest_2V    @   client-3C59107ECE567…7334A.cache.js:9734
(anonymous) @   client-3C59107ECE567…7334A.cache.js:1583
com_google_gwt_core_client_impl_Impl_apply__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2    @   client-3C59107ECE567…57334A.cache.js:916
com_google_gwt_core_client_impl_Impl_entry0__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2   @   client-3C59107ECE567…57334A.cache.js:955
(anonymous) @   client-3C59107ECE567…57334A.cache.js:943
XMLHttpRequest.send (async)     
com_vaadin_client_gwt_elemental_js_util_Xhr_request__Lcom_google_gwt_xhr_client_XMLHttpRequest_2Ljava_lang_String_2Ljava_lang_String_2Ljava_lang_String_2Ljava_lang_String_2Lcom_vaadin_client_gwt_elemental_js_util_Xhr$Callback_2Lcom_google_gwt_xhr_client_XMLHttpRequest_2  @   client-3C59107ECE567…7334A.cache.js:9710
com_vaadin_client_gwt_elemental_js_util_Xhr_post__Ljava_lang_String_2Ljava_lang_String_2Ljava_lang_String_2Lcom_vaadin_client_gwt_elemental_js_util_Xhr$Callback_2Lcom_google_gwt_xhr_client_XMLHttpRequest_2   @   client-3C59107ECE567…7334A.cache.js:9700
com_vaadin_client_communication_XhrConnection_$send__Lcom_vaadin_client_communication_XhrConnection_2Lelemental_json_JsonObject_2V  @   client-3C59107ECE567…7334A.cache.js:6037
com_vaadin_client_communication_MessageSender_$send__Lcom_vaadin_client_communication_MessageSender_2Lelemental_json_JsonArray_2Lelemental_json_JsonObject_2V   @   client-3C59107ECE567…7334A.cache.js:5537
com_vaadin_client_communication_MessageSender_$doSendInvocationsToServer__Lcom_vaadin_client_communication_MessageSender_2V @   client-3C59107ECE567…7334A.cache.js:5504
com_vaadin_client_communication_MessageSender_$sendInvocationsToServer__Lcom_vaadin_client_communication_MessageSender_2V   @   client-3C59107ECE567…7334A.cache.js:5552
com_vaadin_client_communication_ServerRpcQueue_$doFlush__Lcom_vaadin_client_communication_ServerRpcQueue_2V @   client-3C59107ECE567…7334A.cache.js:5979
com_vaadin_client_communication_ServerRpcQueue$0methodref$doFlush$Type_run__V   @   client-3C59107ECE567…7334A.cache.js:6008
com_vaadin_client_communication_ServerRpcQueue$lambda$1$Type_execute__V @   client-3C59107ECE567…7334A.cache.js:6027
com_google_gwt_core_client_impl_SchedulerImpl_runScheduledTasks__Lcom_google_gwt_core_client_JsArray_2Lcom_google_gwt_core_client_JsArray_2Lcom_google_gwt_core_client_JsArray_2    @   client-3C59107ECE567…7334A.cache.js:1211
com_google_gwt_core_client_impl_SchedulerImpl_$flushPostEventPumpCommands__Lcom_google_gwt_core_client_impl_SchedulerImpl_2V    @   client-3C59107ECE567…7334A.cache.js:1111
com_google_gwt_core_client_impl_SchedulerImpl$Flusher_execute__Z    @   client-3C59107ECE567…7334A.cache.js:1258
com_google_gwt_core_client_impl_SchedulerImpl_execute__Lcom_google_gwt_core_client_Scheduler$RepeatingCommand_2Z    @   client-3C59107ECE567…7334A.cache.js:1189
com_google_gwt_core_client_impl_Impl_apply__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2    @   client-3C59107ECE567…57334A.cache.js:916
com_google_gwt_core_client_impl_Impl_entry0__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2   @   client-3C59107ECE567…57334A.cache.js:955
(anonymous) @   client-3C59107ECE567…57334A.cache.js:943
callback    @   client-3C59107ECE567…7334A.cache.js:1230
setTimeout (async)      
com_google_gwt_core_client_impl_SchedulerImpl_scheduleFixedDelayImpl__Lcom_google_gwt_core_client_Scheduler$RepeatingCommand_2IV    @   client-3C59107ECE567…7334A.cache.js:1234
com_google_gwt_core_client_impl_SchedulerImpl_$maybeSchedulePostEventPumpCommands__Lcom_google_gwt_core_client_impl_SchedulerImpl_2V    @   client-3C59107ECE567…7334A.cache.js:1124
com_vaadin_client_TrackingScheduler_$scheduleDeferred__Lcom_vaadin_client_TrackingScheduler_2Lcom_google_gwt_core_client_Scheduler$ScheduledCommand_2V  @   client-3C59107ECE567…7334A.cache.js:3870
com_vaadin_client_communication_ServerRpcQueue_$flush__Lcom_vaadin_client_communication_ServerRpcQueue_2V   @   client-3C59107ECE567…7334A.cache.js:5988
com_vaadin_client_communication_ServerConnector_$sendMessage__Lcom_vaadin_client_communication_ServerConnector_2Lelemental_json_JsonObject_2V   @   client-3C59107ECE567…7334A.cache.js:5904
com_vaadin_client_communication_ServerConnector_$sendNodeSyncMessage__Lcom_vaadin_client_communication_ServerConnector_2Lcom_vaadin_client_flow_StateNode_2ILjava_lang_String_2Ljava_lang_Object_2V @   client-3C59107ECE567…7334A.cache.js:5928
com_vaadin_client_flow_StateTree_$sendNodePropertySyncToServer__Lcom_vaadin_client_flow_StateTree_2Lcom_vaadin_client_flow_nodefeature_MapProperty_2V   @   client-3C59107ECE567…7334A.cache.js:6831
com_vaadin_client_flow_nodefeature_MapProperty_$lambda$3__Lcom_vaadin_client_flow_nodefeature_MapProperty_2Lcom_vaadin_client_flow_StateTree_2V @   client-3C59107ECE567…7334A.cache.js:8920
com_vaadin_client_flow_nodefeature_MapProperty$lambda$3$Type_run__V @   client-3C59107ECE567…7334A.cache.js:9065
com_vaadin_client_flow_binding_SimpleElementBindingStrategy_$syncPropertyIfNeeded__Lcom_vaadin_client_flow_binding_SimpleElementBindingStrategy_2Ljava_lang_String_2Lcom_vaadin_client_flow_binding_SimpleElementBindingStrategy$BindingContext_2V  @   client-3C59107ECE567…7334A.cache.js:7864
com_vaadin_client_flow_binding_SimpleElementBindingStrategy_$handlePropertySyncDomEvent__Lcom_vaadin_client_flow_binding_SimpleElementBindingStrategy_2Lcom_vaadin_client_flow_binding_SimpleElementBindingStrategy$BindingContext_2V   @   client-3C59107ECE567…7334A.cache.js:7749
com_vaadin_client_flow_binding_SimpleElementBindingStrategy$lambda$14$Type_handleEvent__Lelemental_events_Event_2V  @   client-3C59107ECE567…7334A.cache.js:8351
elemental_js_dom_JsElementalMixinBase_handleEvent__Lelemental_events_EventListener_2Lelemental_events_Event_2V  @   client-3C59107ECE567…334A.cache.js:10177
(anonymous) @   client-3C59107ECE567…334A.cache.js:10167
com_google_gwt_core_client_impl_Impl_apply__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2    @   client-3C59107ECE567…57334A.cache.js:916
com_google_gwt_core_client_impl_Impl_entry0__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2   @   client-3C59107ECE567…57334A.cache.js:955
(anonymous) @   client-3C59107ECE567…57334A.cache.js:943
dispatchNotifyEvent @   property-effects.html.js:286
runNotifyEffect @   property-effects.html.js:311
runEffectsForProperty   @   property-effects.html.js:142
runNotifyEffects    @   property-effects.html.js:229
_propertiesChanged  @   property-effects.html.js:1645
element._propertiesChanged  @   client-3C59107ECE567…7334A.cache.js:8160
_flushProperties    @   properties-changed.html.js:327
_flushProperties    @   property-effects.html.js:1490
_invalidateProperties   @   property-effects.html.js:1462
_setProperty    @   property-effects.html.js:1447
Object.defineProperty.set   @   properties-changed.html.js:136
_dataProviderClearFilter    @   vaadin-combo-box-dat…er-mixin.html.js:74
runMethodEffect @   property-effects.html.js:798
runEffectsForProperty   @   property-effects.html.js:142
runEffects  @   property-effects.html.js:108
_propertiesChanged  @   property-effects.html.js:1642
element._propertiesChanged  @   client-3C59107ECE567…7334A.cache.js:8160
_flushProperties    @   properties-changed.html.js:327
_flushProperties    @   property-effects.html.js:1490
_invalidateProperties   @   property-effects.html.js:1462
_setProperty    @   property-effects.html.js:1447
Object.defineProperty.set   @   properties-changed.html.js:136
close   @   vaadin-combo-box-mixin.html.js:298
_onFocusout
TatuLund commented 4 years ago

I think it is this Assert which is triggered

https://github.com/vaadin/flow/blob/master/flow-client/src/main/java/com/vaadin/client/DependencyLoader.java#L157

johannest commented 4 years ago

Steps to re-produce

  1. setup demo app: https://github.com/johannest/v14-push-issue-demo
  2. run the app
  3. Open app in Chrome
  4. Switch to Developer console / Network
  5. When the main view is loaded: use slow custom network speed setting (see for example screenshot below)
  6. Click Navigate and then immediately open the combobox and start scrolling it down
  7. If the issue doesn't happen and view is successfully switched to view "second", then click the navigate on that view and immediately start scrolling the grid of the "second" view down until the error happens or view is switched to first view
  8. Repeat steps 6. and 7. until the error happens
  9. You can try different network throttling setting and heartbeat intervals if the issue doesn't appear

image

johannest commented 4 years ago

To make the issue happen, it looks like the following things have to be present:

  1. Flaky network connection
  2. Push used and asynchronous UI updates from background thread
  3. Grid and/or Combobox with callback type dataprovider filtered/sorted while heartbeat request happens
  4. Possible also navigation between views happening
johannest commented 4 years ago

There seems to be several different error happening in the situation like above:

  1. server-log: Got an RPC for non-existent node: xx. This is most common and least critical, since doesn't seem to affect end user experience
  2. client-log: Received message with server id 29 but expected 3. Postponing handling until the missing message(s) have been received client-3C59107ECE5672DD2B3BF7AAD457334A.cache.js:10239 Gave up waiting for message 3 from the server client-3C59107ECE5672DD2B3BF7AAD457334A.cache.js:5515 Resynchronizing from server Second most common, doesn't yet seem to break things badly
  3. Server's log: Resynchronizing UI by client's request. Under normal operations this should not happen and may indicate a bug in Vaadin platform. If you see this message regularly please open a bug report at https://github.com/vaadin/flow/issues. Third most common, sometimes happens after 2.
  4. Error dialog in the browser: "Trying to start new request while another is active" sometimes happens after 3.
  5. Error in client-log: Assertion error: undefined happens sometimes after 4.
  6. Error dialog in the browser: "State node has not suitable binder strategy", happens sometimes after 4. or 5.
  7. Sometimes UI just freezes and refreshing the page doesn't always help
johannest commented 4 years ago

image

Kivinaama commented 4 years ago

For us it happens also with a good network connection (heartbeat ~40ms), but definitely feels to be related to some type of timings as it sometimes happens and sometimes not.

heruan commented 4 years ago

I confirm it happens to us also, with good network (local network).

heruan commented 4 years ago

To be specific: good network + heavy use of push (which might occur in-between a normal request roundtrip).

Artur- commented 4 years ago

While there seems to be several problems here, https://github.com/vaadin/flow/issues/7590 seems like a very fundamental one

TatuLund commented 4 years ago

The fix to issue linked by @Artur- is here https://github.com/vaadin/flow/pull/7631 My understanding is that it should also solve #7553 in the way, that application does not freeze.

Another question is why in some cases the resynchronization happens so often, and that is worth of separate study.

johannest commented 4 years ago

Few additional ideas to try:

  1. Add way to parameterize the threshold before client decides to Gave up waiting for message x from the server (MessageHandler.MAX_SUSPENDED_TIMEOUT is hard coded to 5s)
  2. Add something like this which was implemented to V8 previously: https://github.com/vaadin/framework/pull/11791/files
johannest commented 4 years ago

When using snapshot version of Flow from 2.2 branch, the application seems to work better. No more Assertion error undefined happening at least. We still get "Trying to start a new request while another is active" error right after following log entries:

VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:10344 Gave up waiting for message 9 from the server
elemental_js_html_JsConsole_$warn__Lelemental_js_html_JsConsole_2Ljava_lang_Object_2V @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:10344
com_vaadin_client_Console_warn__Ljava_lang_Object_2V @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:1855
com_vaadin_client_communication_MessageHandler_$forceMessageHandling__Lcom_vaadin_client_communication_MessageHandler_2V @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:5083
com_vaadin_client_communication_MessageHandler$1_run__V @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:5421
com_google_gwt_user_client_Timer_fire__IV @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:1567
(anonymous) @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:1548
com_google_gwt_core_client_impl_Impl_apply__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2 @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:916
com_google_gwt_core_client_impl_Impl_entry0__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2 @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:955
(anonymous) @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:943
setTimeout (async)
com_google_gwt_user_client_Timer_setTimeout__Lcom_google_gwt_core_client_JavaScriptObject_2II @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:1558
com_google_gwt_user_client_Timer_$schedule__Lcom_google_gwt_user_client_Timer_2IV @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:1523
com_vaadin_client_communication_MessageHandler_$handleJSON__Lcom_vaadin_client_communication_MessageHandler_2Lcom_vaadin_client_ValueMap_2V @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:5133
com_vaadin_client_communication_MessageHandler_$handleMessage__Lcom_vaadin_client_communication_MessageHandler_2Lcom_vaadin_client_ValueMap_2V @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:5175
com_vaadin_client_communication_AtmospherePushConnection_onMessage__Lcom_vaadin_client_communication_AtmospherePushConnection$AtmosphereResponse_2V @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:4427
(anonymous) @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:4248
com_google_gwt_core_client_impl_Impl_apply__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2 @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:916
com_google_gwt_core_client_impl_Impl_entry0__Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2Ljava_lang_Object_2 @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:955
(anonymous) @ VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:943
_f @ VM3467 vaadinPush.js:2765
_invokeFunction @ VM3467 vaadinPush.js:2754
_invokeCallback @ VM3467 vaadinPush.js:2884
_websocket.onmessage @ VM3467 vaadinPush.js:1457
VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:5522 Resynchronizing from server
VM3468 client-AE5358E149801E03A4E976C6D4B9C4E9.cache.js:10336 Trying to start a new request while another is active
johannest commented 4 years ago

It seems that increasing MessageHandler.MAX_SUSPENDED_TIMEOUTto 10s, makes the application much more stable since it decreases the risk of resynchronizing

johannest commented 4 years ago

My hypothesis for what causes the need for re-synchronizing so often in our application. When using WEBSOCKET_XHR communication and navigating to view that uses heavily push. Sometimes the request started with XHR from the previous view has not got response from server, before there is a push message arriving browser from another view. I think the risk increases in the network where there is higher latency and (occasionally) big difference between upload and download speeds.

heruan commented 4 years ago

Thank you @johannest for the investigation so far! I don't know Flow internals, so I can only report empirical experience:

  1. this happens to us with very good network (local network, 1Gbit/s)
  2. the occurrence of this increases with time/usage of the app
  3. disabling push this does not happen (at least in our tests)
johannest commented 4 years ago

@heruan Thanks for the update! Can you try following in your (dev) environment, start your application with Java assertions enabled (add -eajvm parameter: https://stackoverflow.com/questions/27435729/how-to-enable-assertions/27435742). Then go trough all the views of your application, especially those where the push is heavily used and where there are async updates from the server to the browser. With assertions enabled Vaadin should give you an error message if the UI is tried to update asynchronously without locking the session.

I have a gut feeling that this might increase the risk of this issue. If you find any of these cases please add an appropriate session locking to these places: https://vaadin.com/docs/v14/flow/advanced/tutorial-push-access.html

joheriks commented 4 years ago

I could force resynchronization locally over a simulated slow line (default "Slow 3G" throttle setting in Chrome devtools Network tab) with the below program. Pushing the button triggers a combination of a bigger amount of data to be transferred as response to the request together with a quickly completing push request that will be received out-of-order. If the original request takes over 5 seconds to complete resync will be triggered.

@johannest @heruan Could this match the access pattern in your applications?

package org.joheriks.testing;

import java.util.Random;

import com.vaadin.flow.component.button.Button;
import com.vaadin.flow.component.html.Div;
import com.vaadin.flow.component.html.Span;
import com.vaadin.flow.component.page.Push;
import com.vaadin.flow.router.Route;
import com.vaadin.flow.shared.ui.Transport;

@Route("")
@Push(transport = Transport.WEBSOCKET_XHR)
public class Test extends Div {

    public Test() {
        add(new Button("Push", e -> {
            // Add large span, random to evade compression
            final Random rnd = new Random();
            final StringBuilder sb = new StringBuilder();
            for (int i = 0; i < 500000; i++) {
                sb.append((char) (rnd.nextInt(26) + 'a'));
            }
            add(new Span(sb.toString()));

            // Send a push message quickly
            new Thread( () -> {
                try {
                    Thread.sleep(200);
                    getUI().get().access(() -> {
                        add(new Span("*"));
                    });
                } catch (InterruptedException ex) {
                    ex.printStackTrace();
                }
            }).start();
        }));
    }
}

EDIT: Simplified the example, one push enough.

heruan commented 4 years ago

@johannest I'll try with assertions enabled and let you know ASAP!

@joheriks I use Spring's @Async and @EventListener annotated methods where I use UI.accessLater (which should take care of session locking) to update the application and most of the time it's just a dataProvider.refreshAll().

TatuLund commented 4 years ago

Should this be now closed as https://github.com/vaadin/flow/issues/7590 and https://github.com/vaadin/flow/issues/7658 are resolved and included in Flow 2.1.6?

joheriks commented 4 years ago

It can be closed if verified that the resynchronization and tuning parameter satisfactorily address the issue in the real-world projects.

Kivinaama commented 4 years ago

Having this fix running in real-world with 14.1.18 + Flow 2.1.6 (resynch timeout 7s):

I would really hope you are still working on finding/fixing the root cause for this i.e. how to prevent the messaging go out of synch. We also tried to have pure WEBSOCKET as communication but it does not seem to work properly in our environment.

johannest commented 4 years ago

@heruan We discovered that similar issue happens with some load balancer(s) and Chrome/Edge Chromium. In that case the issue was that websocket channel was silently closed/broken and a push update from server-side was silently loss. This resulted forced resynchronization.

For a workaround to the issue, we configured Atmosphere to renew the websocket channel more frequently. The default idle timeout was 5min, we are trying now 45s timeout. To configure the timeout one can use ServletContextInitializer:

servletContext.setInitParameter("org.atmosphere.cpr.AtmosphereConfig.getInitParameter","true");
servletContext.setInitParameter("org.atmosphere.websocket.maxIdleTime","45000");

Another way could be using web.xml or webinit param.

heruan commented 4 years ago

Thank you @johannest for the update! So you're saying that the synchronization is lost because of a missed websocket update?

I do not see closed/broken channel errors in the balancer logs (Apache) and the issue still happens. Users get confused because the loading bar suddenly disappears; after that moment navigation won't work until a hard refresh.

johannest commented 4 years ago

@heruan with extensive logging every single request and response of a real life application (with a custom flow build), we saw that one async update message never arrived to the browser. This happened after the websocket channel has been open for a while, and apparently it was somehow silently terminated such that seemed to be still open.

Kivinaama commented 4 years ago

For us this latest fix that @johannest discovered that Push channel is automatically renewed before the load-balancer closes/"loses" them is working well. Users no longer complain slowness (=jamming + resynch). We have even received a few positive feedbacks. Closing the ticket.

heruan commented 4 years ago

@Kivinaama how did you fix the issue with the load-balancer?

Kivinaama commented 4 years ago

@heruan for us the fix Johannes figured out (in our environment) above worked.

servletContext.setInitParameter("org.atmosphere.cpr.AtmosphereConfig.getInitParameter","true"); servletContext.setInitParameter("org.atmosphere.websocket.maxIdleTime","45000");

We have now these parameters for Spring Vaadin: vaadin.maxMessageSuspendTimeout=7000 vaadin.websocket.idle.timeout=45000

How Johannes told me was that this instructs the client to request server to initialize a new Push-channel websocket every 45s.

The difference is clear: there are no recurring odd freeze-ups, the UI is very responsive all around. Apparently this issue had also caused some of the regular push-updates getting lost as well since now all view transitions are much smoother. We have even heard a couple of positive feedbacks from the users which is nice for our data-intensive UIs.

johannest commented 4 years ago

@heruan We just heard about another case where the same error happens in pure V8 application, when changing Vaadin theme from settings dialog. In their case this resulted endless resync loop and apparently neither of these timeouts helped. I'll let you know if we found a solution/root cause for this.

In this case the error started to happen when the app was deployed to QA environment (not confirmed yet but probably Kubernetes). When running the app with debug mode and inspecting responses that are got in the browser, they saw that the "missing" reponse with syncId (e.g.) 74 is got but nevertheless browser later informs that “Gave up waiting for message 74 from the server” and resync loop begins.

arenk commented 2 years ago

I'm currently experimenting with a HeartbeatInterceptor and thought this might be interesting to some of you. The approach is based on this Atmosphere Wiki Page and keeps the websocket alive instead of refreshing every e.g. 45s.

Not sure if this has any side effects. So far it's looking good in a test environment behind a load balancer with a 60s idle timeout (previously I've seen Websocket closed, reason: Connection was closed abnormally in console logs every 60s and in some rare cases Resynchronizing UI by client's request in server logs).

@Component
public class CustomAtmosphereConfig implements ServletContextInitializer {

    @Override
    public void onStartup(ServletContext servletContext) {
        servletContext.setInitParameter("org.atmosphere.cpr.AtmosphereConfig.getInitParameter", "true");
        servletContext.setInitParameter("org.atmosphere.cpr.AtmosphereInterceptor", "org.atmosphere.interceptor.HeartbeatInterceptor");
        servletContext.setInitParameter("org.atmosphere.interceptor.HeartbeatInterceptor.paddingChar", "{\"command\":\"serverInfo\", \"data\":{}}");
        servletContext.setInitParameter("org.atmosphere.interceptor.HeartbeatInterceptor.heartbeatFrequencyInSeconds", "45");
    }
}

I've set paddingChar to something that does not lead to a console error with vaadin-dev-tools due to an unkown message.

Vaadin 23.1.7, Spring Boot 2.7.2, Tomcat 9.0.65 (embedded)

#9399 #14232