Radicale not working after FBx update to 22.12

Support
1

On DAVxxx (Android) I get error message “network or I/O error - connection reset”,
in Evolution “connection terminated unexpectidly” and “Gegenstelle scheiterte bei Ausführung des TLS-Handshake: Fehler beim Erhalt von Daten: Die Verbindung wurde vom Kommunikationspartner zurückgesetzt”

I already did the magic thing restarting Freedombox, actually twice.

#systemctl status radicale
● radicale.service - A simple CalDAV (calendar) and CardDAV (contact) server
Loaded: loaded (/lib/systemd/system/radicale.service; disabled; vendor preset: enabled)
Active: inactive (dead)
Docs: man:radicale(1)

Why inactive (dead)?
running diagnosis in plinth everything is “passed”

Trying to start the web client from plinth gives a blank page “about:blank”, after being asked for the password. Some parts of radicale are not working.

2

We don’t use radicale.service in FreedomBox, instead it is served by the uwsgi service. The logs will be in /var/log/uwsgi/app/radicale.log.

3

Hi James,

thanks for supporting me. I am really lost here.

File radicale.log is empty, so I cat the last file here.
I see no error message and frankly, the log does not tell me anything:

xxx@freedombox:/var/log/uwsgi/app$ sudo cat radicale.log.1
Sat May 28 15:06:34 2022 - SIGINT/SIGQUIT received…killing workers…
Sat May 28 15:06:39 2022 - worker 4 buried after 5 seconds
Sat May 28 15:06:40 2022 - worker 3 buried after 6 seconds
Sat May 28 15:06:40 2022 - worker 1 buried after 6 seconds
Sat May 28 15:06:40 2022 - goodbye to uWSGI.
Sat May 28 15:08:38 2022 - *** Starting uWSGI 2.0.19.1-debian (32bit) on [Sat May 28 15:08:37 2022] ***
Sat May 28 15:08:38 2022 - compiled with version: 10.2.1 20210110 on 11 June 2021 09:08:33
Sat May 28 15:08:38 2022 - os: Linux-5.10.0-14-armmp-lpae #1 SMP Debian 5.10.113-1 (2022-04-29)
Sat May 28 15:08:38 2022 - nodename: freedombox
Sat May 28 15:08:38 2022 - machine: armv7l
Sat May 28 15:08:38 2022 - clock source: unix
Sat May 28 15:08:38 2022 - pcre jit disabled
Sat May 28 15:08:38 2022 - detected number of CPU cores: 2
Sat May 28 15:08:38 2022 - current working directory: /
Sat May 28 15:08:38 2022 - writing pidfile to /run/uwsgi/app/radicale/pid
Sat May 28 15:08:38 2022 - detected binary path: /usr/bin/uwsgi-core
Sat May 28 15:08:38 2022 - your processes number limit is 2946
Sat May 28 15:08:38 2022 - your memory page size is 4096 bytes
Sat May 28 15:08:38 2022 - detected max file descriptor number: 1024
Sat May 28 15:08:38 2022 - lock engine: pthread robust mutexes
Sat May 28 15:08:38 2022 - thunder lock: disabled (you can enable it with --thunder-lock)
Sat May 28 15:08:38 2022 - uwsgi socket 0 bound to UNIX address /run/uwsgi/app/radicale/socket fd 3
Sat May 28 15:08:38 2022 - running “if ! dpkg-statoverride --list /var/lib/radicale >/dev/null 2>&1; then chown radicale: /var/lib/radicale /var/lib/radicale/collections; chmod g-w,o-rwx /var/lib/radicale /var/lib/radicale/collections; fi” (as root)…
Sat May 28 15:08:39 2022 - running “if ! dpkg-statoverride --list /var/log/radicale >/dev/null 2>&1; then chown radicale:adm /var/log/radicale; chmod g-w,o-rwx /var/log/radicale; fi” (as root)…
Sat May 28 15:08:39 2022 - setgid() to 121
Sat May 28 15:08:39 2022 - setuid() to 116
Sat May 28 15:08:39 2022 - Python version: 3.9.2 (default, Feb 28 2021, 17:03:44) [GCC 10.2.1 20210110]
Sat May 28 15:08:42 2022 - Python main interpreter initialized at 0x1f21150
Sat May 28 15:08:42 2022 - python threads support enabled
Sat May 28 15:08:42 2022 - your server socket listen backlog is limited to 100 connections
Sat May 28 15:08:42 2022 - your mercy for graceful operations on workers is 60 seconds
Sat May 28 15:08:42 2022 - mapped 1481856 bytes (1447 KB) for 64 cores
Sat May 28 15:08:42 2022 - *** Operational MODE: preforking+threaded ***
Sat May 28 15:09:07 2022 - WSGI app 0 (mountpoint=‘’) ready in 25 seconds on interpreter 0x1f21150 pid: 909 (default app)
Sat May 28 15:09:07 2022 - spawned uWSGI master process (pid: 909)
Sat May 28 15:09:07 2022 - chdir() to /var/lib/radicale/collections
Sat May 28 15:09:07 2022 - spawned uWSGI worker 1 (pid: 1185, cores: 4)
Sat May 28 15:09:07 2022 - spawned uWSGI worker 2 (pid: 1189, cores: 4)
Sat May 28 15:09:07 2022 - chdir() to /var/lib/radicale/collections
Sat May 28 15:09:07 2022 - spawned uWSGI worker 3 (pid: 1190, cores: 4)
Sat May 28 15:09:08 2022 - chdir() to /var/lib/radicale/collections
Sat May 28 15:23:25 2022 - SIGINT/SIGQUIT received…killing workers…
Sat May 28 15:23:26 2022 - worker 2 buried after 1 seconds
Sat May 28 15:23:27 2022 - worker 1 buried after 2 seconds
Sat May 28 15:23:27 2022 - worker 3 buried after 2 seconds
Sat May 28 15:23:27 2022 - goodbye to uWSGI.
Sat May 28 15:24:31 2022 - *** Starting uWSGI 2.0.19.1-debian (32bit) on [Sat May 28 15:24:31 2022] ***
Sat May 28 15:24:31 2022 - compiled with version: 10.2.1 20210110 on 11 June 2021 09:08:33
Sat May 28 15:24:31 2022 - os: Linux-5.10.0-14-armmp-lpae #1 SMP Debian 5.10.113-1 (2022-04-29)
Sat May 28 15:24:31 2022 - nodename: freedombox
Sat May 28 15:24:31 2022 - machine: armv7l
Sat May 28 15:24:31 2022 - clock source: unix
Sat May 28 15:24:31 2022 - pcre jit disabled
Sat May 28 15:24:31 2022 - detected number of CPU cores: 2
Sat May 28 15:24:31 2022 - current working directory: /
Sat May 28 15:24:31 2022 - writing pidfile to /run/uwsgi/app/radicale/pid
Sat May 28 15:24:31 2022 - detected binary path: /usr/bin/uwsgi-core
Sat May 28 15:24:31 2022 - your processes number limit is 2946
Sat May 28 15:24:31 2022 - your memory page size is 4096 bytes
Sat May 28 15:24:31 2022 - detected max file descriptor number: 1024
Sat May 28 15:24:31 2022 - lock engine: pthread robust mutexes
Sat May 28 15:24:31 2022 - thunder lock: disabled (you can enable it with --thunder-lock)
Sat May 28 15:24:31 2022 - uwsgi socket 0 bound to UNIX address /run/uwsgi/app/radicale/socket fd 3
Sat May 28 15:24:31 2022 - running “if ! dpkg-statoverride --list /var/lib/radicale >/dev/null 2>&1; then chown radicale: /var/lib/radicale /var/lib/radicale/collections; chmod g-w,o-rwx /var/lib/radicale /var/lib/radicale/collections; fi” (as root)…
Sat May 28 15:24:32 2022 - running “if ! dpkg-statoverride --list /var/log/radicale >/dev/null 2>&1; then chown radicale:adm /var/log/radicale; chmod g-w,o-rwx /var/log/radicale; fi” (as root)…
Sat May 28 15:24:32 2022 - setgid() to 121
Sat May 28 15:24:32 2022 - setuid() to 116
Sat May 28 15:24:32 2022 - Python version: 3.9.2 (default, Feb 28 2021, 17:03:44) [GCC 10.2.1 20210110]
Sat May 28 15:24:34 2022 - Python main interpreter initialized at 0x20ce0e8
Sat May 28 15:24:34 2022 - python threads support enabled
Sat May 28 15:24:34 2022 - your server socket listen backlog is limited to 100 connections
Sat May 28 15:24:34 2022 - your mercy for graceful operations on workers is 60 seconds
Sat May 28 15:24:34 2022 - mapped 1481856 bytes (1447 KB) for 64 cores
Sat May 28 15:24:34 2022 - *** Operational MODE: preforking+threaded ***
Sat May 28 15:25:52 2022 - WSGI app 0 (mountpoint=‘’) ready in 78 seconds on interpreter 0x20ce0e8 pid: 1377 (default app)
Sat May 28 15:25:52 2022 - spawned uWSGI master process (pid: 1377)
Sat May 28 15:25:53 2022 - spawned uWSGI worker 1 (pid: 1495, cores: 4)
Sat May 28 15:25:53 2022 - chdir() to /var/lib/radicale/collections
Sat May 28 15:25:53 2022 - spawned uWSGI worker 2 (pid: 1496, cores: 4)
Sat May 28 15:25:53 2022 - spawned uWSGI worker 3 (pid: 1500, cores: 4)
Sat May 28 15:25:53 2022 - chdir() to /var/lib/radicale/collections
Sat May 28 15:25:53 2022 - chdir() to /var/lib/radicale/collections
Sat May 28 18:35:56 2022 - SIGINT/SIGQUIT received…killing workers…
Sat May 28 18:35:57 2022 - worker 1 buried after 1 seconds
Sat May 28 18:35:57 2022 - worker 2 buried after 1 seconds
Sat May 28 18:35:57 2022 - worker 3 buried after 1 seconds
Sat May 28 18:35:57 2022 - goodbye to uWSGI.
Sat May 28 18:38:46 2022 - *** Starting uWSGI 2.0.19.1-debian (32bit) on [Sat May 28 18:38:46 2022] ***
Sat May 28 18:38:46 2022 - compiled with version: 10.2.1 20210110 on 11 June 2021 09:08:33
Sat May 28 18:38:46 2022 - os: Linux-5.10.0-14-armmp-lpae #1 SMP Debian 5.10.113-1 (2022-04-29)
Sat May 28 18:38:46 2022 - nodename: freedombox
Sat May 28 18:38:46 2022 - machine: armv7l
Sat May 28 18:38:46 2022 - clock source: unix
Sat May 28 18:38:46 2022 - pcre jit disabled
Sat May 28 18:38:46 2022 - detected number of CPU cores: 2
Sat May 28 18:38:46 2022 - current working directory: /
Sat May 28 18:38:46 2022 - writing pidfile to /run/uwsgi/app/radicale/pid
Sat May 28 18:38:46 2022 - detected binary path: /usr/bin/uwsgi-core
Sat May 28 18:38:46 2022 - your processes number limit is 2946
Sat May 28 18:38:46 2022 - your memory page size is 4096 bytes
Sat May 28 18:38:46 2022 - detected max file descriptor number: 1024
Sat May 28 18:38:46 2022 - lock engine: pthread robust mutexes
Sat May 28 18:38:46 2022 - thunder lock: disabled (you can enable it with --thunder-lock)
Sat May 28 18:38:46 2022 - uwsgi socket 0 bound to UNIX address /run/uwsgi/app/radicale/socket fd 3
Sat May 28 18:38:46 2022 - running “if ! dpkg-statoverride --list /var/lib/radicale >/dev/null 2>&1; then chown radicale: /var/lib/radicale /var/lib/radicale/collections; chmod g-w,o-rwx /var/lib/radicale /var/lib/radicale/collections; fi” (as root)…
Sat May 28 18:38:47 2022 - running “if ! dpkg-statoverride --list /var/log/radicale >/dev/null 2>&1; then chown radicale:adm /var/log/radicale; chmod g-w,o-rwx /var/log/radicale; fi” (as root)…
Sat May 28 18:38:47 2022 - setgid() to 121
Sat May 28 18:38:47 2022 - setuid() to 116
Sat May 28 18:38:47 2022 - Python version: 3.9.2 (default, Feb 28 2021, 17:03:44) [GCC 10.2.1 20210110]
Sat May 28 18:38:48 2022 - Python main interpreter initialized at 0x10a70e8
Sat May 28 18:38:48 2022 - python threads support enabled
Sat May 28 18:38:48 2022 - your server socket listen backlog is limited to 100 connections
Sat May 28 18:38:48 2022 - your mercy for graceful operations on workers is 60 seconds
Sat May 28 18:38:48 2022 - mapped 1481856 bytes (1447 KB) for 64 cores
Sat May 28 18:38:48 2022 - *** Operational MODE: preforking+threaded ***
Sat May 28 18:39:06 2022 - WSGI app 0 (mountpoint=‘’) ready in 18 seconds on interpreter 0x10a70e8 pid: 5142 (default app)
Sat May 28 18:39:06 2022 - spawned uWSGI master process (pid: 5142)
Sat May 28 18:39:06 2022 - spawned uWSGI worker 1 (pid: 5277, cores: 4)
Sat May 28 18:39:06 2022 - spawned uWSGI worker 2 (pid: 5278, cores: 4)
Sat May 28 18:39:06 2022 - chdir() to /var/lib/radicale/collections
Sat May 28 18:39:06 2022 - spawned uWSGI worker 3 (pid: 5282, cores: 4)
Sat May 28 18:39:06 2022 - chdir() to /var/lib/radicale/collections
Sat May 28 18:39:06 2022 - chdir() to /var/lib/radicale/collections

4

As I am still fishing in the dark, let’s try a different approach.

In Firefox, I am launching plinth through freedombox.local/plinth. After log-in, I click on the installed app “Radicale”. I am asked for user-ID and password, entered and the browser stays at plinth.
Can someone please counter-check, if this is just on my installation or a general issue?

5

I just compared the config files in /etc with those of an old back-up of April: no change. So it is not due a faulty config file.

6

mine is working… in fbx testing 22.12,

7

Since there’s no error shown in the radicale log, I would check the apache2 log next, to see if it is attempting a connection.

8

When trying to access Radicale through Evolution I get the following output in error.log:

[Wed Jun 01 20:49:22.063578 2022] [ssl:warn] [pid 13469:tid 2590950432] (22)Invalid argument: AH02026: Failed to acquire SSL session cache lock
[Wed Jun 01 20:49:22.064081 2022] [ssl:warn] [pid 13469:tid 2590950432] (22)Invalid argument: AH02027: Failed to release SSL session cache lock
[Wed Jun 01 20:49:22.065297 2022] [ssl:warn] [pid 13469:tid 2590950432] (22)Invalid argument: AH02026: Failed to acquire SSL session cache lock
[Wed Jun 01 20:49:22.065530 2022] [ssl:warn] [pid 13469:tid 2590950432] (22)Invalid argument: AH02027: Failed to release SSL session cache lock
[Wed Jun 01 20:49:27.363817 2022] [ssl:warn] [pid 13469:tid 2788156448] (22)Invalid argument: AH02026: Failed to acquire SSL session cache lock
[Wed Jun 01 20:49:27.365235 2022] [ssl:warn] [pid 13469:tid 2788156448] (22)Invalid argument: AH02027: Failed to release SSL session cache lock
[Wed Jun 01 20:49:27.421252 2022] [ssl:warn] [pid 13469:tid 2788156448] (22)Invalid argument: AH02026: Failed to acquire SSL session cache lock
[Wed Jun 01 20:49:27.422280 2022] [ssl:warn] [pid 13469:tid 2788156448] (22)Invalid argument: AH02027: Failed to release SSL session cache lock
[Wed Jun 01 20:49:27.569485 2022] [ssl:warn] [pid 13469:tid 2777674784] (22)Invalid argument: AH01948: Failed to acquire OCSP ssl-stapling lock
[Wed Jun 01 20:49:27.570034 2022] [ssl:warn] [pid 13469:tid 2777674784] (22)Invalid argument: AH01949: Failed to release OCSP ssl-stapling lock
[Wed Jun 01 20:49:27.616451 2022] [ssl:warn] [pid 13469:tid 2777674784] (22)Invalid argument: AH02026: Failed to acquire SSL session cache lock
[Wed Jun 01 20:49:27.616853 2022] [ssl:warn] [pid 13469:tid 2777674784] (22)Invalid argument: AH02027: Failed to release SSL session cache lock
[Wed Jun 01 20:49:27.617999 2022] [ssl:warn] [pid 13469:tid 2777674784] (22)Invalid argument: AH02026: Failed to acquire SSL session cache lock
[Wed Jun 01 20:49:27.618336 2022] [ssl:warn] [pid 13469:tid 2777674784] (22)Invalid argument: AH02027: Failed to release SSL session cache lock
[Wed Jun 01 20:49:27.620415 2022] [ldap:crit] [pid 13469:tid 2777674784] (22)Invalid argument: [client 87.174.202.77:36532] AH10134: LDAP cache lock failed
[Wed Jun 01 20:49:27.620778 2022] [core:crit] [pid 13469:tid 2777674784] AH00102: [Wed Jun 01 20:49:27 2022] file util_ldap.c, line 85, assertion "0" failed
[Wed Jun 01 20:49:28.508954 2022] [core:notice] [pid 1111:tid 3066944096] AH00052: child pid 13469 exit signal Aborted (6)

Interesting are the SSL lock errors and “LDAP cache lock failed”.
So an issue with LDAP???

access.log:

87.174.202.77 - - [01/Jun/2022:20:56:55 +0200] "GET /radicale HTTP/2.0" 301 489 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101 Firefox/91.0"
87.174.202.77 - - [01/Jun/2022:20:56:55 +0200] "GET /radicale/ HTTP/2.0" 401 640 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101 Firefox/91.0"
9

According to what I read in the manual, radical is not using LDAP. So I am trying to look at it from a different point of view again:

What really puzzles me is that if I go to freedombox.local/radicale I am asked to enter username and password. And that when I enter the credentials, nothing happens. To me it looks as if radicale is not running at all, cannot respond. Therefore the “connection refused”. Thus I tried:

$ sudo systemctl status uwsgi
● uwsgi.service - LSB: Start/stop uWSGI server instance(s)
     Loaded: loaded (/etc/init.d/uwsgi; generated)
     Active: active (running) since Wed 2022-06-01 04:34:31 CEST; 1 day 15h ago
       Docs: man:systemd-sysv-generator(8)
    Process: 4385 ExecStart=/etc/init.d/uwsgi start (code=exited, status=0/SUCCESS)
      Tasks: 21 (limit: 883)
     Memory: 4.3M
        CPU: 5min 19.282s
     CGroup: /system.slice/uwsgi.service
             ├─4484 /usr/bin/uwsgi --ini /usr/share/uwsgi/conf/default.ini --ini /etc/uwsgi/apps-enabled/bepasty-freedombox.ini --daemonize /var/log/uwsgi/app/bepasty-freed>
             ├─4561 /usr/bin/uwsgi --ini /usr/share/uwsgi/conf/default.ini --ini /etc/uwsgi/apps-enabled/bepasty-freedombox.ini --daemonize /var/log/uwsgi/app/bepasty-freed>
             ├─4562 /usr/bin/uwsgi --ini /usr/share/uwsgi/conf/default.ini --ini /etc/uwsgi/apps-enabled/bepasty-freedombox.ini --daemonize /var/log/uwsgi/app/bepasty-freed>
             ├─4577 /usr/bin/uwsgi --ini /usr/share/uwsgi/conf/default.ini --ini /etc/uwsgi/apps-enabled/radicale.ini --daemonize /var/log/uwsgi/app/radicale.log
             ├─4674 /usr/bin/uwsgi --ini /usr/share/uwsgi/conf/default.ini --ini /etc/uwsgi/apps-enabled/searx.ini --daemonize /var/log/uwsgi/app/searx.log
             ├─4679 /usr/bin/uwsgi --ini /usr/share/uwsgi/conf/default.ini --ini /etc/uwsgi/apps-enabled/searx.ini --daemonize /var/log/uwsgi/app/searx.log
             ├─4680 /usr/bin/uwsgi --ini /usr/share/uwsgi/conf/default.ini --ini /etc/uwsgi/apps-enabled/searx.ini --daemonize /var/log/uwsgi/app/searx.log
             ├─4681 /usr/bin/uwsgi --ini /usr/share/uwsgi/conf/default.ini --ini /etc/uwsgi/apps-enabled/searx.ini --daemonize /var/log/uwsgi/app/searx.log
             ├─4682 /usr/bin/uwsgi --ini /usr/share/uwsgi/conf/default.ini --ini /etc/uwsgi/apps-enabled/searx.ini --daemonize /var/log/uwsgi/app/searx.log
             ├─4686 /usr/bin/uwsgi --ini /usr/share/uwsgi/conf/default.ini --ini /etc/uwsgi/apps-enabled/radicale.ini --daemonize /var/log/uwsgi/app/radicale.log
             ├─4687 /usr/bin/uwsgi --ini /usr/share/uwsgi/conf/default.ini --ini /etc/uwsgi/apps-enabled/radicale.ini --daemonize /var/log/uwsgi/app/radicale.log
             └─4688 /usr/bin/uwsgi --ini /usr/share/uwsgi/conf/default.ini --ini /etc/uwsgi/apps-enabled/radicale.ini --daemonize /var/log/uwsgi/app/radicale.log

