logcollector does not recognize journald rotation #26545

printerderby · 2024-10-25T13:32:56Z

printerderby
Oct 25, 2024

Hello

I was thinking about creating a bug report. But I hope, I am missing something or did a simple mistake. Maybe you can give me a hint.

We started to roll out the wazuh-agent to our Debian 12 machines. But all of them stop collecting logs via journald, when it rotates it's files.
The wazuh-logcollector does not close the deleted files (which keeps them from physical deletion and therefore from freeing it's diskspace, which is another symptom).

Setting logcollector.force_reload=1 and logcollector.reload_interval=512 did not help either.

Wazuh version	Component	Install type	Install method	Platform
4.9.0-1	wazuh-agent	Agent	Wazuh Debian Repo	Debian 12 with ZFS as rootfs

Below is some output of a system, that stopped sending in logs, at 11:09:54 system time (CEST), 09:09:54 (UTC).

When journad started rotating its logs...

root@some-devel-01:~# journalctl -u systemd-journald | tail -4
Oct 25 04:33:09 some-devel-01 systemd-journald[719]: Data hash table of /var/log/journal/a5fdf874817bb2c9415bedc866d58b64/system.journal has a fill level at 75.0 (174763 of 233016 items, 67108864 file size, 383 bytes per hash table item), suggesting rotation.
Oct 25 04:33:09 some-devel-01 systemd-journald[719]: /var/log/journal/a5fdf874817bb2c9415bedc866d58b64/system.journal: Journal header limits reached or header out-of-date, rotating.
Oct 25 11:09:53 some-devel-01 systemd-journald[719]: Data hash table of /var/log/journal/a5fdf874817bb2c9415bedc866d58b64/system.journal has a fill level at 75.0 (174765 of 233016 items, 67108864 file size, 383 bytes per hash table item), suggesting rotation.
Oct 25 11:09:53 some-devel-01 systemd-journald[719]: /var/log/journal/a5fdf874817bb2c9415bedc866d58b64/system.journal: Journal header limits reached or header out-of-date, rotating.
root@some-devel-01:~#

The server stopped receiving any new log. This is from the servers dashboard.

Oct 25, 2024 @ 11:09:54.603 some-devel-01 Oct 25 09:09:53 some-devel-01 sudo[2764222]: zabbix : PWD=/ ; USER=root ; COMMAND=/sbin/somecmd
Oct 25, 2024 @ 11:09:52.609 some-devel-01 Oct 25 09:09:52 some-devel-01 sudo[2764219]: pam_unix(sudo:session): session closed for user root
Oct 25, 2024 @ 11:09:52.607 some-devel-01 Oct 25 09:09:52 some-devel-01 sudo[2764219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=103)

Strangely, the wazuh-agent does not close the old logs.

root@some-devel-01:~# ps auxfww | grep wazuh-log
root     1423373  0.0  0.0   6332  1400 pts/0    S+   14:52   0:00          \_ grep wazuh-log
root      691257  0.0  0.5 1241008 46240 ?       Sl   08:28   0:13 /var/ossec/bin/wazuh-logcollector
root@some-devel-01:~# lsof -n -p 691257 | grep deleted
wazuh-log 691257 root   49r   REG               0,46 59098424       742 /var/log/journal/a5fdf874817bb2c9415bedc866d58b64/system@bb71717d18944be6bf53c30a7ecf4add-0000000001363287-000624920c2e2248.journal (deleted)
wazuh-log 691257 root   61r   REG               0,46 10882064      1072 /var/log/journal/a5fdf874817bb2c9415bedc866d58b64/user-1000@777d36c3c3064592b9368bad270fdbca-00000000013491cd-0006248c51165c96.journal (deleted)
wazuh-log 691257 root  103r   REG               0,46  5250168       744 /var/log/journal/a5fdf874817bb2c9415bedc866d58b64/user-1001@a4334d64ddca406cbda4f715e922050e-000000000136338f-0006249210eef8da.journal (deleted)

logcollector.force_reload=1 and logcollector.reload_interval=512 does not seem to help.

root@some-devel-01:~# grep -ri 'logcoll.*reload' /var/ossec/etc/
/var/ossec/etc/local_internal_options.conf.bak:logcollector.force_reload=1
/var/ossec/etc/internal_options.conf:logcollector.force_reload=1
/var/ossec/etc/internal_options.conf:logcollector.reload_interval=64
/var/ossec/etc/internal_options.conf:logcollector.reload_delay=1000
/var/ossec/etc/local_internal_options.conf:logcollector.force_reload=1
/var/ossec/etc/local_internal_options.conf:logcollector.reload_interval=512
root@some-devel-01:~# stat /var/ossec/etc/internal_options.conf
  File: /var/ossec/etc/internal_options.conf
  Size: 14480     	Blocks: 18         IO Block: 14848  regular file
Device: 0,42	Inode: 191066      Links: 1
Access: (0640/-rw-r-----)  Uid: (    0/    root)   Gid: (  116/   wazuh)
Access: 2024-10-25 08:28:13.573933759 +0200
Modify: 2024-10-25 08:27:58.666016086 +0200
Change: 2024-10-25 08:27:58.666016086 +0200
 Birth: 2024-10-25 08:27:58.666016086 +0200
root@some-devel-01:~# ls -ltr /proc/691257/ | head -n 5
total 0
-r--r--r--  1 root root  0 Oct 25 08:31 status
-r--r--r--  1 root root  0 Oct 25 08:32 stat
-r--r--r--  1 root root  0 Oct 25 08:32 cmdline
dr-x------  2 root root  0 Oct 25 08:34 fd
root@some-devel-01:~#

Besides "no new entry", there is no new "read_journald" line in the debug log.

2024/10/25 11:09:52 wazuh-logcollector[691255] logcollector.c:2123 at w_input_thread(): DEBUG: (9005): Skipping is not the owner of the journal log.
2024/10/25 11:09:52 wazuh-logcollector[691255] logcollector.c:2123 at w_input_thread(): DEBUG: (9005): Skipping is not the owner of the journal log.
2024/10/25 11:09:52 wazuh-logcollector[691255] logcollector.c:2123 at w_input_thread(): DEBUG: (9005): Skipping is not the owner of the journal log.
2024/10/25 11:09:54 wazuh-logcollector[691255] read_journald.c:168 at read_journald(): DEBUG: (9008): Reading from journal: 'Oct 25 09:09:53 some-devel-01 sudo[2764222]:   zabbix : PWD=/ ; USER=root ; COMMAND=/sbin/somecmd'.
2024/10/25 11:09:54 wazuh-logcollector[691255] read_journald.c:142 at read_journald(): DEBUG: (9006): No new entries in the journal.
2024/10/25 11:09:54 wazuh-logcollector[691255] read_syslog.c:104 at read_syslog(): DEBUG: Reading syslog message: '192.168.x.x - - [25/Oct/2024:11:09:53 +0200] "GET /status HTT'...
2024/10/25 11:09:54 wazuh-logcollector[691255] read_syslog.c:104 at read_syslog(): DEBUG: Reading syslog message: '192.168.x.x - - [25/Oct/2024:11:09:53 +0200] "GET /status HTT'...
2024/10/25 11:09:54 wazuh-logcollector[691255] read_syslog.c:104 at read_syslog(): DEBUG: Reading syslog message: '192.168.x.x - - [25/Oct/2024:11:09:54 +0200] "GET /status HTT'...
2024/10/25 11:09:54 wazuh-logcollector[691255] read_syslog.c:152 at read_syslog(): DEBUG: Read 3 lines from /var/log/nginx/access.log
2024/10/25 11:09:54 wazuh-logcollector[691255] logcollector.c:2123 at w_input_thread(): DEBUG: (9005): Skipping is not the owner of the journal log.
2024/10/25 11:09:54 wazuh-logcollector[691255] logcollector.c:2123 at w_input_thread(): DEBUG: (9005): Skipping is not the owner of the journal log.
2024/10/25 11:09:54 wazuh-logcollector[691255] logcollector.c:2123 at w_input_thread(): DEBUG: (9005): Skipping is not the owner of the journal log.
2024/10/25 11:09:56 wazuh-logcollector[691255] read_journald.c:142 at read_journald(): DEBUG: (9006): No new entries in the journal.
2024/10/25 11:09:56 wazuh-logcollector[691255] read_syslog.c:104 at read_syslog(): DEBUG: Reading syslog message: '192.168.x.x - - [25/Oct/2024:11:09:55 +0200] "GET /status HTT'...
2024/10/25 11:09:56 wazuh-logcollector[691255] read_syslog.c:104 at read_syslog(): DEBUG: Reading syslog message: '192.168.x.x - - [25/Oct/2024:11:09:55 +0200] "GET /status HTT'...
2024/10/25 11:09:56 wazuh-logcollector[691255] read_syslog.c:104 at read_syslog(): DEBUG: Reading syslog message: '192.168.x.x - - [25/Oct/2024:11:09:55 +0200] "GET /api/v1/sta'...
2024/10/25 11:09:56 wazuh-logcollector[691255] read_syslog.c:104 at read_syslog(): DEBUG: Reading syslog message: '192.168.x.x - - [25/Oct/2024:11:09:56 +0200] "GET /status HTT'...
2024/10/25 11:09:56 wazuh-logcollector[691255] read_syslog.c:152 at read_syslog(): DEBUG: Read 4 lines from /var/log/nginx/access.log
2024/10/25 11:09:56 wazuh-logcollector[691255] logcollector.c:2123 at w_input_thread(): DEBUG: (9005): Skipping is not the owner of the journal log.
2024/10/25 11:09:56 wazuh-logcollector[691255] logcollector.c:2123 at w_input_thread(): DEBUG: (9005): Skipping is not the owner of the journal log.
2024/10/25 11:09:56 wazuh-logcollector[691255] logcollector.c:2123 at w_input_thread(): DEBUG: (9005): Skipping is not the owner of the journal log.
2024/10/25 11:09:58 wazuh-logcollector[691255] read_journald.c:142 at read_journald(): DEBUG: (9006): No new entries in the journal.

Best regards :)
Steffen

