flow icon indicating copy to clipboard operation
flow copied to clipboard

Unexpected message id from the client (sync ids different)

Open thomaskiesl opened this issue 3 years ago • 47 comments

Description of the bug

I receive sometimes the same error message on my production system. But I do not have any idea when this happen:

2021-12-27 07:27:43,174 INFO | https-jsse-nio-18443-exec-10 | com.vaadin.flow.server.communication.ServerRpcHandler | Ignoring old duplicate message from the client. Expected: 1748, got: 1747

2021-12-27 07:28:01,354  WARN | https-jsse-nio-18443-exec-5 | de.app.ApplicationVaadinServiceInitListener         | Unexpected error
java.lang.UnsupportedOperationException: Unexpected message id from the client. Expected sync id: 1751, got 1752. more details logged on DEBUG level.
        at com.vaadin.flow.server.communication.ServerRpcHandler.handleRpc(ServerRpcHandler.java:310)
        at com.vaadin.flow.server.communication.UidlRequestHandler.synchronizedHandleRequest(UidlRequestHandler.java:115)
        at com.vaadin.flow.server.SynchronizedRequestHandler.handleRequest(SynchronizedRequestHandler.java:40)
        at com.vaadin.flow.server.VaadinService.handleRequest(VaadinService.java:1565)
        at com.vaadin.flow.server.VaadinServlet.service(VaadinServlet.java:302)
        at com.vaadin.flow.spring.SpringServlet.service(SpringServlet.java:109)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:750)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:327)
        at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:115)
        at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:81)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
        at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:122)
        at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:116)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
        at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:126)
        at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:81)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
        at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:109)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
        at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:149)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)

It seems it is the same bug as https://github.com/vaadin/flow/issues/9778

Minimal reproducible example

Unfortunately I'm not possible to reproduce the issue. I only find the messages in the logfile.

Versions

  • Vaadin / Flow version: 21.0.9
  • Java version: 17.0.1
  • OS version: CentOS

thomaskiesl avatar Dec 27 '21 08:12 thomaskiesl

Currently I find this issue ~10-20 per day in my logfile. Unfortunately I have no idea where this is coming from. The problem is that everytime a error message is shown to the user...

thomaskiesl avatar Jan 02 '22 13:01 thomaskiesl

I activated the debug logging, and got the following (unfortunately no special information):

2022-01-02 20:25:10,673 DEBUG | https-jsse-nio-18443-exec-9 | com.vaadin.flow.server.communication.ServerRpcHandler | Unexpected message id from the client. Expected sync id: 2, got 1. Message start:

2022-01-02 20:25:10,685  WARN | https-jsse-nio-18443-exec-9 | de.app.AppVaadinServiceInitListener         | Unexpected error
java.lang.UnsupportedOperationException: Unexpected message id from the client. Expected sync id: 2, got 1. more details logged on DEBUG level.
        at com.vaadin.flow.server.communication.ServerRpcHandler.handleRpc(ServerRpcHandler.java:310)
        at com.vaadin.flow.server.communication.UidlRequestHandler.synchronizedHandleRequest(UidlRequestHandler.java:115)
        at com.vaadin.flow.server.SynchronizedRequestHandler.handleRequest(SynchronizedRequestHandler.java:40)
        at com.vaadin.flow.server.VaadinService.handleRequest(VaadinService.java:1565)
        at com.vaadin.flow.server.VaadinServlet.service(VaadinServlet.java:302)
        at com.vaadin.flow.spring.SpringServlet.service(SpringServlet.java:109)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:750)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:327)
        at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:115)
        at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:81)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
        at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:122)
        at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:116)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
        at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:126)
        at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:81)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
        at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:109)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
        at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:149)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)
        at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336)

thomaskiesl avatar Jan 02 '22 19:01 thomaskiesl

Additional info: Once today I got the following message:

2022-01-02 20:25:09,626 INFO | https-jsse-nio-18443-exec-7 | com.vaadin.flow.server.communication.ServerRpcHandler | Ignoring old duplicate message from the client. Expected: 1, got: 0

and some milliseconds after "Unexpected message id from the client. Expected sync id: 2, got 1. more details logged on DEBUG level." the following:

2022-01-02 20:25:11,225 WARN | https-jsse-nio-18443-exec-7 | com.vaadin.flow.server.communication.ServerRpcHandler | 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

thomaskiesl avatar Jan 02 '22 22:01 thomaskiesl

Without only this information it would feel like one server message to the client is lost as the server should for each response send a syncId that it expects the client to have in the next request. In short:

The server generates a strictly increasing id for each response to each
request from the client. This ID is then replayed back to the server on
each request. This helps the server in knowing in what state the client
is, and compare it to its own state. In short, it helps with concurrent
changes between the client and server.

Without any way to reproduce this is really hard to investigate. @Legioth would you have any ideas on how @thomaskiesl could try to investigate the issue on their end?

caalador avatar Jan 04 '22 11:01 caalador

Does anyone have an idea how to find this out? I got this message every day multiple times? Additional logging?

thomaskiesl avatar Jan 21 '22 21:01 thomaskiesl

There's supposed to be some additional information about the message payload after Message start: in the thing that is logged on the debug level. Looking at that data might reveal some pattern in the messages that cause the problem. Looking at the code, there is also a possibility that nothing is actually logged - this would happen in the theoretical case with an empty array in the message.

There are a couple of possible causes for why old sequence numbers would show up unexpectedly. Finding out the cause is usually very difficult without a good way of reproducing.

  • The browser might for some reason retry sending the message in case it didn't receive a response.
  • An HTTP proxy or similar in between might do the same.
  • There's a possibility that these aren't actually sequence mismatches, but instead somehow mixing up sessions or UI instances. It would on the other hand be expected to also see mismatches in the other direction then, i.e. messages where the received sequence number is greater than the expected number.

Legioth avatar Jan 26 '22 11:01 Legioth

@Legioth I recevie for example the following info within the debug file:

 Unexpected message id from the client. Expected sync id: 34, got 35. Message start: { type: event node: 1.0 feature: null }
 Unexpected message id from the client. Expected sync id: 34, got 35. more details logged on DEBUG level.

thomaskiesl avatar Jan 26 '22 18:01 thomaskiesl

I'm experiencing this issue too, same vaadin version [com.vaadin.flow.server.DefaultErrorHandler] (default task-359) : java.lang.UnsupportedOperationException: Unexpected message id from the client. Expected sync id: 5, got 2. Message start: {"csrfToken":"ac311843-2839-4ffe-878c-256d7f69ae7a",rpc":[],"syncId":3,"clientId":2,"resynchronize":true}

giorgiac98 avatar Mar 16 '22 10:03 giorgiac98

Also getting this on Vaadin 14.7.0. Upon getting this it leads to an internal error page on the UI.

Uncaught UI exception: java.lang.UnsupportedOperationException: Unexpected message id from the client. Expected sync id: 41, got 39. Message start: {"csrfToken":"7f83ca3d-e864-4362-9dda-a8af3e641780","rpc":[],"syncId":52,"clientId":39,"resynchronize":true}
	at com.vaadin.flow.server.communication.ServerRpcHandler.handleRpc(ServerRpcHandler.java:310)
	at com.vaadin.flow.server.communication.UidlRequestHandler.synchronizedHandleRequest(UidlRequestHandler.java:92)

I was able to replicate it by setting up a Chrome network throttling profile with a Download of 100 kbits/s, Upload of 50 kbits/s and a latency of 500.

Then I quickly clicked on a paged table's paginator so that it would change pages and data being fetched and from time to time clicked on a row on the table. After a minute or so the UI went blank while the server log showed

