flow icon indicating copy to clipboard operation
flow copied to clipboard

Page constantly reloads by itself after a websocket connection fails

Open echarlus opened this issue 1 year ago • 9 comments

Description of the bug

On some occasions, the browser will start reloading the current page forever. Looking at Chrome console one can see js exceptions. Looking at the network activity, one can also see that there is a recurrent POST being made to the server and it results in an exception on the client. The only way to get out of this behavior is to force reload the whole page.

Expected behavior

Page would not be reloaded forever ....

Minimal reproducible example

Unfortunately as this is fairly random I do not have a sample to provide. Here's a screenshot of the console (the image load which results in a 404 is "normal", it's probably when the page is being reloaded that it tries to refetch this resource that does not exist for this particular case).

image

logs.zip

Here are logs from the client (chrome console + chrome network activity) and the corresponding tomcat logs on the server side taken when the issue occurred.

Versions

  • Vaadin 23.2.3 with flow 23.2.4 (as I had also faced issue https://github.com/vaadin/flow/issues/14232)
  • Java version: 11
  • OS version: Mac OS 12.6
  • Browser version (if applicable): Chrome 106.0.5249.103
  • Application Server (if applicable): Linux with Tomcat 9.0.65 on Java openjdk version "11.0.16.1" 2022-08-12
  • IDE (if applicable): IntelliJ IDEA 2022.2.2

echarlus avatar Oct 11 '22 05:10 echarlus

Would it be possible to strip away everything from the app so that it still fails with the issue? From this it would seem like something goes wrong after the 404 for the image.

caalador avatar Oct 12 '22 10:10 caalador

The 404 for the image is not from the app itself since it's a direct URL to the resource embedded in the war file : /img/areas/logo_21.png for example. How could this affect the behavior of the app ? I was assuming this type of query is handled directly by the browser and the app server, without any vaadin interaction. Am I wrong ?

echarlus avatar Oct 12 '22 11:10 echarlus

Mainly because I heard of another project where a resync happens and there I heard it also seems to happen after a failing image download. Though that seems to do a Gave up waiting for message {} from the server then resync.

But without a project to test this is a guessing game with not good guesses.

caalador avatar Oct 12 '22 11:10 caalador

I'm assuming there are other conditions since depending on the user profile, I have a lot of accounts which will have the missing image and they do not experience the issue (or on a random manner). I have seen it occasionally with no evident pattern so it's quite hard to figure out a way to trigger the issue. I can make basic app with an image that fails to load 100% of the time but I then one would need to trigger the issue, which is another story. I'll try anyway and let you know.

echarlus avatar Oct 12 '22 11:10 echarlus

@caalador I cannot reproduce upon request but one of my user reported that the issue occurred today during a presentation. I check the logs and found this in both catalina.out and access.log :

10.1.0.5 - - [13/Oct/2022:15:42:09 +0200] "POST /?v-r=uidl&v-uiId=2 HTTP/1.1" 200 39
10.1.0.5 - - [13/Oct/2022:15:42:11 +0200] "POST /?v-r=uidl&v-uiId=2 HTTP/1.1" 200 31623
10.1.0.5 - - [13/Oct/2022:15:42:12 +0200] "POST /?v-r=uidl&v-uiId=2 HTTP/1.1" 200 217
10.1.0.5 - - [13/Oct/2022:15:42:17 +0200] "POST /?v-r=uidl&v-uiId=2 HTTP/1.1" 200 109182
10.1.0.5 - - [13/Oct/2022:15:42:17 +0200] "POST /?v-r=uidl&v-uiId=2 HTTP/1.1" 200 39
10.1.0.5 - - [13/Oct/2022:15:42:22 +0200] "POST /?v-r=uidl&v-uiId=2 HTTP/1.1" 200 106920
10.1.0.5 - - [13/Oct/2022:15:42:24 +0200] "POST /?v-r=heartbeat&v-uiId=2 HTTP/1.1" 200 -
10.1.0.5 - - [13/Oct/2022:15:42:24 +0200] "POST /?v-r=uidl&v-uiId=2 HTTP/1.1" 200 39
10.1.0.5 - - [13/Oct/2022:15:42:29 +0200] "POST /?v-r=uidl&v-uiId=2 HTTP/1.1" 200 106795
10.1.0.5 - - [13/Oct/2022:15:42:30 +0200] "POST /?v-r=uidl&v-uiId=2 HTTP/1.1" 200 39
10.1.0.5 - - [13/Oct/2022:15:42:30 +0200] "POST /?v-r=uidl&v-uiId=2 HTTP/1.1" 200 137
10.1.0.5 - - [13/Oct/2022:15:42:30 +0200] "POST /?v-r=uidl&v-uiId=2 HTTP/1.1" 200 39

At the same time, in catalina.out :

[http-nio-8080-exec-7] WARN com.vaadin.flow.server.communication.ServerRpcHandler - Resynchronizing UI by client's request. A network message was lost before reaching the client and the client is reloading the full UI state. This typically happens because of a bad network connection with packet loss or because of some part of the network infrastructure (load balancer, proxy) terminating a push (websocket or long-polling) connection. If you are using push with a proxy, make sure the push timeout is set to be smaller than the proxy connection timeout
[http-nio-8080-exec-10] WARN com.vaadin.flow.server.communication.ServerRpcHandler - Resynchronizing UI by client's request. A network message was lost before reaching the client and the client is reloading the full UI state. This typically happens because of a bad network connection with packet loss or because of some part of the network infrastructure (load balancer, proxy) terminating a push (websocket or long-polling) connection. If you are using push with a proxy, make sure the push timeout is set to be smaller than the proxy connection timeout
oct. 13, 2022 3:42:23 PM fr.ocell.ovisuserver.ui.MultiIndicatorsChart timeLineRangeChanged
FINE: timeLineRangeChanged for chart fr.ocell.ovisuserver.ui.MultiIndicatorsChart@777e909a min=Wed Oct 05 22:14:36 CEST 2022 max=Thu Oct 13 17:07:24 CEST 2022 changed=true
oct. 13, 2022 3:42:23 PM fr.ocell.ovisuserver.ui.MultiIndicatorsChart timeLineRangeChanged
FINE: timeLineRangeChanged for chart fr.ocell.ovisuserver.ui.MultiIndicatorsChart@71d3168d min=Wed Oct 05 22:21:16 CEST 2022 max=Thu Oct 13 17:07:20 CEST 2022 changed=true
[http-nio-8080-exec-5] WARN com.vaadin.flow.server.communication.ServerRpcHandler - Resynchronizing UI by client's request. A network message was lost before reaching the client and the client is reloading the full UI state. This typically happens because of a bad network connection with packet loss or because of some part of the network infrastructure (load balancer, proxy) terminating a push (websocket or long-polling) connection. If you are using push with a proxy, make sure the push timeout is set to be smaller than the proxy connection timeout

The user told me he was on Wifi and that everything else seemed to work fine ... FYI for this particular user, the image causing a 404 on the logs I sent above was present, therefore no 404 was returned so I believe it's not linked to that ... So this is still happening even with the latest version and seems to be random which is a real pain to track down. Any idea of what I could do to gather more context info when this happens ? This is really a killer and should be tracked down and fixed. Thanks.

echarlus avatar Oct 13 '22 15:10 echarlus

The request and response payloads might help to see if there's some component/add-on that causes it. As now we don't know if it is the server that moves the sync id forward or if the client steps wrong, nor what happened just before the resync. Do you ever get this locally with the applications?

caalador avatar Oct 14 '22 04:10 caalador

@caalador if you load the .xhr file I've provided in the zip referenced in the bug report (see logs.zip link just below the console logs screen capture) you'll have the payload details for every request. Unfortunately I do not have it for the last report that I got from a customer but the one I managed to capture might help you. You have the Chrome network panel logs (full requests history + payloads), the Chrome console output and the Tomcat logs. I hope these info will be enough because I do not see how I can get more if the issue occurs again ...

echarlus avatar Oct 14 '22 06:10 echarlus

The har starts with the first resynchronize request. syncId/clientId -> 21/18 vs response 24/19 then request 24/19 vs response 26/20 So the syncId is multiple steps wrong (updates multiples against one request) all the time making the resync fail. Do you have automatic push in the application(s)?

caalador avatar Oct 14 '22 07:10 caalador

yes Push is set to automatic.

echarlus avatar Oct 14 '22 07:10 echarlus

Flow 23.2.5 (out with Vaadin 23.2.6) got the pwa change. Does that help with the issue or is it still happening?

caalador avatar Oct 25 '22 09:10 caalador

Thanks for the update. I'll check that next week and get back to you

echarlus avatar Oct 25 '22 15:10 echarlus

I have pretty much the same issue with resync and Vaadin 23.2.5 https://stackoverflow.com/questions/74147029/vaadin-23-unable-to-fully-reload-application-after-redeploy

alexanoid avatar Oct 25 '22 17:10 alexanoid

Same in Vaadin 14. After redeploying, resync happens a lot.

tiagomartins91 avatar Oct 28 '22 09:10 tiagomartins91

@caalador unfortunately, the latest flow version (Vaadin 23.2.6 with Flow 23.2.5) does not fix the issue. One of my customers just experienced it again. I found this in the logs : [http-nio-8080-exec-5] WARN com.vaadin.flow.server.communication.ServerRpcHandler - Resynchronizing UI by client's request. A network message was lost before reaching the client and the client is reloading the full UI state. This typically happens because of a bad network connection with packet loss or because of some part of the network infrastructure (load balancer, proxy) terminating a push (websocket or long-polling) connection. If you are using push with a proxy, make sure the push timeout is set to be smaller than the proxy connection timeout [http-nio-8080-exec-4] WARN com.vaadin.flow.server.communication.ServerRpcHandler - Resynchronizing UI by client's request. A network message was lost before reaching the client and the client is reloading the full UI state. This typically happens because of a bad network connection with packet loss or because of some part of the network infrastructure (load balancer, proxy) terminating a push (websocket or long-polling) connection. If you are using push with a proxy, make sure the push timeout is set to be smaller than the proxy connection timeout [http-nio-8080-exec-7] WARN com.vaadin.flow.server.communication.ServerRpcHandler - Resynchronizing UI by client's request. A network message was lost before reaching the client and the client is reloading the full UI state. This typically happens because of a bad network connection with packet loss or because of some part of the network infrastructure (load balancer, proxy) terminating a push (websocket or long-polling) connection. If you are using push with a proxy, make sure the push timeout is set to be smaller than the proxy connection timeout [http-nio-8080-exec-9] WARN com.vaadin.flow.server.communication.ServerRpcHandler - Resynchronizing UI by client's request. A network message was lost before reaching the client and the client is reloading the full UI state. This typically happens because of a bad network connection with packet loss or because of some part of the network infrastructure (load balancer, proxy) terminating a push (websocket or long-polling) connection. If you are using push with a proxy, make sure the push timeout is set to be smaller than the proxy connection timeout [http-nio-8080-exec-1] WARN com.vaadin.flow.server.communication.ServerRpcHandler - Resynchronizing UI by client's request. A network message was lost before reaching the client and the client is reloading the full UI state. This typically happens because of a bad network connection with packet loss or because of some part of the network infrastructure (load balancer, proxy) terminating a push (websocket or long-polling) connection. If you are using push with a proxy, make sure the push timeout is set to be smaller than the proxy connection timeout [http-nio-8080-exec-6] WARN com.vaadin.flow.server.communication.ServerRpcHandler - Resynchronizing UI by client's request. A network message was lost before reaching the client and the client is reloading the full UI state. This typically happens because of a bad network connection with packet loss or because of some part of the network infrastructure (load balancer, proxy) terminating a push (websocket or long-polling) connection. If you are using push with a proxy, make sure the push timeout is set to be smaller than the proxy connection timeout [http-nio-8080-exec-10] WARN com.vaadin.flow.server.communication.ServerRpcHandler - Resynchronizing UI by client's request. A network message was lost before reaching the client and the client is reloading the full UI state. This typically happens because of a bad network connection with packet loss or because of some part of the network infrastructure (load balancer, proxy) terminating a push (websocket or long-polling) connection. If you are using push with a proxy, make sure the push timeout is set to be smaller than the proxy connection timeout Page reloaded itself in a loop (see video)

https://user-images.githubusercontent.com/7509875/200643616-7ffce00b-87ac-4010-97aa-217c46e1fe25.mp4

Any other hints on your side on what could be causing this ?

echarlus avatar Nov 08 '22 18:11 echarlus

Based on previous investigation we noted that (in this instance) the sync id jumps 3 at a time for some reason. It would seem like there is something happening that increments the internal serever id but for the server that is only done for UIDL creation. I at least can not see what could cause this.

caalador avatar Nov 09 '22 06:11 caalador

This incrementation occurs on the server or on the client ? Is there any thing I can do to add logs and try to figure out what's happening ?

echarlus avatar Nov 09 '22 07:11 echarlus