Jun 01 04:34:23 freedombox systemd[1]: Starting LSB: Start/stop uWSGI server instance(s)...
Jun 01 04:34:31 freedombox uwsgi[4385]: Starting app server(s): uwsgi -> . . . done.
Jun 01 04:34:31 freedombox systemd[1]: Started LSB: Start/stop uWSGI server instance(s).

It is active, since about 4:30, which is when my provider cuts the connection for a second every day.

So all okay, but why is it not able to connect to radicale? Whom does it try to connect to anyway? Who is not responding?

So I am wondering if I should re-install radicale with apt. Which packages should I re-install in the hope this fixes my problem? I would prefer NOT to purge radicale first, in the hope I do not have to set-up the network of syncronized calendars etc. again.

10

Oh, that’s funny.
With my random trials I de-activated SEARX and Wordpress in Plinth.
Now Radicale is working normally again.

A really surprising behaviour, as if the device was overloaded with too many running applictions.
This reminds me of the bad old days with Windows 3.1 where I had issues because I have been running out of “hooks” (or so, maybe they were called differently) when doing something complex.

11

That was praising too early. Now it is behaving as before. Something is really unstable in my FBx.
I will look into Nextcloud next week.

12

SOLVED - but not understood why.

So I deactivated mediawiki and radicale is working again.