abeverley · 2024-11-04T22:32:16Z

abeverley
Nov 4, 2024

I am also seeing this problem. I'm wondering if you made any progress in fixing it?

0 replies

printerderby · 2024-11-11T09:31:13Z

printerderby
Nov 11, 2024
Author

@abeverley Thanks for testing :)
I'm not a developer and would create a bugreport, now. What system/distro are you using? Are you using ZFS, too?

0 replies

abeverley · 2024-11-11T09:40:32Z

abeverley
Nov 11, 2024

Thanks @printerderby I think a good bug report could be created directing using your detailed analysis (using the "create issue from discussion" button) 😀

I'm using ext4, so it seems to be a general issue with Debian (and maybe others? I'm surprised this is not affecting many others)

0 replies

printerderby · 2024-11-11T10:34:58Z

printerderby
Nov 11, 2024
Author

Bugreport #26778 created.

Thank you :)

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

logcollector does not recognize journald rotation #26545

Uh oh!

{{title}}

Uh oh!

Replies: 4 comments

Uh oh!

{{title}}

Uh oh!

Uh oh!

{{title}}

Uh oh!

Uh oh!

{{title}}

Uh oh!

Uh oh!

{{title}}

Uh oh!

Select a reply

Uh oh!

logcollector does not recognize journald rotation #26545

Uh oh!

printerderby Oct 25, 2024

Replies: 4 comments

Uh oh!

abeverley Nov 4, 2024

Uh oh!

printerderby Nov 11, 2024 Author

Uh oh!

abeverley Nov 11, 2024

Uh oh!

printerderby Nov 11, 2024 Author

printerderby
Oct 25, 2024

abeverley
Nov 4, 2024

printerderby
Nov 11, 2024
Author

abeverley
Nov 11, 2024

printerderby
Nov 11, 2024
Author