systemd-journald fails

[Rainer Dorsch]

Hi,

on a fresh jessie install, upgraded to stretch I get

***@scw:~# systemctl status systemd-journald.service
● systemd-journald.service - Journal Service
Loaded: loaded (/lib/systemd/system/systemd-journald.service; static; vendor preset: enabled)
Active: failed (Result: exit-code) since Sun 2016-12-04 15:11:15 UTC; 2s ago
Docs: man:systemd-journald.service(8)
man:journald.conf(5)
Process: 23592 ExecStart=/lib/systemd/systemd-journald (code=exited, status=1/FAILURE)
Main PID: 23592 (code=exited, status=1/FAILURE)
***@scw:~#

I think this then results in errors during an apt-get upgrade:

[...]
After this operation, 0 B of additional disk space will be used.
Do you want to continue? [Y/n]
Setting up mariadb-server-10.0 (10.0.28-2) ...
logger: socket /dev/log: Connection refused
logger: socket /dev/log: Connection refused
dpkg: error processing package mariadb-server-10.0 (--configure):
subprocess installed post-installation script returned error exit status 1
Errors were encountered while processing:
[...]

The system is hosted at scaleway, i.e. it is not a Debian kernel, which is running.

Any hints what I could do to resolve this, is welcome.

Thanks
Rainer

[deloptes]

Post by Rainer Dorsch
The system is hosted at scaleway, i.e. it is not a Debian kernel, which is running.

would you mind if we know what is the kernel and the systemd version?

I don't think it is a kernel issue though.
You see your systemd-journal fails to start so you don't provide /dev/log
which is needed by ... well perhaps most of the newer applications. Try
solving this first

regards

[emetib]

Post by Rainer Dorsch
/dev/log

?

try and take a look at 'journalctl -b 0'
that might give some info or you can look at '/var/log/messages' and/or '/var/log/syslog'. those last two kind of depends on how your systemd is set up.

take care
em

[Rainer Dorsch]

Post by emetib

Post by Rainer Dorsch
/dev/log

?
try and take a look at 'journalctl -b 0'
that might give some info or you can look at '/var/log/messages' and/or '/var/log/syslog'. those last two kind of depends on how your systemd is set up.

***@scw:~# journalctl -b 0
-- No entries --
***@scw:~#

/var/log/syslog (I can provide more if needed, but pastbinit was unhappy to send more in one chunk):

http://paste.debian.net/900634/ (line 1-1000)
http://paste.debian.net/900638/ (line 1001-1800)

The first real suspicious lines I see here (around line 1200):

Dec 4 09:43:26 scw-1fe3cf systemd[1]: [/lib/systemd/system/systemd-udevd.service:26] Unknown lvalue 'TasksMax' in section 'Service'
Dec 4 09:43:26 scw-1fe3cf systemd[1]: [/lib/systemd/system/systemd-udevd.service:28] Unknown lvalue 'MemoryDenyWriteExecute' in section 'Service'
Dec 4 09:43:26 scw-1fe3cf systemd[1]: [/lib/systemd/system/systemd-udevd.service:29] Unknown lvalue 'RestrictRealtime' in section 'Service'
Dec 4 09:43:26 scw-1fe3cf systemd[1]: [/lib/systemd/system/systemd-udevd.service:26] Unknown lvalue 'TasksMax' in section 'Service'
Dec 4 09:43:26 scw-1fe3cf systemd[1]: [/lib/systemd/system/systemd-udevd.service:28] Unknown lvalue 'MemoryDenyWriteExecute' in section 'Service'
Dec 4 09:43:26 scw-1fe3cf systemd[1]: [/lib/systemd/system/systemd-udevd.service:29] Unknown lvalue 'RestrictRealtime' in section 'Service'


/var/log/messages does not look suspicious for me:

http://paste.debian.net/900635/

Thanks
Rainer

[emetib]

quick question for you.

if you wanted to have stretch, why did you install jessie and then upgrade instead of just installing stretch?

https://www.debian.org/devel/debian-installer/

i've personally found it's better to just install the testing image right away instead of doing a dist-upgrade. that way if somethings do change, like going from sysinit to systemd, things are all ready in place.

take a look at this forum for all of the discussions on sysinit vs systemd.

take care
em

[Greg Wooledge]

Post by emetib
if you wanted to have stretch, why did you install jessie and then upgrade instead of just installing stretch?

Because until the stretch installer is ready for prime time, that is
the safest way to get stretch.

Post by emetib
https://www.debian.org/devel/debian-installer/

Currently "alpha 8". I don't know how many people consider this to be
ready for end users, versus ready for additional testing by people
willing & able to report and/or fix installer bugs.

Personally I'm in no hurry for stretch at this time, but I can see how
people with newer hardware could be.

[Rainer Dorsch]

Hi emetib,

Post by emetib
quick question for you.
if you wanted to have stretch, why did you install jessie and then upgrade instead of just installing stretch?
https://www.debian.org/devel/debian-installer/

scaleway offered jessie and sid as ready to go images. I thought it should be safer to upgrade from jessie than to wait until the sid packages migrated to stretch.

Post by emetib
i've personally found it's better to just install the testing image right away instead of doing a dist-upgrade.

A dist-upgrade should eventually work (and also did in the past 20 years for me -)

Post by emetib
that way if somethings do change, like going from sysinit to systemd, things are all ready in place.

Jessie is also using systemd (?).

Post by emetib
take a look at this forum for all of the discussions on sysinit vs systemd.

Hmm...do you suggest to go to sysvinit? Hmmm...

Thanks
Rainer

[Greg Wooledge]

Post by Rainer Dorsch
Jessie is also using systemd (?).

Yes, jessie is the first release to use systemd by default. (It was
available in wheezy as a "technology preview" only.) You're also
allowed to run jessie using sysvinit, but this is not the default.

[Dan Ritter]

Post by Rainer Dorsch

Post by emetib
take a look at this forum for all of the discussions on sysinit vs systemd.

Hmm...do you suggest to go to sysvinit? Hmmm...

http://without-systemd.org/wiki/index.php/How_to_remove_systemd_from_a_Debian_jessie/sid_installation

Has easy to follow instructions.

-dsr-

[emetib]

hey rainer

yeah i wouldn't go with sid, it's fun to play around with yet not for a server install.

sysinit vs systemd is up to you. i haven't had a problem with systemd, it's just another thing that you have to read about to get the hang of it.

you will have to forgive me for not reading all the way through your original post and not noticing that this is a hosted system.

i took a look at my virtual testing machine's '/lib/systemd/system/systemd-udev.service' --
17 [Service]
18 Type=notify
19 OOMScoreAdjust=-1000
20 Sockets=systemd-udevd-control.socket systemd-udevd-kernel.socket
21 Restart=always
22 RestartSec=0
23 ExecStart=/lib/systemd/systemd-udevd
24 KillMode=mixed
25 WatchdogSec=3min
26 TasksMax=infinity
27 MountFlags=slave
28 MemoryDenyWriteExecute=yes
29 RestrictRealtime=yes

see if yours are similar.
take a look at 'man systemd-udevd.service', it doesn't talk about the service arguments, yet gives references to other man pages.

em

[Jonathan de Boyne Pollard]

It does indeed. It is systemd-journald that resides at the server end
of /dev/log on a systemd operating system. Quite a lot of other stuff
will break for you if you don't have a running systemd-journald, because
there are quite a lot of things plumbed into systemd-journald, not least
the standard outputs of many of the services on your system.

Restarting systemd-journald historically has not worked *a lot* in
systemd. Bugs about it abound. Things just don't get hooked back up
correctly, and services are surprised and confused by EPIPE errors and
SIGPIPE signals when simply writing to their standard output or error.

* https://bugzilla.redhat.com/show_bug.cgi?id=1378929
* https://bugs.freedesktop.org/show_bug.cgi?id=84923
* https://github.com/chef-cookbooks/chef-client/issues/359
* https://bugs.freedesktop.org/show_bug.cgi?id=56043
... and so on.

You need systemd-journald running. Your best course of action is to see
whether it comes up properly at bootstrap, in normal, rescue, or
emergency mode. If it does not, then *why* is pretty much the first
problem that you need to solve. Note that it is correct for the service
unit to be "static" rather than "enabled". The unit that needs to be
"enabled" is systemd-journald.socket, which is what fires up
systemd-journald.service.

Of course, if a service does not come up, the first port of call is the
log from the service manager to see what errors are recorded, the
infamous "So what do 'journalctl -u systemd-journald -e -b' and
'systemctl status systemd-journald' say?". But in the systemd world
that log is also managed by systemd-journald. Chicken. Egg.

(This is why designs in the daemontools family world have more than one
log daemon. Laurent Bercot describes things in terms of a "logging
chain". If mysqld doesn't start, then one consults the logs maintained
by its (individual) log service. If the mysqld log service itself
didn't start, then one consults the logs maintained by the service
manager's own (distinct) log service.)
[/lib/systemd/system/systemd-journald.service:25] Unknown lvalue
'FileDescriptorStoreMax' in section 'Service'

Oh look. The version of systemd that you have doesn't like the settings
in the systemd-supplied service units that you have. Have you checked
that everything is at the same version?
[/lib/systemd/system/emergency.service:19] Not an absolute path,
ignoring: -/root
[/lib/systemd/system/rescue.service:18] Not an absolute path, ignoring:
-/root

The version of systemd that you have doesn't like some other settings,
too. Rescue and emergency modes are going to be interesting for you, I
suspect.

[Rainer Dorsch]

Hi Jonathan,

many thanks for your response.

Post by Jonathan de Boyne Pollard
It does indeed. It is systemd-journald that resides at the server end
of /dev/log on a systemd operating system. Quite a lot of other stuff
will break for you if you don't have a running systemd-journald, because
there are quite a lot of things plumbed into systemd-journald, not least
the standard outputs of many of the services on your system.
Restarting systemd-journald historically has not worked *a lot* in
systemd. Bugs about it abound. Things just don't get hooked back up
correctly, and services are surprised and confused by EPIPE errors and
SIGPIPE signals when simply writing to their standard output or error.
* https://bugzilla.redhat.com/show_bug.cgi?id=1378929
* https://bugs.freedesktop.org/show_bug.cgi?id=84923
* https://github.com/chef-cookbooks/chef-client/issues/359
* https://bugs.freedesktop.org/show_bug.cgi?id=56043
... and so on.
You need systemd-journald running. Your best course of action is to see
whether it comes up properly at bootstrap, in normal, rescue, or
emergency mode. If it does not, then *why* is pretty much the first
problem that you need to solve. Note that it is correct for the service
unit to be "static" rather than "enabled". The unit that needs to be
"enabled" is systemd-journald.socket, which is what fires up
systemd-journald.service.

Hmmm...I need to find out how I boot in rescue mode on a virtual machine from scaleway (KVM).

Post by Jonathan de Boyne Pollard
Of course, if a service does not come up, the first port of call is the
log from the service manager to see what errors are recorded, the
infamous "So what do 'journalctl -u systemd-journald -e -b' and
'systemctl status systemd-journald' say?". But in the systemd world
that log is also managed by systemd-journald. Chicken. Egg.

Indeed there is not much information.

***@scw:~# systemctl status systemd-journald
● systemd-journald.service - Journal Service
Loaded: loaded (/lib/systemd/system/systemd-journald.service; static; vendor preset: enabled)
Active: failed (Result: exit-code) since Fri 2016-12-09 20:27:23 UTC; 1min 11s ago
Docs: man:systemd-journald.service(8)
man:journald.conf(5)
Main PID: 2395 (code=exited, status=1/FAILURE)
***@scw:~# journalctl -u systemd-journald -e -b
-- No entries --

Post by Jonathan de Boyne Pollard
(This is why designs in the daemontools family world have more than one
log daemon. Laurent Bercot describes things in terms of a "logging
chain". If mysqld doesn't start, then one consults the logs maintained
by its (individual) log service. If the mysqld log service itself
didn't start, then one consults the logs maintained by the service
manager's own (distinct) log service.)
[/lib/systemd/system/systemd-journald.service:25] Unknown lvalue
'FileDescriptorStoreMax' in section 'Service'
Oh look. The version of systemd that you have doesn't like the settings
in the systemd-supplied service units that you have. Have you checked
that everything is at the same version?

It is an uptodate stretch system, therefore I would assume that the systemd components fit together.

Is there anything more you include in "everything"? :-)

***@scw:~# dpkg --get-selections|grep -i systemd
libpam-systemd:amd64 install
libsystemd0:amd64 install
systemd install
systemd-sysv install
***@scw:~# apt-cache policy systemd
systemd:
Installed: 232-7
Candidate: 232-7
Version table:
*** 232-7 500
500 http://ftp.fr.debian.org/debian stretch/main amd64 Packages
100 /var/lib/dpkg/status
***@scw:~# apt-cache policy systemd-sysv
systemd-sysv:
Installed: 232-7
Candidate: 232-7
Version table:
*** 232-7 500
500 http://ftp.fr.debian.org/debian stretch/main amd64 Packages
100 /var/lib/dpkg/status
***@scw:~# apt-cache policy libsystemd
libsystemd0 libsystemd-dev
***@scw:~# apt-cache policy libsystemd0
libsystemd0:
Installed: 232-7
Candidate: 232-7
Version table:
*** 232-7 500
500 http://ftp.fr.debian.org/debian stretch/main amd64 Packages
100 /var/lib/dpkg/status
***@scw:~# apt-cache policy libpam-systemd
libpam-systemd:
Installed: 232-7
Candidate: 232-7
Version table:
*** 232-7 500
500 http://ftp.fr.debian.org/debian stretch/main amd64 Packages
100 /var/lib/dpkg/status

Post by Jonathan de Boyne Pollard
[/lib/systemd/system/emergency.service:19] Not an absolute path,
ignoring: -/root
-/root
The version of systemd that you have doesn't like some other settings,
too. Rescue and emergency modes are going to be interesting for you, I
suspect.

I try to figure out tomorrow if I can boot one of them....

Thanks again
Rainer

[Jonathan de Boyne Pollard]

[ 20.704584] systemd[1]: Initializing machine ID from D-Bus machine ID.
Invalid argument

You need to look at at least two files, /var/lib/dbus/machine-id and
/etc/machine-id . They should contain only a 128-bit hexadecimal number
plus a newline, and this number must match the number used in the
directory names below /run/log/journal/ and /var/log/journal/ .

[Rainer Dorsch]

Post by Jonathan de Boyne Pollard

[ 20.704584] systemd[1]: Initializing machine ID from D-Bus machine ID.
Invalid argument

You need to look at at least two files, /var/lib/dbus/machine-id and
/etc/machine-id . They should contain only a 128-bit hexadecimal number
plus a newline, and this number must match the number used in the
directory names below /run/log/journal/ and /var/log/journal/ .

Many thanks, Jonathan, I think that resolves the problem:

***@scw:~# cat /var/lib/dbus/machine-id
26da2c29c6a545fd9af95d29ca9b5a5a
***@scw:~# cat /etc/machine-id
26da2c29c6a545fd9af95d29ca9b5a5a
6df
***@scw:~#

Not sure how the 6df ended in /etc/machine-id, but after removing that things seem to have settled:

***@scw:~# systemctl status
● scw
State: degraded
Jobs: 0 queued
Failed: 1 units
Since: Sat 2016-12-10 12:32:15 UTC; 1min 36s ago
CGroup: /
├─user.slice
│ └─user-0.slice
│ ├─***@0.service
│ │ └─init.scope
│ │ ├─3816 /lib/systemd/systemd --user
│ │ └─3824 (sd-pam)
│ └─session-1.scope
│ ├─3814 sshd: ***@pts/0
│ ├─4508 -bash
│ ├─4514 systemctl status
│ └─4515 pager
├─init.scope
│ └─1 /sbin/init
└─system.slice
├─irqbalance.service
│ └─3239 /usr/sbin/irqbalance --pid=/var/run/irqbalance.pid
├─dbus.service
│ └─3161 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation
├─ssh.service
│ └─3430 /usr/sbin/sshd -D
├─system-serial\x2dgetty.slice
│ └─serial-***@ttyS0.service
│ └─3453 /sbin/agetty --keep-baud 115200,38400,9600 ttyS0 vt220
├─ntp.service
│ └─3804 /usr/sbin/ntpd -p /var/run/ntpd.pid -g -c /run/ntp.conf.dhcp -u 104:108
├─system-getty.slice
│ └─***@tty1.service
│ └─3449 /sbin/agetty --noclear tty1 linux
├─systemd-logind.service
│ └─3198 /lib/systemd/systemd-logind
├─cron.service
│ └─3212 /usr/sbin/cron -f
├─apache2.service
│ ├─3497 /usr/sbin/apache2 -k start
│ ├─3505 /usr/sbin/apache2 -k start
│ ├─3506 /usr/sbin/apache2 -k start
│ ├─3507 /usr/sbin/apache2 -k start
│ ├─3508 /usr/sbin/apache2 -k start
│ └─3511 /usr/sbin/apache2 -k start
├─systemd-udevd.service
│ └─2164 /lib/systemd/systemd-udevd
├─rsyslog.service
│ └─3180 /usr/sbin/rsyslogd -n
├─networking.service
│ └─3359 /sbin/dhclient -v -pf /run/dhclient.eth0.pid -lf /var/lib/dhcp/dhclient.eth0.leases -I -df /var/lib/dhcp/dhclient6.eth0.leases eth0
├─systemd-journald.service
│ └─2142 /lib/systemd/systemd-journald
├─bind9.service
│ └─3422 /usr/sbin/named -f -u bind
└─exim4.service
└─3801 /usr/sbin/exim4 -bd -q30m
***@scw:~# systemctl status systemd-journald
● systemd-journald.service - Journal Service
Loaded: loaded (/lib/systemd/system/systemd-journald.service; static; vendor preset: enabled)
Active: active (running) since Sat 2016-12-10 12:32:16 UTC; 1min 47s ago
Docs: man:systemd-journald.service(8)
man:journald.conf(5)
Main PID: 2142 (systemd-journal)
Status: "Processing requests..."
Tasks: 1 (limit: 4915)
CGroup: /system.slice/systemd-journald.service
└─2142 /lib/systemd/systemd-journald

Dec 10 12:32:16 scw systemd-journald[2142]: Missed 152 kernel messages
Dec 10 12:32:16 scw systemd-journald[2142]: Journal started
Dec 10 12:32:16 scw systemd-journald[2142]: Runtime journal (/run/log/journal/26da2c29c6a545fd9af95d29ca9b5a5a) is 0B, max 0B, 0B free.
Dec 10 12:32:16 scw systemd-journald[2142]: Runtime journal (/run/log/journal/26da2c29c6a545fd9af95d29ca9b5a5a) is 0B, max 0B, 0B free.
Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable.
***@scw:~# journalctl -u systemd-journald -e -b
[...]
-- Logs begin at Sat 2016-12-10 12:32:16 UTC, end at Sat 2016-12-10 12:34:07 UTC. --
Dec 10 12:32:16 scw systemd-journald[2142]: Missed 152 kernel messages
Dec 10 12:32:16 scw systemd-journald[2142]: Journal started
Dec 10 12:32:16 scw systemd-journald[2142]: Runtime journal (/run/log/journal/26da2c29c6a545fd9af95d29ca9b5a5a) is 0B, max 0B, 0B free.
Dec 10 12:32:16 scw systemd-journald[2142]: Runtime journal (/run/log/journal/26da2c29c6a545fd9af95d29ca9b5a5a) is 0B, max 0B, 0B free.
***@scw:~#

I upgraded from a fresh jessie installation (image from scaleway, I did not install myself). Is it worthwhile to chase down the origin of the 6df or is this a known issue which should not affect the standard upgrade path from jessie to stretch?

Kind regards
Rainer

[Michael Biebl]

Post by Rainer Dorsch
Not sure how the 6df ended in /etc/machine-id, but after removing
I upgraded from a fresh jessie installation (image from scaleway, I
did not install myself). Is it worthwhile to chase down the origin of
the 6df or is this a known issue which should not affect the standard
upgrade path from jessie to stretch?

Sounds like https://github.com/systemd/systemd/issues/4475

[Rainer Dorsch]

Post by Michael Biebl

Post by Rainer Dorsch
Not sure how the 6df ended in /etc/machine-id, but after removing
I upgraded from a fresh jessie installation (image from scaleway, I
did not install myself). Is it worthwhile to chase down the origin of
the 6df or is this a known issue which should not affect the standard
upgrade path from jessie to stretch?

Sounds like https://github.com/systemd/systemd/issues/4475

Hmmm....I setup a new jessie installation in the scaleway cloud and planed to redo the upgrade. But to my surprise even on a fresh install of the jessie image /etc/machine-id is already broken:

***@blackbox:~$ ssh ***@51.15.55.3
The authenticity of host '51.15.55.3 (51.15.55.3)' can't be established.
ECDSA key fingerprint is c1:b0:78:78:36:d9:48:af:74:de:ac:41:b6:56:5e:7b.
Are you sure you want to continue connecting (yes/no)? yes
Warning: Permanently added '51.15.55.3' (ECDSA) to the list of known hosts.
_
___ ___ __ _| | _____ ____ _ _ _
/ __|/ __/ _` | |/ _ \ \ /\ / / _` | | | |
\__ \ (_| (_| | | __/\ V V / (_| | |_| |
|___/\___\__,_|_|\___| \_/\_/ \__,_|\__, |
|___/

Welcome on Debian Jessie (GNU/Linux 4.5.7-std-3 x86_64 )

System information as of: Sat Dec 10 19:51:11 UTC 2016

System load: 0.16 Int IP Address: 10.8.60.147
Memory usage: 2.8% Pub IP Address: 51.15.55.3
Usage on /: 3% Swap usage: 0.0%
Local Users: 0 Processes: 78
Image build: 2016-04-06 System uptime: 6 min
Disk nbd0: l_ssd 50G

Documentation: https://scaleway.com/docs
Community: https://community.scaleway.com
Image source: https://github.com/scaleway/image-debian

***@scw-790923:~# cat /etc/machine-id
9d1b906dd5ea40359e2071d29c12aabe
71f
***@scw-790923:~#

But it seems the systemd version in jessie seems to be more tolerant against broken machine-id fails (?).

Regards
Rainer

[Jonathan de Boyne Pollard]

Post by Rainer Dorsch
But to my surprise even on a fresh install of the jessie image

Post by Rainer Dorsch
9d1b906dd5ea40359e2071d29c12aabe
71f

But it seems the systemd version in jessie seems to be more tolerant
against broken machine-id fails (?).

It is. Lennart Poettering introduced this intolerance on 2016-07-21.
Before then, /etc/machine-id could contain other stuff after the first
line, and systemd would ignore it because it only ever read and wrote
the 32-character ID and the newline of the first line of the file.
Lennart Poettering changed an I/O function call from an exact length
read of 33 characters to a variable length read of up to 38 characters
followed by a check that the number of characters read is only ever 33,
and the intolerance is as you see now.

So your machine IDs have possibly been like this for a long time.

Your next stops are https://github.com/systemd/systemd/issues/4025 and
https://github.com/scaleway/image-tools/issues/181 .

[Michael Biebl]

Post by Rainer Dorsch
The system is hosted at scaleway, i.e. it is not a Debian kernel, which is running.

What kernel is that? Can you check if all requirements as outlined in
/usr/share/doc/systemd/README.gz are fulfilled?

[Rainer Dorsch]

Post by Michael Biebl

Post by Rainer Dorsch
The system is hosted at scaleway, i.e. it is not a Debian kernel, which is running.

What kernel is that?
Can you check if all requirements as outlined in
/usr/share/doc/systemd/README.gz are fulfilled?

See my other post, it was an /etc/machine-id issue.

Kind regards
Rainer