[com.business.ui.MainLayout] (default task-74) Uncaught UI exception: java.lang.UnsupportedOperationException: Unexpected message id from the client. Expected sync id: 135, got 126. Message start: {"csrfToken":"e92cd975-d064-4551-9277-59b21ca057c1","rpc":[{"type":"publishedEventHandler","node":844,"templateEventMethodName":"deselect","templateEventMethodArgs":["215"],"promise":188},{"type":"publishedEventHandler","node":844,"templateEventMethodName":"setDetailsVisible","templateEventMethodArgs":[null],"promise":189},{"type":"event","node":844,"event":"item-click","data":{"event.detail.screenY":511,"event.detail.metaKey":false,"event.detail.button":0,"event.detail.shiftKey":false,"event.detail.screenX":1024,"event.detail.itemKey":"215","event.detail.internalColumnId":"col6","event.detail.altKey":false,"event.detail.clientX":1024,"event.detail.detail":1,"event.detail.clientY":408,"event.detail.ctrlKey":false}},{"type":"publishedEventHandler","node":844,"templateEventMethodName":"select","templateEventMethodArgs":["216"],"promise":190},{"type":"publishedEventHandler","node":844,"templateEventMethodName":"setDetailsVisible","templateEventMethodArgs":["216"],"promise":191},{"type":"e
	at com.vaadin.flow.server.communication.ServerRpcHandler.handleRpc(ServerRpcHandler.java:310)

Before that I also see some

2022-04-22 06:08:41,376 WARN  [com.vaadin.flow.server.communication.rpc.AbstractRpcInvocationHandler] (default task-74) Got an RPC for non-existent node: 844

messages in the logs.

Issue seems to be related to https://github.com/vaadin/flow/issues/9778

sergiupienar avatar Apr 22 '22 05:04 sergiupienar

I'm using Vaadin 24.2.3 with Java 21, SpringBoot 3.2 and Spring Framework 6.1 (on macOS Ventura 13.5) and still see this issue:

java.lang.UnsupportedOperationException: Unexpected message id from the client. Expected sync id: 13, got 14. more details logged on DEBUG level.
	at com.vaadin.flow.server.communication.ServerRpcHandler.handleRpc(ServerRpcHandler.java:313)
	at com.vaadin.flow.server.communication.UidlRequestHandler.synchronizedHandleRequest(UidlRequestHandler.java:114)
	at com.vaadin.flow.server.SynchronizedRequestHandler.handleRequest(SynchronizedRequestHandler.java:40)
	at com.vaadin.flow.server.VaadinService.handleRequest(VaadinService.java:1522)
	at com.vaadin.flow.server.VaadinServlet.service(VaadinServlet.java:398)
	at com.vaadin.flow.spring.SpringServlet.service(SpringServlet.java:106)
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:205)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
	at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:642)
	at org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:408)
	at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:313)
	at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:277)
	at org.springframework.web.servlet.mvc.ServletForwardingController.handleRequestInternal(ServletForwardingController.java:141)
	at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:178)
	at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:51)
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089)
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979)
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
	at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:914)
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:590)
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:205)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
	at org.springframework.web.multipart.support.MultipartFilter.doFilterInternal(MultipartFilter.java:125)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
	at org.springframework.security.web.ObservationFilterChainDecorator$FilterObservation$SimpleFilterObservation.lambda$wrap$1(ObservationFilterChainDecorator.java:479)
	at org.springframework.security.web.ObservationFilterChainDecorator.lambda$wrapUnsecured$1(ObservationFilterChainDecorator.java:90)
	at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:219)
	at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:191)
	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:352)
	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:268)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
	at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
	at org.springframework.web.filter.ServerHttpObservationFilter.doFilterInternal(ServerHttpObservationFilter.java:109)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:167)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:482)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:115)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:340)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:391)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:896)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1744)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
	at java.base\/java.lang.VirtualThread.run(VirtualThread.java:311)

Any news on this?

Cheers, Fabian

funfried avatar Nov 27 '23 12:11 funfried

Same problem here on JDK17, vaadin 24.1.11, SB3.1 - fairly trivial application. 20% of e2e-Tests fail randomly with something similar to

023-11-29T20:59:15.336Z ERROR 3414 --- [o-auto-1-exec-2] c.v.flow.server.DefaultErrorHandler      : 

