Mediawiki is not functional

Avron · April 6, 2024, 12:29pm

Mediawiki is not functional on my Pioneer with HDD (it was functional at some point, it has been dysfunctional for at least a week, perhaps longer).

The journal shows:

avril 06 02:07:07 hector systemd[1]: Started mediawiki-jobrunner.service - MediaWiki job runner.
avril 06 02:08:01 hector CRON[19253]: pam_unix(cron:session): session opened for user daemon(uid=1) by (uid=0)
avril 06 02:08:01 hector CRON[19254]: (daemon) CMD (test -x /usr/bin/debsecan && /usr/bin/debsecan --cron)
avril 06 02:08:10 hector CRON[19253]: pam_unix(cron:session): session closed for user daemon
avril 06 02:09:01 hector CRON[19262]: pam_unix(cron:session): session opened for user root(uid=0) by (uid=0)
avril 06 02:09:01 hector CRON[19263]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
avril 06 02:09:01 hector CRON[19262]: pam_unix(cron:session): session closed for user root
avril 06 02:09:04 hector systemd[1]: Starting phpsessionclean.service - Clean php session files...
avril 06 02:09:05 hector systemd[1]: phpsessionclean.service: Deactivated successfully.
avril 06 02:09:05 hector systemd[1]: Finished phpsessionclean.service - Clean php session files.
avril 06 02:09:05 hector systemd[1]: phpsessionclean.service: Consumed 1.403s CPU time.
avril 06 02:12:07 hector systemd[1]: mediawiki-jobrunner.service: Service reached runtime time limit. Stopping.
avril 06 02:12:07 hector systemd[1]: mediawiki-jobrunner.service: Failed with result 'timeout'.
avril 06 02:12:07 hector systemd[1]: mediawiki-jobrunner.service: Consumed 4min 59.318s CPU time.
avril 06 02:12:23 hector systemd[1]: mediawiki-jobrunner.service: Scheduled restart job, restart counter is at 542.
avril 06 02:12:23 hector systemd[1]: Stopped mediawiki-jobrunner.service - MediaWiki job runner.
avril 06 02:12:23 hector systemd[1]: mediawiki-jobrunner.service: Consumed 4min 59.318s CPU time.
avril 06 02:12:23 hector systemd[1]: Started mediawiki-jobrunner.service - MediaWiki job runner.`

This repeats itself continuously. I tried clicking on the button in the diagnostics in plinth to execute the configuration again, this makes no difference. I also rebooted, no change.

Any suggestion is welcome.

fefekrzr · April 7, 2024, 12:52am

Hello,

Just to throw some ideas around.

Does the Diagnostics page show any failure for MediaWiki? If so, which diagnostic failed?
Have you tried running:
journalctl -xe -u mediawiki-jobrunner
Or checked the logs of the MediaWiki service through the Logs section in Cockpit?

Avron · April 8, 2024, 8:13am

These one fail:
Access URL https://127.0.0.1/mediawiki/ failed
Access URL https://[::1]/mediawiki/ failed
Access URL https://192.168.48.222/mediawiki/ failed
Access URL https://[fe80::4493:3431:8194:918d%end0]/mediawiki/ failed
Access URL https://localhost/mediawiki/ failed
Access URL https://localhost/mediawiki/ failed
Access URL https://hector/mediawiki/ failed

This is not surprising since the service isn’t started.

The journal you mentioned gives this:

-- The job identifier is 141134.
Apr 08 10:04:54 hector systemd[1]: mediawiki-jobrunner.service: Service reached runtime time limit. Stopping.
Apr 08 10:04:54 hector systemd[1]: mediawiki-jobrunner.service: Failed with result 'timeout'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- The unit mediawiki-jobrunner.service has entered the 'failed' state with result 'timeout'.
Apr 08 10:04:54 hector systemd[1]: mediawiki-jobrunner.service: Consumed 4min 41.791s CPU time.
-- Subject: Resources consumed by unit runtime
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- The unit mediawiki-jobrunner.service completed and consumed the indicated resources.
Apr 08 10:05:09 hector systemd[1]: mediawiki-jobrunner.service: Scheduled restart job, restart counter is at 81.
-- Subject: Automatic restarting of a unit has been scheduled
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- Automatic restarting of the unit mediawiki-jobrunner.service has been scheduled, as the result for
-- the configured Restart= setting for the unit.
Apr 08 10:05:09 hector systemd[1]: Stopped mediawiki-jobrunner.service - MediaWiki job runner.
-- Subject: A stop job for unit mediawiki-jobrunner.service has finished
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- A stop job for unit mediawiki-jobrunner.service has finished.
-- 
-- The job identifier is 141367 and the job result is done.
Apr 08 10:05:09 hector systemd[1]: mediawiki-jobrunner.service: Consumed 4min 41.791s CPU time.
-- Subject: Resources consumed by unit runtime
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- The unit mediawiki-jobrunner.service completed and consumed the indicated resources.
Apr 08 10:05:09 hector systemd[1]: Started mediawiki-jobrunner.service - MediaWiki job runner.
-- Subject: A start job for unit mediawiki-jobrunner.service has finished successfully
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- A start job for unit mediawiki-jobrunner.service has finished successfully.

This is the last attempt to start, you see the restart counter is at 81, so there are the 80 previous ones before.

Ged296123 · April 8, 2024, 6:00pm

@Avron this happened to me at some point as well. if i remember right, i backed up my wiki, completely removed it and did a fresh install and restore.
i know it’s not a solution to the problem (whatever it is) but just my two cents - hope it works for you.

jvalleroy · April 9, 2024, 1:34pm

I’m not sure if mediawiki-jobrunner.service is actually the most relevant service here. MediaWiki is a PHP application, so it is served by apache2 with php-fpm. mediawiki-jobrunner is probably used for some cleanup tasks in the background.

Avron · April 9, 2024, 2:20pm

When I try loading the mediawiki main page, this is what I see in the journal:

avril 09 16:15:26 hector apache-error[11090]: [ssl:warn] [pid 11093:tid 11149] (22)Invalid argument: AH02026: Failed to acquire SSL session cache lock
avril 09 16:15:26 hector apache-error[11090]: [ssl:warn] [pid 11093:tid 11149] (22)Invalid argument: AH02027: Failed to release SSL session cache lock
avril 09 16:15:26 hector apache-error[11090]: [ssl:warn] [pid 11093:tid 11149] (22)Invalid argument: AH02026: Failed to acquire SSL session cache lock
avril 09 16:15:26 hector apache-error[11090]: [ssl:warn] [pid 11093:tid 11149] (22)Invalid argument: AH02027: Failed to release SSL session cache lock
avril 09 16:15:56 hector apache-error[11090]: [proxy_fcgi:error] [pid 11093:tid 11095] [client someIP:32738] AH01071: Got error 'PHP message: PHP Fatal error:  Maximum execution time of 30 seconds exceeded in /usr/share/mediawiki/includes/WebRequest.php on line 954', referer https://hector/plinth
avril 09 16:16:01 hector apache-access[11091]: hector:443 someIP - - [09/Apr/2024:16:15:26 +0200] "GET /mediawiki/ HTTP/2.0" 500 0 "https://hector/plinth" "Mozilla/5.0 (X11; Linux x86_64; rv:124.0) Gecko/20100101 Firefox/124.0"

(I removed the IP address and domain names)

The first messages appear immediately (the ones marked 16:15:26) when trying to load the page. I don’t know whether that can help understanding what is happening.

Avron · May 31, 2024, 4:09pm

What did you do for that?

Ged296123 · May 31, 2024, 4:25pm

been some time… wasnt sure if fbx properly backed up (in any case restoring with previous settings was not something i preferred). didnt take any chances.

Avron · June 11, 2024, 8:30pm

I deactivated and reactivated mediawiki, no change.

I get this (replacing the host name with <localname> and the FQDN with <myhostname>:

juin 11 22:04:25 <localname> apachectl[2099]: [core:warn] [pid 2099:tid 2099] AH00114: Useless use of AllowOverride in line 2 of /etc/apache2/includes/freedombox-sharing.conf.
juin 11 22:04:25 <localname> apachectl[2099]: [core:warn] [pid 2099:tid 2099] AH00114: Useless use of AllowOverride in line 2 of /etc/apache2/includes/freedombox-sharing.conf.
juin 11 22:04:25 <localname> apache-error[1343]: [mpm_event:notice] [pid 1339:tid 1339] AH00493: SIGUSR1 received.  Doing graceful restart
juin 11 22:04:25 <localname> systemd[1]: Reloaded apache2.service - The Apache HTTP Server.
juin 11 22:04:26 <localname> apache-error[1343]: [core:warn] [pid 1339:tid 1339] AH00114: Useless use of AllowOverride in line 2 of /etc/apache2/includes/freedombox-sharing.conf.
juin 11 22:04:26 <localname> apache-error[1343]: [core:warn] [pid 1339:tid 1339] AH00114: Useless use of AllowOverride in line 2 of /etc/apache2/includes/freedombox-sharing.conf.
juin 11 22:04:26 <localname> apache-error[2100]: [ssl:warn] [pid 1339:tid 1339] AH01882: Init: this version of mod_ssl was compiled against a newer library (OpenSSL 3.0.13 30 Jan 2024 (OpenSSL 3.0.11 19 Sep 2023), version currently loaded is 0x300000B0) - may result in undefined or erroneous behavior
juin 11 22:04:26 <localname> apache-error[2100]: [ssl:warn] [pid 1339:tid 1339] AH01909: <localname>.<myhostname>:443:0 server certificate does NOT include an ID which matches the server name
juin 11 22:04:26 <localname> apache-error[2100]: [ssl:error] [pid 1339:tid 1339] AH02217: ssl_stapling_init_cert: can't retrieve issuer certificate! [subject: CN=freedombox / issuer: CN=freedombox / serial: 144EAD17AE690DA571493235DA50C60B4E2BA40C / notbefore: Jan 13 20:26:48 2024 GMT / notafter: Jan 10 20:26:48 2034 GMT]
juin 11 22:04:26 <localname> apache-error[2100]: [ssl:error] [pid 1339:tid 1339] AH02604: Unable to configure certificate <localname>.<myhostname>:443:0 for stapling
juin 11 22:04:26 <localname> apache-error[2100]: [mpm_event:notice] [pid 1339:tid 1339] AH00489: Apache/2.4.59 (Debian) mod_auth_pubtkt/0.13 OpenSSL/3.0.11 configured -- resuming normal operations
juin 11 22:04:26 <localname> apache-error[2100]: [core:notice] [pid 1339:tid 1339] AH00094: Command line: '/usr/sbin/apache2'
juin 11 22:04:26 <localname> apache-error[2100]: [mpm_event:warn] [pid 1339:tid 1339] AH00488: long lost child came home! (pid 1344)
juin 11 22:04:28 <localname> sudo[2005]: pam_unix(sudo:session): session closed for user root
juin 11 22:04:28 <localname> /usr/bin/plinth[606]: # apache..enable(…) 
juin 11 22:04:28 <localname> sudo[2209]:   plinth : PWD=/ ; USER=root ; COMMAND=/usr/share/plinth/actions/actions apache enable --write-fd 17
juin 11 22:04:28 <localname> sudo[2209]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=110)
juin 11 22:04:45 <localname> systemd[1]: Reloading apache2.service - The Apache HTTP Server...
juin 11 22:04:47 <localname> apachectl[2230]: [core:warn] [pid 2230:tid 2230] AH00114: Useless use of AllowOverride in line 2 of /etc/apache2/includes/freedombox-sharing.conf.
juin 11 22:04:47 <localname> apachectl[2230]: [core:warn] [pid 2230:tid 2230] AH00114: Useless use of AllowOverride in line 2 of /etc/apache2/includes/freedombox-sharing.conf.
juin 11 22:04:47 <localname> apache-error[2100]: [mpm_event:notice] [pid 1339:tid 1339] AH00493: SIGUSR1 received.  Doing graceful restart
juin 11 22:04:47 <localname> systemd[1]: Reloaded apache2.service - The Apache HTTP Server.
juin 11 22:04:47 <localname> apache-error[2100]: [core:warn] [pid 1339:tid 1339] AH00114: Useless use of AllowOverride in line 2 of /etc/apache2/includes/freedombox-sharing.conf.
juin 11 22:04:47 <localname> apache-error[2100]: [core:warn] [pid 1339:tid 1339] AH00114: Useless use of AllowOverride in line 2 of /etc/apache2/includes/freedombox-sharing.conf.
juin 11 22:04:48 <localname> apache-error[2231]: [ssl:warn] [pid 1339:tid 1339] AH01882: Init: this version of mod_ssl was compiled against a newer library (OpenSSL 3.0.13 30 Jan 2024 (OpenSSL 3.0.11 19 Sep 2023), version currently loaded is 0x300000B0) - may result in undefined or erroneous behavior
juin 11 22:04:48 <localname> apache-error[2231]: [ssl:warn] [pid 1339:tid 1339] AH01909: <localname>.<myhostname>:443:0 server certificate does NOT include an ID which matches the server name
juin 11 22:04:48 <localname> apache-error[2231]: [ssl:error] [pid 1339:tid 1339] AH02217: ssl_stapling_init_cert: can't retrieve issuer certificate! [subject: CN=freedombox / issuer: CN=freedombox / serial: 144EAD17AE690DA571493235DA50C60B4E2BA40C / notbefore: Jan 13 20:26:48 2024 GMT / notafter: Jan 10 20:26:48 2034 GMT]
juin 11 22:04:48 <localname> apache-error[2231]: [ssl:error] [pid 1339:tid 1339] AH02604: Unable to configure certificate <localname>.<myhostname>:443:0 for stapling
juin 11 22:04:48 <localname> apache-error[2231]: [mpm_event:notice] [pid 1339:tid 1339] AH00489: Apache/2.4.59 (Debian) mod_auth_pubtkt/0.13 OpenSSL/3.0.11 configured -- resuming normal operations
juin 11 22:04:48 <localname> apache-error[2231]: [core:notice] [pid 1339:tid 1339] AH00094: Command line: '/usr/sbin/apache2'
juin 11 22:04:48 <localname> apache-error[2231]: [mpm_event:warn] [pid 1339:tid 1339] AH00488: long lost child came home! (pid 2101)
juin 11 22:04:49 <localname> sudo[2209]: pam_unix(sudo:session): session closed for user root
juin 11 22:04:49 <localname> /usr/bin/plinth[606]: # plinth..enable(…) 
juin 11 22:04:50 <localname> sudo[2340]:   plinth : PWD=/ ; USER=root ; COMMAND=/usr/share/plinth/actions/actions plinth enable --write-fd 17
juin 11 22:04:50 <localname> sudo[2340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=110)
juin 11 22:05:29 <localname> /usr/share/plinth/actions/actions[2342]: Initialized apps - apache, api, names, avahi, storage, backups, cockpit, firewall, config, datetime, diagnostics, dynamicdns, first_boot, help, letsencrypt, networks, power, privacy, security, snapshot, ssh, sso, upgrades, users, bepasty, bind, calibre, coturn, deluge, ejabberd, email, gitweb, i2p, ikiwiki, infinoted, janus, jsxc, kiwix, matrixsynapse, mediawiki, minetest, minidlna, mumble, nextcloud, openvpn, pagekite, performance, privoxy, quassel, radicale, roundcube, rssbridge, samba, searx, shaarli, shadowsocks, shadowsocksserver, sharing, syncthing, tor, torproxy, transmission, ttrss, wireguard, wordpress, zoph
juin 11 22:05:30 <localname> systemd[1]: Reloading.
juin 11 22:05:40 <localname> systemd[1]: Started mediawiki-jobrunner.service - MediaWiki job runner.
juin 11 22:05:46 <localname> sudo[2340]: pam_unix(sudo:session): session closed for user root
juin 11 22:05:52 <localname> systemd[1]: Starting systemd-tmpfiles-clean.service - Cleanup of Temporary Directories...
juin 11 22:05:52 <localname> systemd[1]: systemd-tmpfiles-clean.service: Deactivated successfully.
juin 11 22:05:52 <localname> systemd[1]: Finished systemd-tmpfiles-clean.service - Cleanup of Temporary Directories.
juin 11 22:05:52 <localname> systemd[1]: run-credentials-systemd\x2dtmpfiles\x2dclean.service.mount: Deactivated successfully.
juin 11 22:05:59 <localname> apache-access[2232]: <myhostname>:443 192.168.1.254 - - [11/Jun/2024:22:05:47 +0200] "GET /plinth/apps/mediawiki/ HTTP/2.0" 200 12245 "https://<myhostname>/plinth/apps/mediawiki/" "Mozilla/5.0 (X11; Linux x86_64; rv:126.0) Gecko/20100101 Firefox/126.0"
juin 11 22:06:17 <localname> Tor-plinth[1756]: Self-testing indicates your ORPort 82.66.3.254:9001 is reachable from the outside. Excellent. Publishing server descriptor.
juin 11 22:06:18 <localname> Tor-plinth[1756]: Performing bandwidth self-test...done.
juin 11 22:06:44 <localname> Tor-plinth[1756]: http status 400 ("Tor version is insecure or unsupported. Please upgrade!") response from dirserver 66.111.2.131:9001. Please correct.
juin 11 22:06:51 <localname> apache-access[2232]: <myhostname>:443 192.168.1.254 - - [11/Jun/2024:22:06:49 +0200] "GET /plinth/apps/ HTTP/2.0" 200 4834 "https://<myhostname>/plinth/apps/mediawiki/" "Mozilla/5.0 (X11; Linux x86_64; rv:126.0) Gecko/20100101 Firefox/126.0"
juin 11 22:07:02 <localname> apache-access[2232]: <myhostname>:443 192.168.1.254 - - [11/Jun/2024:22:06:55 +0200] "GET /plinth/apps/mediawiki/ HTTP/2.0" 200 11795 "https://<myhostname>/plinth/apps/" "Mozilla/5.0 (X11; Linux x86_64; rv:126.0) Gecko/20100101 Firefox/126.0"
juin 11 22:07:05 <localname> apache-access[2232]: <myhostname>:443 192.168.1.254 - - [11/Jun/2024:22:07:05 +0200] "GET /mediawiki HTTP/2.0" 301 448 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:126.0) Gecko/20100101 Firefox/126.0"
juin 11 22:08:01 <localname> CRON[2411]: pam_unix(cron:session): session opened for user daemon(uid=1) by (uid=0)
juin 11 22:08:01 <localname> CRON[2412]: (daemon) CMD (test -x /usr/bin/debsecan && /usr/bin/debsecan --cron)
juin 11 22:08:15 <localname> apache-access[2232]: <localname>.<myhostname>:80 87.121.69.52 - - [11/Jun/2024:22:08:15 +0200] "CONNECT google.com:443 HTTP/1.1" 302 494 "-" "Go-http-client/1.1"
juin 11 22:08:29 <localname> CRON[2411]: pam_unix(cron:session): session closed for user daemon
juin 11 22:08:32 <localname> apache-error[2231]: [proxy_fcgi:error] [pid 2234:tid 2246] [client 192.168.1.254:45114] AH01071: Got error 'PHP message: PHP Fatal error:  Maximum execution time of 30 seconds exceeded in /usr/share/mediawiki/includes/exception/MWExceptionHandler.php on line 723'
juin 11 22:08:32 <localname> apache-access[2232]: <myhostname>:443 192.168.1.254 - - [11/Jun/2024:22:07:05 +0200] "GET /mediawiki/ HTTP/2.0" 500 67 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:126.0) Gecko/20100101 Firefox/126.0"

I don’t know whether the errors on certificates could explain why there is this “maximum execution time of 30 seconds”. Or should the duration of this timeout be increased, for something to complete?

Avron · July 2, 2024, 12:47pm

I made a fresh install and restored the backup but after restoring mediawiki, the behaviour is exactly as it was before, i.e. blank page and same things in the journal.

My wiki includes documentation that is essential for me and that I spent significant time writing, so it is very unfortunate that I can’t access it anymore. Perhaps the contents are in /var/lib/mediawiki-db/my_wiki.sqlite, but this is not text and I have zero knowledge of databases. I found out that with sqlite3, .dump text seems to give a lot of text, so I’ll use this to get my text.

Perhaps mediawiki is good for collaborative work but given this situation, I’ll revert to writing my documentation as html pages in a text editor as I did before.

Ged296123 · July 2, 2024, 5:45pm

Sorry to hear that @Avron.
Did you by any chance manually intervene with the mediwiki configurations (i mean not through plinth)?

Avron · July 3, 2024, 7:47am

No, I only did things through plinth.

I got my text directly from the sqlite file (in sqlite3, using select * from text;) but it was looking like multiple pieces, with some sentences cut in the middle, perhaps it has different edits as different entries in this text table, but since I did not have that many pages, rather than further searching how to extract them properly, I rewrote them, sometimes picking pieces of text.

I can’t retry now since I don’t get mediawiki to work, but I remember that writing and correcting things with mediawiki felt really slow. The main benefit of mediawiki over writing plain html that I noticed was to automatically get a consistent layout, but I might be able to achieve this with some discipline and usage of templates when writing html.

Based on this experience and on messages from multiple people on this forum, I would at least warn anyone who wants to use mediawiki on freedombox. A precaution might be to regularly do a plain extraction with wget from another computer (but I can’t test this now).

jvalleroy · July 5, 2024, 2:10pm

In /etc/php/8.2/fpm/php.ini (where 8.2 is the current php version), there is a value max_execution_time with a default of 30. I think we need to increase this value for FreedomBox.

Edit: I opened an issue about this: