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.

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

Vaadin Push fails during session deserialization #111

Open
MichaelPluessErni opened this issue Feb 28, 2024 · 15 comments · Fixed by #143
Open

Vaadin Push fails during session deserialization #111

MichaelPluessErni opened this issue Feb 28, 2024 · 15 comments · Fixed by #143

Comments

@MichaelPluessErni
Copy link

Error:

During session deserialization it can happen, that vaadin pushes fail and trigger a refresh.

Expectation:

Refreshs should not be triggered during session deserialization.

More details:

I suspect that the push process and the deserialization process run in parallel and can interfere.

vaadin_push_fails_during_deserialization_and_causes_refresh

Versions:
Flow: 24.3.5
Vaadin: 24.3.4
Spring Boot: 3.2.2
Java: Oracle Corporation 17
OS: amd64 Windows 10 10.0
Browser: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/121.0.0.0 Safari/537.36
Live reload: Java unavailable
(JRebel): Front end active

@mcollovati
Copy link
Contributor

In this case, it appears that the Flow client, for some reason (page reload? Navigating away?), is closing the push connection (X-Atmosphere-Transport=close), not actually receiving updates, but what's weird is that the 405 response code.
Currently, I couldn't find any Flow nor Atmosphere code that is sending a 405.
Are there any relevant logs on the server related to the failing request?

@MichaelPluessErni
Copy link
Author

@mcollovati Unfortunately, I could not find related messages in the logs.

@mcollovati mcollovati self-assigned this Mar 28, 2024
@mcollovati mcollovati moved this from 🟢Ready to Go to ⚒️ In progress in Vaadin Flow ongoing work (Vaadin 10+) Mar 28, 2024
@mcollovati
Copy link
Contributor

Unfortunately, I'm unable to reproduce the PUSH 405 failure.
However, I think the PUSH request failure is a consequence of the page reload, not the cause.

For further investigation, it would be good to have the trace of the previous UIDL request (request + response payloads) and, if Spring Security is configured for the application, the server logs with category org.springframework.security at debug level.

@mcollovati
Copy link
Contributor

@MichaelPluessErni additional question: is this happening in production or development mode?

@MichaelPluessErni
Copy link
Author

@mcollovati this happens in production mode.

I'll have a look whether I can procure a logging trace as described in your previous post.

@mcollovati
Copy link
Contributor

Testing locally, I had a confirmation that the POST PUSH request is caused by a page reload, not the opposite.
On page reload, Flow client closes the atmosphere connection, but it looks like that currently requests to /VAADIN/push are not considered as internal request and this may cause some Spring Security filter to check a request that should not be blocked.

@MichaelPluessErni
Copy link
Author

I've been unable to replicate the 405 Error Code for some time. Instead I've observed different behaviour, that might be related:

When having the website open and restarting the pod, sometimes the website stays at it is (desired) and sometimes it reloads and goes back to the login screen (not desired).

In the case where it reloads, I've seen in the last "app/?v-r=uidl&v-uild=1" Request that two Set-Cookie headers were added. In most cases these headers are not present. Might this be related and cause a reload?

pod_restart_website_reload

In cases where there was no reload, an "app/?v-r..." request was not present.

I hope this helps / gives a clue.

@mcollovati
Copy link
Contributor

mcollovati commented Apr 17, 2024

It would be good to know the contents of the UIDL request.
About the cookies, I think they are correct if the server changed.
Could you please also check that the request causing the reload has the clusterKey⁣ cookie correctly set? Without it, the session cannot be restored.

@MichaelPluessErni
Copy link
Author

The clusterKey is set correctly.

Contents of the UIDL request:

Request headers:

:authority:
XXXX-3154.XXXX
:method:
POST
:path:
/app/?v-r=uidl&v-uiId=1
:scheme:
https
Accept:
*/*
Accept-Encoding:
gzip, deflate, br, zstd
Accept-Language:
de-DE,de;q=0.9,en-US;q=0.8,en;q=0.7
Content-Length:
342
Content-Type:
application/json; charset=UTF-8
Cookie:
XXXX-config-point-of-sale=2875; clusterKey=4f090fde-90f8-4526-b91b-acc3591a9501; ingress-nginx-LB-cookie=6dfbdf159c4685fa5a1a066096b6f7a3|e307bd8c560d84365a1cbd65ac4ddd3d; JSESSIONID=18CB36FCF481A01E31D721D9F00A003C
Origin:
https://XXXX-gke-XXXX-3154.XXXX
Sec-Ch-Ua:
"Google Chrome";v="123", "Not:A-Brand";v="8", "Chromium";v="123"
Sec-Ch-Ua-Mobile:
?0
Sec-Ch-Ua-Platform:
"Windows"
Sec-Fetch-Dest:
empty
Sec-Fetch-Mode:
cors
Sec-Fetch-Site:
same-origin
User-Agent:
Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36

Payload:

{"csrfToken":"73ef5d1f-055e-40f3-8770-1357b60e08d7","rpc":[{"type":"event","node":84,"event":"click","data":{"event.shiftKey":false,"event.metaKey":false,"event.detail":1,"event.ctrlKey":false,"event.clientX":546,"event.clientY":819,"event.altKey":false,"event.button":0,"event.screenY":-534,"event.screenX":1526}}],"syncId":22,"clientId":22}

Interestingly, the reload seems to be triggered by a click on the website. It does not reload of its own beforehand.

@mcollovati
Copy link
Contributor

Could you post also the content of the response?

@MichaelPluessErni
Copy link
Author

MichaelPluessErni commented Apr 17, 2024

Example of the response headers of one of these requests where a reload happened:

Cache-Control:
no-cache, no-store, must-revalidate
Content-Encoding:
gzip
Content-Security-Policy:
default-src 'self'; script-src 'self' 'unsafe-inline' 'unsafe-eval' blob:; connect-src 'self' wss://*.coop.ch https://sdk-api.scandit.com; img-src 'self' *.coop.ch data:; media-src 'self' *.coop.ch data:; style-src 'self' 'unsafe-inline'; font-src data:; manifest-src 'self' *.coop.ch;frame-ancestors 'none'; child-src blob:; worker-src 'self' blob:;
Content-Type:
application/json;charset=UTF-8
Date:
Wed, 17 Apr 2024 14:06:13 GMT
Expires:
0
Pragma:
no-cache
Referrer-Policy:
no-referrer
Set-Cookie:
ingress-nginx-LB-cookie=a3a7c471ec4fa61c0c868bf2a187a403|e307bd8c560d84365a1cbd65ac4ddd3d; Expires=Wed, 17-Apr-24 15:06:13 GMT; Max-Age=3600; Path=/; Secure; HttpOnly
Set-Cookie:
JSESSIONID=5816F213C529418F402BAFE9EC6749EE; Path=/; Secure; HttpOnly
Strict-Transport-Security:
max-age=15724800; includeSubDomains
Vary:
origin,access-control-request-method,access-control-request-headers,accept-encoding
X-Content-Type-Options:
nosniff
X-Frame-Options:
SAMEORIGIN

X-Xss-Protection:
0

(Edit: this is not quite correct) There does not seem to be a response body. Instead the browser debugger shows this message:

grafik

This seems to be expected Chrome behaviour: https://superuser.com/questions/1788537/why-do-chromes-developer-tools-fail-to-collect-data-consistently
I'll try to retrieve an example where the data is available.

@MichaelPluessErni
Copy link
Author

MichaelPluessErni commented Apr 24, 2024

I was able to retrieve an example where the page was reloaded. Here the issue seemed to have been a session loss.

Situation:

  • Pod was restarted
  • Text was entered into an input field
  • A button was clicked
  • Page was reloaded and login screen was shown

grafik

UIDL request:

{
  "csrfToken":"f2d302ca-9e27-407b-af89-676c263f72ef",
  "rpc":[
    {"type":"mSync","node":2193,"feature":1,"property":"value","value":"une description erreur et le chose plus importante: c'est très impossible"},
    {"type":"event","node":2193,"event":"change","data":{}}
  ],
  "syncId":44,
  "clientId":38
}

UIDL response:

for(;;);[{"meta":{"sessionExpired":true}}]

This triggered a push request:

PUSH request headers:

POST /app/VAADIN/push?v-r=push&v-uiId=1&v-pushId=17d14dc8-b141-4757-923b-95ef41cc67d7&X-Atmosphere-Transport=close&X-Atmosphere-tracking-id=82ff298d-1cf4-4aa4-b66c-b3b88c03c142&X-Vaadin-LastSeenServerSyncId=44 HTTP/2
Host: xxxx-gke-xxxx-3154.xxxx-gkej2ee-test3.hs-gc.xxxx.ch
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0
Accept: */*
Accept-Language: en-US,en;q=0.5
Accept-Encoding: gzip, deflate, br
Content-Type: text/plain;charset=UTF-8
Content-Length: 0
Origin: null
DNT: 1
Sec-Fetch-Dest: empty
Sec-Fetch-Mode: no-cors
Sec-Fetch-Site: same-origin
Connection: keep-alive
Cookie: xxxx-config-point-of-sale=6018; tws_camp=%7B%22medium%22%3A%22organic%22%2C%22source%22%3A%22google%22%7D; JSESSIONID=92C331B874BC506B18FE39D58FBF143C; clusterKey=298cb9f4-c141-42bf-a435-a8c1ebf1d4a1; ingress-nginx-LB-cookie=1e41174373e4e3a366748c43964349aa|e307bd8c560d84365a1cbd65ac4ddd3d
TE: trailers

PUSH response headers:

HTTP/2 302 
date: Wed, 24 Apr 2024 11:29:10 GMT
content-length: 0
location: https://xxxx-gke-xxxx-3154.xxxx-gkej2ee-test3.hs-gc.xxxx.ch/app/login
vary: Origin
vary: Access-Control-Request-Method
vary: Access-Control-Request-Headers
x-content-type-options: nosniff
x-xss-protection: 0
cache-control: no-cache, no-store, max-age=0, must-revalidate
pragma: no-cache
expires: 0
strict-transport-security: max-age=15724800; includeSubDomains
x-frame-options: SAMEORIGIN
content-security-policy: default-src 'self'; script-src 'self' 'unsafe-inline' 'unsafe-eval' blob:; connect-src 'self' wss://*.xxxx.ch https://sdk-api.scandit.com; img-src 'self' *.xxxx.ch data:; media-src 'self' *.xxxx.ch data:; style-src 'self' 'unsafe-inline'; font-src data:; manifest-src 'self' *.xxxx.ch;frame-ancestors 'none'; child-src blob:; worker-src 'self' blob:;
referrer-policy: no-referrer
X-Firefox-Spdy: h2

Logs:
The serialisation to Redis seems to have worked:

2024-04-24 13:29:14.633
Marking serialization complete for 298cb9f4-c141-42bf-a435-a8c1ebf1d4a1

2024-04-24 13:29:14.633
Session 298cb9f4-c141-42bf-a435-a8c1ebf1d4a1 sent to Redis

2024-04-24 13:29:14.536
Sending session 298cb9f4-c141-42bf-a435-a8c1ebf1d4a1 to Redis

I hope this helps. Let me know if you need anything else.

@mcollovati
Copy link
Contributor

Thanks, @MichaelPluessErni
The sessionExpired message is what I expected to see, causing the client to close the push connection.

One thing to notice is that the response to the UIDL request has a set-cookie header for JSESSIONID.
But unfortunately, the screenshot does not show all the cookies sent by the client.
It would be great to check if the request has a JSESSIONID different from the one in the response.

I'll have to find a way to reproduce the issues constantly and debug the session expiration handlig.

@mcollovati
Copy link
Contributor

mcollovati commented Jun 6, 2024

This comment on a Flow issue may be related to the session expiration case: vaadin/flow#12640 (comment)

@mcollovati mcollovati removed their assignment Oct 10, 2024
mcollovati added a commit that referenced this issue Oct 14, 2024
Currently clusterKey cookie is set only when an HTTP session exists.
In addition to the cookie, the key is also set as a session attribute
so that SessionSerializer can fetch it later.
However, if two or more concurrent requests are sent from the client,
all of them create a new cookie, but the session attribute gets the value
of the first one. This causes the distributed session to be written with
a wrong key and when there a server switch the session cannot be restored.
This change sets the clusterKey cookie even if there is not yet an HTTP
session, so the key is only defined during first request and remains stable
with subsequent calls; once the HTTP session is create, the key is stored
as an attribute.

Potentially fixes #111

See https://github.com/vaadin/kubernetes-kit/issues/111\#issuecomment-2074909790
@github-project-automation github-project-automation bot moved this from ⚒️ In progress to Done in Vaadin Flow ongoing work (Vaadin 10+) Oct 29, 2024
@mcollovati
Copy link
Contributor

Re-opening because it is not confirmed that the referenced fix resolves this issue

@mcollovati mcollovati reopened this Oct 29, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
Development

Successfully merging a pull request may close this issue.

2 participants