[Journalbeat] Can't read journal logs since systemd 246

[mickymiek]

Journalbeat has stopped working for us since the version 246 of systemd is out.

This seems to be the culprit: https://github.com/systemd/systemd/blob/93caec7ed612c3d5d62ee092774bb481995fc05e/NEWS#L2049-L2057
We made it work again by setting SYSTEMD_JOURNAL_KEYED_HASH to 0 in systemd-journald.service. It would make sense to do what's needed for journalbeat to work without this workaround.

Would be happy to help if needed !

[elasticmachine]

Pinging @elastic/integrations-services (Team:Services)

[kvch]

This needs to be fixed in the journald input as well.

[jbguerraz]

@kvch In addition to that, there is that issue (also related to systemd 246+): #23220 (comment)

[codeaprendiz]

How we can replicate the issue with minimal configurations

journalbeat:7.10.2 has issues with Fedora 33.2.* (CoreOS)

What we will do to replicate the issue

• Start a simple docker journalbeat
• read the logs from /var/log/journal/
• output the logs to standard output

Expected Output

• We should be able to see the logs in standard out :)

Behaviour on Fedora 33.20210104.3.1 (CoreOS)

• check the os version

[root@ip-172-16-6-197 core]# cat /etc/os-release  | egrep "PRETTY_NAME" 
PRETTY_NAME="Fedora CoreOS 33.20210104.3.1"

Setup the journalbeat.yml

[root@ip-172-16-6-197 log]# cat /tmp/journalbeat.yml 
logging.level: debug
logging.to_files: true
logging.files:
  path: /var/log/journalbeat
  name: journalbeat
  keepfiles: 7
  permissions: 0644

output.console:
  pretty: true


journalbeat.inputs:
  - paths: ["/var/log/journal"]
    seek: tail

Do we have something to read

[root@ip-172-16-6-197 log]# ls /var/log/journal/ec202d401c5992820776e21d113a6d85/
system.journal  user-1000.journal

Let's start the docker journalbeat

sudo docker run  \
--rm  --name=journalbeat \
--user=root \
--volume="/var/log/journal:/var/log/journal" \
--volume="/etc/machine-id:/etc/machine-id" \
--volume="/run/systemd:/run/systemd" \
--volume="/tmp/journalbeat.yml:/usr/share/journalbeat/journalbeat.yml"   \
docker.elastic.co/beats/journalbeat:7.10.2 journalbeat -e -strict.perms=false
.
.
2021-02-02T08:30:04.594Z        INFO    [journalbeat]   beater/journalbeat.go:93        journalbeat is running! Hit CTRL-C to stop it.
2021-02-02T08:30:04.597Z        INFO    [monitoring]    log/log.go:118  Starting metrics logging every 30s

PROOF OF ISSUE 1

• Say something to system-cat

[root@ip-172-16-6-197 core]# echo 'hello world' | systemd-cat -p info

• Does journalbeat read the logs?

Sadly, It has no idea what's happening. Its not reading the logs

PROOF OF ISSUE 2

• Let's login to the container and see what's happening

[root@ip-172-16-6-197 core]# docker ps
CONTAINER ID        IMAGE                                        COMMAND                  CREATED             STATUS              PORTS               NAMES
69be0030b5c0        docker.elastic.co/beats/journalbeat:7.10.2   "/usr/local/bin/dock…"   4 minutes ago       Up 4 minutes                            journalbeat
[root@ip-172-16-6-197 core]# docker exec -it journalbeat sh
sh-4.2# cd /var/log/journal/ec202d401c5992820776e21d113a6d85/
sh-4.2# journalctl
Journal file /var/log/journal/ec202d401c5992820776e21d113a6d85/system.journal uses an unsupported feature, ignoring file.
-- No entries --
sh-4.2# journalctl --version
systemd 219
+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 -SECCOMP +BLKID +ELFUTILS +KMOD +IDN

• lets exit the container and see the version of journalctl on host OS

[root@ip-172-16-6-197 core]# journalctl --version
systemd 246 (v246.7-1.fc33)
+PAM +AUDIT +SELINUX +IMA -APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +ZSTD +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=unified

What is the root cause ?

I am not sure but i think

• The systemd version inside the container (219) is obviously unable to read or interpret the log files which have been created on the host by a higher version of systemd (246)

Have tested this scenario on Fedora 31.* (CoreOS) and it works as expected

[andrewkroh]

Does journalbeat read them when it is executed directly on the host? In that case it would be using the same systemd library as the host (rather than the one shipped in the journalbeat container (219)).

[kvch]

Closing as inactive and Journalbeat is removed in 7.16. Please use journald input instead. If the issue persist using the input, feel free to open a new issue.