java.lang.UnsupportedOperationException: Unexpected message id from the client. Expected sync id: 2, got 3. more details logged on DEBUG level.
	at com.vaadin.flow.server.communication.ServerRpcHandler.handleRpc(ServerRpcHandler.java:313) ~[flow-server-24.1.13.jar:24.1.13]
	at com.vaadin.flow.server.communication.UidlRequestHandler.synchronizedHandleRequest(UidlRequestHandler.java:114) ~[flow-server-24.1.13.jar:24.1.13]
	at com.vaadin.flow.server.SynchronizedRequestHandler.handleRequest(SynchronizedRequestHandler.java:40) ~[flow-server-24.1.13.jar:24.1.13]
	at com.vaadin.flow.server.VaadinService.handleRequest(VaadinService.java:1529) ~[flow-server-24.1.13.jar:24.1.13]
	at com.vaadin.flow.server.VaadinServlet.service(VaadinServlet.java:398) ~[flow-server-24.1.13.jar:24.1.13]
	at com.vaadin.flow.spring.SpringServlet.service(SpringServlet.java:106) ~[vaadin-spring-24.1.13.jar:na]
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658) ~[tomcat-embed-core-10.1.15.jar:6.0]

uweschaefer avatar Nov 29 '23 21:11 uweschaefer

Same issue for me on vaadin version= 24.2.6 and springboot=3.0.6

2023-12-14T05:46:52.970Z ERROR 117 --- [http-nio-80-exec-9] c.v.flow.server.DefaultErrorHandler      :
java.lang.UnsupportedOperationException: Unexpected message id from the client. Expected sync id: 2, got 3. more details logged on DEBUG level.at com.vaadin.flow.server.communication.ServerRpcHandler.handleRpc(ServerRpcHandler.java:313) ~[flow-server-24.2.5.jar!/:24.2.5]at com.vaadin.flow.server.communication.UidlRequestHandler.synchronizedHandleRequest(UidlRequestHandler.java:114) ~[flow-server-24.2.5.jar!/:24.2.5]at com.vaadin.flow.server.SynchronizedRequestHandler.handleRequest(SynchronizedRequestHandler.java:40) ~[flow-server-24.2.5.jar!/:24.2.5]at com.vaadin.flow.server.VaadinService.handleRequest(VaadinService.java:1522) ~[flow-server-24.2.5.jar!/:24.2.5]at com.vaadin.flow.server.VaadinServlet.service(VaadinServlet.java:398) ~[flow-server-24.2.5.jar!/:24.2.5]at com.vaadin.flow.spring.SpringServlet.service(SpringServlet.java:106) ~[vaadin-spring-24.2.5.jar!/:na]at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658) ~[tomcat-embed-core-10.1.8.jar!/:na]at 

manpreetsoftodia avatar Dec 14 '23 05:12 manpreetsoftodia

Same issue for me. Vaadin=24.3.3 Spring boot=3.2.2 java.lang.UnsupportedOperationException: Unexpected message id from the client. Expected sync id: 1, got 2. more details logged on DEBUG level.

leandropnto avatar Feb 10 '24 04:02 leandropnto

We have the same issue. It randomly occurs after logging in when opening the first UI after Login. Vaadin: 24.3.5 Spring boot: 3.2.2

11:38:53.233 DEBUG [http-nio-8090-exec-6] c.v.f.server.communication.ServerRpcHandler:311    - Unexpected message id from the client. Expected sync id: 2, got 3. Message start: 
11:38:53.233 ERROR [http-nio-8090-exec-6] com.vaadin.flow.server.DefaultErrorHandler:105     - 
java.lang.UnsupportedOperationException: Unexpected message id from the client. Expected sync id: 2, got 3. more details logged on DEBUG level.

Interestingly the Message Start output ist empty. When debugging I see that the rpcArray is empty which causes the debug output to be empty. The "changeMessage" is:

{"csrfToken":"40cf2444-6f3f-42a2-bc41-b7df9aa4d1bf","rpc":[],"syncId":2,"clientId":3,"UNLOAD":true}

It just happens on one application and I can't find the difference that causes it.

ssindelar avatar Feb 22 '24 11:02 ssindelar

We have the same issue.

Java: 17 Vaadin: 24.2.9 Spring boot: 3.2.0 Running on google cloud

java.lang.UnsupportedOperationException: Unexpected message id from the client. Expected sync id: 2, got 3. more details logged on DEBUG level.
at com.vaadin.flow.server.communication.ServerRpcHandler.handleRpc ( com/vaadin.flow.server.communication/ServerRpcHandler.java:313 )

SebastianDietrich avatar Mar 12 '24 09:03 SebastianDietrich