I some logs I had seen that there was a lot of action going on with mediawiki (GET, …). I thought this was not related and did not report it here. So a wild guess made me de-activate all apps that are not vital to me (mediawiki, searx, wordpress, calibre, …) and after the turn came to mediawiki, radicale is working since 24 h w/o issues.

I’d still like to understand what was going on. RAM and disk space are no issue, checked.

13

I am now 100% sure that Mediawiki is the culprit. Activating it causes Radicale to run on an error, de-activating it makes Radicale run.

According to the change log, these changes were done to Mediawiki in 22.12:

mediawiki: Add stricter sandbox rules for jobrunner service
mediawiki: Fix URL diagnostics with redirects involved

Probably the 1st change impacts Radicale. Maybe the sandboxing has a side-affect.

@ zippy99: do you run Mediawiki?
If yes, my theory is wrong, if not, can you install it and check if your Radicale is still running?

14

yes. running. mediawiki started.

15

And can you still access the web interface of radicale?

16

I am asked for user-ID and password, entered and the browser stays at plinth.
Can someone please counter-check, if this is just on my installation or a general issue?

For this, I would suggest trying to log in after clearing your browser’s cookies and cache or using a private window or a different browser.

17

yes, I can access the web interface.

18

Thanks for checking.
Then, something broke again my set-up.
Instead of trying the nice and fancy features of FBx, I will restrict myself to the vital functions. A pity for my nice do-it-yourself wiki, which cannot run any more because I need radicale.

I will stop investigating here and now.

Thanks to all for the support.

19

I have the same Problem. After deactivating Wordpress, radicale works… Strange.