Details
-
Bug
-
Resolution: Unresolved
-
Major
-
None
-
17.1.0
-
None
-
Unknown
-
Description
This bug has been found while investigating a flickering behaviour on NotificationsIT#simpleNotifications test. It's reproducing around 25% of the time when running the test: we simplified the original test to keep the setup of 2 users, then login with user1 perform a page creation, login with user2 perform notification set up, login with user1 and start creating pages. All operations are going through UI (no REST API used for creating pages) and to login users we use the standard form through TestUtils#login without performing a logout first. We added a check in the for loop for creating pages, ensuring that the value of the page is correct: 25% of the time the value is not correct as a CSRF token error occurs.
It appeared when investigating on the bug that User1 is supposed to perform the page creation, and its token is properly cached when it's logged-in. However, we found that a few milliseconds after User1 logged in AJAX requests are triggered to the REST API for displaying icon and for getting notifications count: those requests, 25% of the time, are still using User2 credentials.
To be more specific, it appeared that sometimes, the first request happening after User1 log-in, triggers a cookie authentification using User2 information. We also showed that the session invalidation method, and the method to replace cookie information were properly called when User1 is logged in. We even demonstrated that after calling the session invalidation method a new HttpSession was used, than the previous one, and when the request triggers a new cookie authentication, then it's again a new HttpSession. Here's an excerpt of the logs:
19:25:46.697 [docker-java-stream-1307036906] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2025-03-17 18:25:46,696 [http-nio-8080-exec-10 - http://xwikiweb:8080/xwiki/bin/logi nsubmit/XWiki/XWikiLogin?form_token=dXq17MlMoAo4WfQqG8IUBA&xredirect=http%3A%2F%2Fxwikiweb%3A8080%2Fxwiki%2Fbin%2Fregister%2FXWiki%2FRegister%3F_%3D1742235946689&j_password=notificatio nsUser1&j_username=NotificationsITuser1&] WARN .x.x.u.i.x.MyFormAuthenticator - New login with username [NotificationsITuser1] but session contains [SimplePrincipal[name = 'xwiki:XWik i.NotificationsITuser2']] and principal is [SimplePrincipal[name = 'xwiki:XWiki.NotificationsITuser2']]. Session is [7AD2BC7545B2FE47F432029EEA6EB5AD] 19:25:46.697 [docker-java-stream-1307036906] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2025-03-17 18:25:46,696 [http-nio-8080-exec-10 - http://xwikiweb:8080/xwiki/bin/logi nsubmit/XWiki/XWikiLogin?form_token=dXq17MlMoAo4WfQqG8IUBA&xredirect=http%3A%2F%2Fxwikiweb%3A8080%2Fxwiki%2Fbin%2Fregister%2FXWiki%2FRegister%3F_%3D1742235946689&j_password=notificatio nsUser1&j_username=NotificationsITuser1&] WARN .x.x.u.i.x.MyFormAuthenticator - Invalidating session 19:25:46.697 [docker-java-stream-1307036906] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2025-03-17 18:25:46,697 [http-nio-8080-exec-10 - http://xwikiweb:8080/xwiki/bin/logi nsubmit/XWiki/XWikiLogin?form_token=dXq17MlMoAo4WfQqG8IUBA&xredirect=http%3A%2F%2Fxwikiweb%3A8080%2Fxwiki%2Fbin%2Fregister%2FXWiki%2FRegister%3F_%3D1742235946689&j_password=notificatio nsUser1&j_username=NotificationsITuser1&] WARN .x.x.u.i.x.MyFormAuthenticator - Call rememberLogin with user [NotificationsITuser1] 19:25:46.697 [docker-java-stream-1307036906] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2025-03-17 18:25:46,697 [http-nio-8080-exec-10 - http://xwikiweb:8080/xwiki/bin/logi nsubmit/XWiki/XWikiLogin?form_token=dXq17MlMoAo4WfQqG8IUBA&xredirect=http%3A%2F%2Fxwikiweb%3A8080%2Fxwiki%2Fbin%2Fregister%2FXWiki%2FRegister%3F_%3D1742235946689&j_password=notificatio nsUser1&j_username=NotificationsITuser1&] WARN u.i.x.MyPersistentLoginManager - Answering Set-Cookie [username="5Osm0gvQHqYcV7wNtk8e5+9gSoFBpFOv"; Version=1; Path=/; HttpOnly] 19:25:46.697 [docker-java-stream-1307036906] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2025-03-17 18:25:46,697 [http-nio-8080-exec-10 - http://xwikiweb:8080/xwiki/bin/logi nsubmit/XWiki/XWikiLogin?form_token=dXq17MlMoAo4WfQqG8IUBA&xredirect=http%3A%2F%2Fxwikiweb%3A8080%2Fxwiki%2Fbin%2Fregister%2FXWiki%2FRegister%3F_%3D1742235946689&j_password=notificatio nsUser1&j_username=NotificationsITuser1&] WARN u.i.x.MyPersistentLoginManager - Answering Set-Cookie [password="ApSPxyya5Q+3FneJUyVMYhRw2Jr81i0p"; Version=1; Path=/; HttpOnly] 19:25:46.698 [docker-java-stream-1307036906] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2025-03-17 18:25:46,697 [http-nio-8080-exec-10 - http://xwikiweb:8080/xwiki/bin/logi nsubmit/XWiki/XWikiLogin?form_token=dXq17MlMoAo4WfQqG8IUBA&xredirect=http%3A%2F%2Fxwikiweb%3A8080%2Fxwiki%2Fbin%2Fregister%2FXWiki%2FRegister%3F_%3D1742235946689&j_password=notificatio nsUser1&j_username=NotificationsITuser1&] WARN u.i.x.MyPersistentLoginManager - Answering Set-Cookie [rememberme="false"; Version=1; Path=/; HttpOnly] 19:25:46.698 [docker-java-stream-1307036906] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2025-03-17 18:25:46,697 [http-nio-8080-exec-10 - http://xwikiweb:8080/xwiki/bin/logi nsubmit/XWiki/XWikiLogin?form_token=dXq17MlMoAo4WfQqG8IUBA&xredirect=http%3A%2F%2Fxwikiweb%3A8080%2Fxwiki%2Fbin%2Fregister%2FXWiki%2FRegister%3F_%3D1742235946689&j_password=notificatio nsUser1&j_username=NotificationsITuser1&] WARN u.i.x.MyPersistentLoginManager - Answering Set-Cookie [validation="e699cc53f5b7e5073e7867ef5a6137a1"; Version=1; Path=/; HttpOnly] 19:25:46.698 [docker-java-stream-1307036906] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2025-03-17 18:25:46,697 [http-nio-8080-exec-10 - http://xwikiweb:8080/xwiki/bin/logi nsubmit/XWiki/XWikiLogin?form_token=dXq17MlMoAo4WfQqG8IUBA&xredirect=http%3A%2F%2Fxwikiweb%3A8080%2Fxwiki%2Fbin%2Fregister%2FXWiki%2FRegister%3F_%3D1742235946689&j_password=notificatio nsUser1&j_username=NotificationsITuser1&] WARN .x.x.u.i.x.MyFormAuthenticator - After setting user principal. User session is [SimplePrincipal[name = 'xwiki:XWiki.NotificationsITuser1 ']] and user principal is [SimplePrincipal[name = 'xwiki:XWiki.NotificationsITuser1']] HttpSession is [308FBDDD41939AB4D150D64661D2F068] 19:25:46.699 [docker-java-stream-1307036906] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2025-03-17 18:25:46,698 [http-nio-8080-exec-10 - http://xwikiweb:8080/xwiki/bin/logi nsubmit/XWiki/XWikiLogin?form_token=dXq17MlMoAo4WfQqG8IUBA&xredirect=http%3A%2F%2Fxwikiweb%3A8080%2Fxwiki%2Fbin%2Fregister%2FXWiki%2FRegister%3F_%3D1742235946689&j_password=notificatio nsUser1&j_username=NotificationsITuser1&] WARN c.x.x.w.XWikiAction - Response headers is [Content-Script-Type : text/javascriptSet-Cookie : username="5Osm0gvQHqYcV7wNtk8e5+ 9gSoFBpFOv"; Version=1; Path=/; HttpOnlySet-Cookie : username="5Osm0gvQHqYcV7wNtk8e5+9gSoFBpFOv"; Version=1; Path=/; HttpOnlySet-Cookie : username="5Osm0gvQHqYcV7wNtk8e5+9gSoFBpFOv"; V ersion=1; Path=/; HttpOnlySet-Cookie : username="5Osm0gvQHqYcV7wNtk8e5+9gSoFBpFOv"; Version=1; Path=/; HttpOnlySet-Cookie : username="5Osm0gvQHqYcV7wNtk8e5+9gSoFBpFOv"; Version=1; Path =/; HttpOnlyLocation : http://xwikiweb:8080/xwiki/bin/register/XWiki/Register?_=1742235946689] 19:25:46.699 [docker-java-stream-1307036906] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2025-03-17 18:25:46,699 [http-nio-8080-exec-9 - http://xwikiweb:8080/xwiki/rest/wiki s/xwiki/iconThemes/icons?name=bell] WARN .x.x.u.i.x.MyFormAuthenticator - COOKIE login with username [xwiki:XWiki.NotificationsITuser2] but session contains [null] and principal is [n ull]. Session is [C609CA6BA024E2C4BF323DE011A341DF] 19:25:46.699 [docker-java-stream-1307036906] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2025-03-17 18:25:46,699 [http-nio-8080-exec-9 - http://xwikiweb:8080/xwiki/rest/wiki s/xwiki/iconThemes/icons?name=bell] WARN ikiContextInitializationFilter - Obtained user principal from XWikiRequest after check auth: [null] User in session [SimplePrincipal[name = 'x wiki:XWiki.NotificationsITuser2']] 19:25:46.699 [docker-java-stream-1307036906] INFO o.x.t.d.i.j.s.ServletContainerExecutor - STDOUT: 2025-03-17 18:25:46,699 [http-nio-8080-exec-9 - http://xwikiweb:8080/xwiki/rest/wiki s/xwiki/iconThemes/icons?name=bell] WARN ikiContextInitializationFilter - XWiki user XWiki.NotificationsITuser2 is authenticated
So there's apparently 2 different but probably linked bugs:
1. Somehow the HttpSession information seems to be wrongly reused, even if the session is supposed to be different according to its ID
2. for some reason, the cookie information is not invalidated properly since we log in again with User2 while it's now supposed to contain User1 information
Note that apparently the bug only reproduced when using Firefox, where it appears 25% of the time in average, while on Chrome I didn't get a single failure in 20 runs. Also I obtained same failures and same information on both jetty and tomcat.
Attachments
Issue Links
- is related to
-
-
- Open
-