Same Issue here, makes the Web basically unusable... Java: 17 Vaadin: 24.3.7 Spring boot: 3.2.3 Azure Spring Apps

difficult2connect avatar Mar 14 '24 13:03 difficult2connect

Any updates on this? Many of my users are not happy with this situation!?

thomaskiesl avatar Mar 26 '24 18:03 thomaskiesl

That error is actually reported multiple times and has been discussed on many tickets. The error itself is not a bug as is, but logged as part of the failsafe mechanism in Vaadin.

When packets are sent back and forth between server and browser, they include serial number so that both parties can verify that no packet is being lost.

There are natural reasons for packet loss

  • Wrong load balancer / proxy setup, e.g. without sticky sessions
  • Firewall, VPN blocking packet due deep inspection, I have seen cases where packets have been blocked due JavaScript or JSON carried in them and too strict settings
  • The above can also just delay packet arrival, especially virus sniffers are problematic, which may cause problem when WebSocket_XHR is used
  • Faulty router (yes, that has happened in real life, one customer had this and after router firmware update issue disappeared)
  • Flake WiFi/Cellular connection (yes has happened)
  • Bug in Vaadin (we have fixed many, thus most of the tickets discussing this are closed). Naturally this is the final option still which cannot be ruled out.

When communication goes un-sync Vaadin detects that and does resynchronize. That is done on purpose in order to restore the operation.

When you see this error, one should observe does it happen in correlation with some usage pattern of the application, frequency, when it is happening etc. All these can give some hints whether it is due some natural cause of the error.

As you see the list of the natural causes are all flaky, hence deterministic re-production may be difficult.

The cases where it has been a bug in Vaadin have been difficult to debug, but with rigorous attempt of following the statistics, close collaboration with the reporter, ruling out natural causes we have been able to find those and fixed them. Naturally we would like to hope that we have identified all of them, and only the natural causes remain.

TatuLund avatar Mar 27 '24 10:03 TatuLund

I see the error on my development machine from time to time. So I can exclude 1,2,4,5. We actually switched from Sophos to SentinelOne in the mean time so I guess I can also rule out 3. The only patterns that I see is that is happening when logging in and it is always request 2 that is missing. Everything after this seems fine. But the Logincode and most of the spring security code is located in a shared project and in the other application I wasn't able to reproduce the error. I will be away for 2 weeks but after that I would love to schedule a meeting, where we could try to find the cause on my machine.

ssindelar avatar Mar 27 '24 10:03 ssindelar

Thanks everyone who commented and thanks @ssindelar for the feedback and willing be up for the meeting. This is that I was going to propose: have a video call and investigate the issue together. What I'm afraid of is that this may be not only limited to logging, but to a resync issue in Vaadin that may cause broken UI, e.g. empty page and page load freezing.

Based on the observations, we may need to implement more robust logic for resync and UIDL overall. I've prioritised this issue for the Vaadin Flow dev team.

Any volunteers are appreciated who can meet with us and show us the problem. Feel free to ping me, e.g. in our Discord (mikhailshabarov) , then we can schedule a meeting.

mshabarov avatar Mar 27 '24 11:03 mshabarov

Happening to me too. Running vaadin 24.3.8 on JDK 21, all dependencies for springboot as defined by vaadin-bom. In my case, it happens if I am using Firefox:

  • I login into the application from a clean browser session
  • I do some actions
  • I logout
  • I try to login again
  • BOOOM.

Only way to login again is by closing the browser and start clean again. I haven't seen this case while using Chrome.

Hope this helps for debugging.

jfarjona avatar Mar 30 '24 02:03 jfarjona

  • I logout
  • I try to login again
  • BOOOM.

This sounds like there's something with the security configuration that causes messages to be eaten after logging in again or maybe that some of the tracking state is not reset.

Legioth avatar Apr 02 '24 09:04 Legioth

Same java 17 vaadin 24.1.10 Azure

seems to be tentative issue

java.lang.UnsupportedOperationException: Unexpected message id from the client. Expected sync id: 0, got 1. more details logged on DEBUG level.

guygoldwasser avatar Apr 11 '24 11:04 guygoldwasser