search

YunoHost-Apps / collabora_ynh

Collabora package for YunoHost
https://www.collaboraoffice.com/
GNU General Public License v3.0
16 stars 13 forks source link

Collabora making system logs suddenly explode in size to many GBs #93

Open eauchat opened 1 week ago

eauchat commented 1 week ago

Describe the bug

I ran into the issue described in this forum topic. Basically, collabora is getting a bit crazy and makes logs fill up all server space. I also noticed that excessive server resources were taken by coolwsd service, even with very limited-to-unexistant use of collabora. I didn't find an issue related to this in this bugtracker so I though it might be worth reporting for the record. Though I can imagine it may be related more to collabora itself than to the yunohost package, maybe it's useful to keep track here of what's going on.

Context

eauchat commented 2 days ago

Took some time to investigate the issue a bit further today. In my situation /var/log/syslog, /var/log/messages and /var/log/user.log are all bloated with logs from coolwsd. I think the amount of logs may be explained by this line:

Setting log-level to [trace] and delaying setting to [warning] until after WSD initialization.| wsd/COOLWSD.cpp

So I think there are so many logs simply because instead of logging level being set to warning as specified in /etc/coolwsd/coolwsd.xml it is set to trace, and there is just simply something going wrong with initialization.

The following logs are the beginning and end of the loop I believe:

Oct 18 16:04:38 myhost coolwsd[23497]: frk-23463-23497 2024-10-18 16:04:37.105396 +0200 [ kit_spare_001 ] INF  Thread 23497 (7f4f1a76a7c0) of process 23497 formerly known as [forkit] is now called [kit_spare_001]| common/Util.cpp:330
Oct 18 16:04:38 myhost coolwsd[23497]: kit-23497-23497 2024-10-18 16:04:37.105913 +0200 [ kit_spare_001 ] INF  Initializing kit. Local time: Fri 2024-10-18 16:04:37 +0200. Log level is [8]| common/Log.cpp:654
Oct 18 16:04:38 myhost coolwsd[23497]: kit-23497-23497 2024-10-18 16:04:37.105930 +0200 [ kit_spare_001 ] INF  Setting log-level to [trace] and delaying setting to [warning] until after Kit initialization.| kit/Kit.cpp:3032
Oct 18 16:04:38 myhost coolwsd[23497]: kit-23497-23497 2024-10-18 16:04:37.105936 +0200 [ kit_spare_001 ] INF  User-data anonymization is disabled.| kit/Kit.cpp:3044
Oct 18 16:04:38 myhost coolwsd[23497]: kit-23497-23497 2024-10-18 16:04:37.105938 +0200 [ kit_spare_001 ] INF  Kit process for Jail [7Ew6GyvWmmOb5he0] started.| kit/Kit.cpp:3053
Oct 18 16:04:38 myhost coolwsd[23497]: kit-23497-23497 2024-10-18 16:04:37.105966 +0200 [ kit_spare_001 ] INF  Creating jail path (if missing): /opt/cool/child-roots/23459-2b87de4c/7Ew6GyvWmmOb5he0/| common/JailUtil.cpp:418
Oct 18 16:04:38 myhost coolwsd[23497]: kit-23497-23497 2024-10-18 16:04:37.106114 +0200 [ kit_spare_001 ] DBG  Move into user namespace as uid 0| kit/Kit.cpp:3179
Oct 18 16:04:38 myhost coolwsd[23497]: kit-23497-23497 2024-10-18 16:04:37.106231 +0200 [ kit_spare_001 ] DBG  Move into user namespace as uid 111| kit/Kit.cpp:3211

...

