Hi all,
I'm writing to the list in the hope of receiving some feedback,
questions, maybe answers to help us solve a conundrum with sessions we
have on our Wikibase/Mediawiki installation.
We're running two different docker-based wikibase installations (one
staging, one production) on two separate virtual machines. Both use the
SimpleSaml extension to connect to a SAML implementation, but we have
found that the random session deletion happens both with and without the
SAML extension used.
The symptoms that we've seen are that out of the blue, users are
disconnected from mediawiki. Since we use SAML, it's enough to click the
Login link to again be connected.
The duration or number of requests until a session is deleted seems
random. It does appear though, that the more (or more frequent) requests
are made (and thus background jobs run) the quicker a session is deleted.
We have even tried setting $wgObjectCacheSessionExpiry = 7200; in order
to exclude any TimeZone related issues which was our first suspicion.
However, changing this from the default 1h session expiry does not
change the behavior we're seeing.
Sessions are deleted regardless of their nature. E.g. sessions
established for oauth connections are deleted in the same way and at the
same time as other sessions. E.g. using wikidataintegrator we're able to
run a number of requests until the CSRF token expires (with the number
of requests that succeed before this happens being random):
[…]
Created Item Q379 from
Classhttp://www.cidoc-crm.org/cidoc-crm/E34_Inscription.
Created Item Q380 from
Classhttp://www.cidoc-crm.org/cidoc-crm/E53_Place.
Errorwhile writing to Wikidata
ERROR creating class referencefor
http://www.cidoc-crm.org/cidoc-crm/E35_Title:
{'error': {'code':'badtoken','info':'Invalid CSRF
token.','*':'See
https://saf-dev.bnl.lu/w/api.php for API usage. Subscribe
to the
mediawiki-api-announce mailing list at
<https://lists.wikimedia.org/mailman/listinfo/mediawiki-api-announce>
for notice of API deprecations and breaking changes.'}}
Errorwhile writing to Wikidata
ERROR creating object property referencefor
http://www.cidoc-crm.org/cidoc-crm/P16_used_specific_object: {'error':
{'code':'badtoken','info':'Invalid CSRF
token.','*':'See
https://saf-dev.bnl.lu/w/api.php for API usage. Subscribe
to the
mediawiki-api-announce mailing list at
<https://lists.wikimedia.org/mailman/listinfo/mediawiki-api-announce>
for notice of API deprecations and breaking changes.'}}
If sessions are not randomly deleted, then session renewal seems to work
as planned with them being renewed after half their expiry time:
|[DBQuery] SqlBagOStuff::fetchBlobMulti [0s] db.svc:3306: SELECT
keyname,value,exptime FROM `objectcache` WHE RE keyname =
'mediawiki:MWSession:n9krnsfa303qk9c2osp6c81tp1k2bp5b' [session]
SessionBackend
"require/require_once/MediaWiki\Session\Session->renew/MediaWiki\Session\SessionBackend-
renew" metadata dirty for renew():
require/require_once/MediaWiki\Session\Session->renew/MediaWiki\Session\Sessi
onBackend->renew [session] SessionBackend
"n9krnsfa303qk9c2osp6c81tp1k2bp5b" force-persist for renew():
require/require_once/Media
Wiki\Session\Session->renew/MediaWiki\Session\SessionBackend->renew
[session] SessionBackend "n9krnsfa303qk9c2osp6c81tp1k2bp5b" save:
dataDirty=0 metaDirty=1 forcePersist=1 [cookie] setcookie:
"mediawiki_session", "n9krnsfa303qk9c2osp6c81tp1k2bp5b",
"0", "/", "",
"1", "1", "" [cookie] setcookie:
"mediawikiUserID", "13", "1648233666",
"/", "", "1", "1", "" [cookie]
setcookie: "mediawikiUserName", "Ibl676",
"1648233666", "/", "", "1", "1",
"" [cookie] already deleted setcookie:
"mediawikiToken", "", "1614105666", "/",
"", "1", "1", "" [cookie]
already deleted setcookie: "forceHTTPS", "", "1614105666",
"/", "", "",
"1", "" [session] SessionBackend
"n9krnsfa303qk9c2osp6c81tp1k2bp5b"
Taking over PHP session [session] SessionBackend
"n9krnsfa303qk9c2osp6c81tp1k2bp5b" save: dataDirty=0 metaDirty=1
forcePersist=1 [cookie] already set setcookie: "mediawiki_session",
"n9krnsfa303qk9c2osp6c81tp1k2bp5b", "0", "/", "",
"1", "1", "" [cookie]
already set setcookie: "mediawikiUserID", "13",
"1648233666", "/", "",
"1", "1", "" [cookie] already set setcookie:
"mediawikiUserName",
"Ibl676", "1648233666", "/", "", "1",
"1", "" [cookie] already deleted
setcookie: "mediawikiToken", "", "1614105666",
"/", "", "1", "1", ""
[cookie] already deleted setcookie: "forceHTTPS", "",
"1614105666", "/",
"", "", "1", "" [DBQuery]
SqlBagOStuff::updateTable [0.002s]
db.svc:3306: REPLACE INTO `objectcache` (keyname,value,exptime) VALU ES
('mediawiki:MWSession:n9krnsfa303qk9c2osp6c81tp1k2bp5b','...\0','20220223194106')|
Here is one example where the session got deleted by whatever feels
responsible to do so:
MariaDB [mediawiki] > select keyname, exptimefrom objectcachewhere keynamelike
'mediawiki:MWSession%';
+------------------------------------------------------+---------------------+
| keyname | exptime |
+------------------------------------------------------+---------------------+
| mediawiki:MWSession:t7d5lms2nrma6k627c6usrgc6289en3a |2022-03-24 17:34:34 |
+------------------------------------------------------+---------------------+
1 rowin set (0.001 sec)
MariaDB [mediawiki] > select keyname, exptimefrom objectcachewhere keynamelike
'mediawiki:MWSession%';
Emptyset (0.001 sec)
MariaDB [mediawiki] > select now();
+---------------------+
| now() |
+---------------------+
|2022-03-24 17:37:15 |
+---------------------+
1 rowin set (0.024 sec)
The only instance of me finding something remotely related to randomly
deleting a session would be these log entries:
|2022-03-24 17:03:29 51290acae35a mediawiki: SessionManager using store
SqlBagOStuff 2022-03-24 17:03:29 51290acae35a mediawiki: Saving all
sessions on shutdown 2022-03-24 17:03:29 51290acae35a mediawiki:
SessionManager using store SqlBagOStuff 2022-03-24 17:03:29 51290acae35a
mediawiki: Session
"[30]MediaWiki\Session\CookieSessionProvider<-:13:Ibl676>8favvi92d08njut82j66un60r601titn":
Unverified user provided and no metadata to auth it 2022-03-24 17:03:29
51290acae35a mediawiki: setcookie: "mediawiki_session", "",
"1616605409", "/", "", "1", "1",
"" 2022-03-24 17:03:29 51290acae35a
mediawiki: setcookie: "mediawikiUserID", "", "1616605409",
"/", "", "1",
"1", "" 2022-03-24 17:03:29 51290acae35a mediawiki: already deleted
setcookie: "mediawikiToken", "", "1616605409",
"/", "", "1", "1", ""
2022-03-24 17:03:29 51290acae35a mediawiki: already deleted setcookie:
"forceHTTPS", "", "1616605409", "/", "",
"", "1", "" 2022-03-24 17:03:29
51290acae35a mediawiki: SessionBackend
"ujf6rcheseb51lpaojrqggb4c23s1flr" is unsaved, marking dirty in
constructor 2022-03-24 17:03:29 51290acae35a mediawiki: SessionBackend
"ujf6rcheseb51lpaojrqggb4c23s1flr" save: dataDirty=1 metaDirty=1
forcePersist=0 2022-03-24 17:03:29 51290acae35a mediawiki: already
deleted setcookie: "mediawiki_session", "", "1616605409",
"/", "", "1",
"1", "" 2022-03-24 17:03:29 51290acae35a mediawiki: already deleted
setcookie: "mediawikiUserID", "", "1616605409",
"/", "", "1", "1", ""
2022-03-24 17:03:29 51290acae35a mediawiki: already deleted setcookie:
"mediawikiToken", "", "1616605409", "/",
"", "1", "1", "" 2022-03-24
17:03:29 51290acae35a mediawiki: already deleted setcookie:
"forceHTTPS", "", "1616605409", "/", "",
"", "1", "" 2022-03-24 17:03:29
51290acae35a mediawiki: Saving all sessions on shutdown |
IBL676 is my SAML ID. I'm not sure why the user is unverified and what
metadata would be used/required to verify it?
Looking forward to any advice on how to further investigate what is
going on here.
Regards,
David
--
*TenTwentyFour S.à r.l.*
www.tentwentyfour.lu <https://www.tentwentyfour.lu>
*T*: +352 20 211 1024
*F*: +352 20 211 1023
1 place de l'Hôtel de Ville
4138 Esch-sur-Alzette