Oct 18 16:09:16 myhost coolwsd[23463]: frk-23463-23463 2024-10-18 16:09:16.022480 +0200 [ forkit ] WRN  The systemplate directory [/opt/cool/systemplate] is read-only, and at least [/opt/cool/systemplate//etc/resolv.conf] is out-of-date. Will have to copy sysTemplate to jails. To restore optimal performance, make sure the files in [/opt/cool/systemplate/etc] are up-to-date.| common/JailUtil.cpp:585
Oct 18 16:09:16 myhost coolwsd[24077]: kit-24077-24077 2024-10-18 16:09:16.027848 +0200 [ kit_spare_004 ] ERR  link("/opt/cool/systemplate/lib64/ld-linux-x86-64.so.2", "/opt/cool/child-roots/23459-2b87de4c/X7EqUIHf8l1J15dE/lib64/ld-linux-x86-64.so.2") failed: Operation not permitted. Very slow copying path triggered.| kit/Kit.cpp:394
Oct 18 16:09:16 myhost coolwsd[24077]: kit-24077-24077 2024-10-18 16:09:16.081097 +0200 [ kit_spare_004 ] ERR  Failed to stat or chown 65534:65534 /opt/cool/child-roots/23459-2b87de4c//linkable/opt/collaboraoffice/presets/database/biblio/biblio.dbt: Invalid argument missing cap_chown?, disabling linkable| kit/Kit.cpp:378
Oct 18 16:09:16 myhost coolwsd[23459]: wsd-23459-23461 2024-10-18 16:09:16.084724 +0200 [ coolwsd ] WRN  Waking up dead poll thread [main], started: false, finished: false| net/Socket.hpp:723
Oct 18 16:09:16 myhost coolwsd[23459]: wsd-23459-23459 2024-10-18 16:04:59.999879 +0200 [ coolwsd ] TRC  Have 1 new children.| wsd/COOLWSD.cpp:4439
Oct 18 16:09:16 myhost coolwsd[23459]: wsd-23459-23459 2024-10-18 16:04:59.999887 +0200 [ coolwsd ] INF  WSD initialization complete: setting log-level to [warning] as configured.| wsd/COOLWSD.cpp:4454
Oct 18 16:09:16 myhost coolwsd[23459]: wsd-23459-23459 2024-10-18 16:09:16.084773 +0200 [ coolwsd ] WRN  Waking up dead poll thread [main], started: false, finished: false| net/Socket.hpp:723
Oct 18 16:09:16 myhost coolwsd[24077]: kit-24077-24077 2024-10-18 16:09:16.359372 +0200 [ kit_spare_004 ] SIG   Fatal signal received: SIGSEGV code: 1 for address: 0x11
Oct 18 16:09:16 myhost coolwsd[24077]: Recent activity:
Oct 18 16:09:16 myhost coolwsd[24077]: Backtrace 24077 - kit startup of 24.04.8.1 8475197:
Oct 18 16:09:16 myhost coolwsd[23459]: wsd-23459-23462 2024-10-18 16:09:16.362539 +0200 [ prisoner_poll ] ERR  #18: Read failed, have 0 buffered bytes (ECONNRESET: Connection reset by peer)| net/Socket.hpp:1154

I searched quite a bit on collabora bugtrackers and around but didn't find related stuff, so I ended up asking in the collabora bugtracker directly, hopefully someone has something useful to say about this issue there.

lapineige commented 2 days ago

Thanks a lot for these findings ! You didn't have to touch /etc/yunohost/apps/collabora/conf/coolwsd.xml then ?

In my case it was : <level type="string" desc="Can be 0-8 (with the lowest numbers being the least verbose), or none (turns off logging), fatal, critical, error, warning, notice, information, debug, trace" default="warning">warning</level>

eauchat commented 1 day ago

Yes to me also it's like this, so I didn't touch it. I think the issue doesn't come from /etc/yunohost/apps/collabora/conf/coolwsd.xml having the wrong logging level, but that this level is somehow overwritten when initializing "kit". No idea what "kit" is though ;) but it seems not to manage to initialize and therefore logs huge amounts of things in loop. At least that's what I assume is happening, but maybe I'm getting all wrong ;/