|
Bugzilla – Full Text Bug Listing |
| Summary: | systemd: why is kmsg polluted? | ||
|---|---|---|---|
| Product: | [openSUSE] openSUSE 12.1 | Reporter: | Jiri Slaby <jslaby> |
| Component: | Basesystem | Assignee: | Frederic Crozat <fcrozat> |
| Status: | RESOLVED FIXED | QA Contact: | E-mail List <qa-bugs> |
| Severity: | Normal | ||
| Priority: | P5 - None | CC: | bruno, coolo, mt, werner |
| Version: | Factory | ||
| Target Milestone: | --- | ||
| Hardware: | Other | ||
| OS: | Other | ||
| Whiteboard: | |||
| Found By: | --- | Services Priority: | |
| Business Priority: | Blocker: | --- | |
| Marketing QA Status: | --- | IT Deployment: | --- |
| Bug Depends on: | |||
| Bug Blocks: | 696902 | ||
| Attachments: |
Hardrive layout
dmesg of last boot bootchart of system |
||
|
Description
Jiri Slaby
2011-10-17 14:39:23 UTC
by default now, service output is redirected to kernel log ring buffer. however, I don't see those in my dmesg output. could you try on kernel cmdline : systemd.default_standard_output=syslog ? (In reply to comment #1) > could you try on kernel cmdline : > systemd.default_standard_output=syslog Still the same: dmesg|grep dbus|tail -1 [ 13.471948] dbus-daemon[1544]: dbus[1544]: [system] Successfully activated service 'org.freedesktop.ConsoleKit' Strangely here I didn't have any dbus message in dmesg output just some systemd dmesg | grep systemd [ 0.000000] Command line: root=/dev/vgsys/lvsuse keyboard=fr-ch-latin1 resume=/dev/vgsys/lvswap lang=en_US splash=silent quiet elevator=cfq rootfstype=ext4 rootflags=data=writeback video.allow_duplicates=1 file_caps=1 nomodeset blacklist=nouveau,radeon reboot=pci intel_iommu=on init=/bin/systemd vga=0x34d [ 0.000000] Kernel command line: root=/dev/vgsys/lvsuse keyboard=fr-ch-latin1 resume=/dev/vgsys/lvswap lang=en_US splash=silent quiet elevator=cfq rootfstype=ext4 rootflags=data=writeback video.allow_duplicates=1 file_caps=1 nomodeset blacklist=nouveau,radeon reboot=pci intel_iommu=on init=/bin/systemd vga=0x34d [ 15.962490] systemd[1]: systemd 37 running in system mode. (+PAM +LIBWRAP +AUDIT +SELINUX +SYSVINIT +LIBCRYPTSETUP; suse) [ 16.067276] systemd[1]: Set hostname to <c-3po.vellerat.ioda.net>. [ 16.595652] systemd[1]: Cannot add dependency job for unit amavis.service, ignoring: Unit amavis.service failed to load: No such file or directory. See system logs and 'systemctl status amavis.service' for details. [ 16.595668] systemd[1]: Cannot add dependency job for unit cyrus.service, ignoring: Unit cyrus.service failed to load: No such file or directory. See system logs and 'systemctl status cyrus.service' for details. [ 16.595675] systemd[1]: Cannot add dependency job for unit ldap.service, ignoring: Unit ldap.service failed to load: No such file or directory. See system logs and 'systemctl status ldap.service' for details. [ 21.885928] systemd-fsck[1074]: fsck.ext4: P\xffffffc3\xffffffa9\xffffffa9riph\xffffffc3\xffffffa9\xffffffa9rique ou ressource occup\xffffffc3\xffffffa9\xffffffa9 lors de la tentative d'ouverture de /dev/mapper/vgsys-lvsrv [ 21.885999] systemd-fsck[1074]: Syst\xffffffc3\xffffffa8\xffffffa8me de fichier mont\xffffffc3\xffffffa9\xffffffa9 ou ouvert en mode exclusif par un autre [ 21.886038] systemd-fsck[1074]: programme\xffffffc2\xffffffa0\xffffffa0? [ 21.886189] systemd-fsck[1074]: fsck failed with error code 8. [ 21.886198] systemd-fsck[1074]: Ignoring error. [ 22.169931] systemd-fsck[1083]: bootraid\xffffffc2\xffffffa0\xffffffa0: propre, 51/130560 fichiers, 88059/522228 blocs [ 22.240494] systemd-fsck[1088]: lvhome\xffffffc2\xffffffa0\xffffffa0: propre, 843033/38010880 fichiers, 56766403/152043520 blocs (v\xffffffc3\xffffffa9\xffffffa9rification dans 3 montages) cat /etc/systemd/system.conf # This file is part of systemd. ... [Manager] #LogLevel=info #LogTarget=syslog-or-kmsg #LogColor=yes #LogLocation=no #DumpCore=yes #CrashShell=no #ShowStatus=yes #SysVConsole=yes #CrashChVT=1 #CPUAffinity=1 2 #MountAuto=yes #SwapAuto=yes #DefaultControllers=cpu #DefaultStandardOutput=syslog #DefaultStandardError=inherit #JoinControllers=cpu,cpuacct (In reply to comment #3) > Strangely here I didn't have any dbus message in dmesg output > just some systemd Yes, even those are there. I want to get rid of them *all* by: [Manager] LogTarget=syslog ... but it doesn't have any effect. Neither the kernel boot parameters. BTW the /dev/kmsg writing process is /lib/systemd/systemd-kmsg-syslogd if it helps somehow. which syslog implementation are you using ? (In reply to comment #6) > which syslog implementation are you using ? rsyslog. But: # /etc/init.d/syslog status syslog.service - System Logging Service Loaded: error (Reason: Invalid argument) Active: inactive (dead) CGroup: name=systemd:/system/syslog.service # systemctl status syslog.service syslog.service - System Logging Service Loaded: error (Reason: Invalid argument) Active: inactive (dead) CGroup: name=systemd:/system/syslog.service # systemctl status rsyslog.service rsyslog.service Loaded: error (Reason: No such file or directory) Active: inactive (dead) # ps aux|grep rsyslog root 3079 0.0 0.0 6792 868 ttyS0 S+ 15:02 0:00 grep rsyslog I have no idea what is going on... syslog.service should be running (syslog implementation are now socket-activated, which is why rsyslog.service doesn't show it). adding werner, he might have an idea why rsyslog isn't running rsyslog is started by syslog.service which depend on /etc/sysconfig/syslog please do not mix up with rsyslog.service Currently the generator /lib/systemd/system-generators/syslog-service-generator provides with the help of /etc/sysconfig/syslog the core file used by /etc/sysconfig/syslog/syslog.service So to answer the question "why is kmsg polluted"... It is because syslog was not running for some reason. The cure was to change
SYSLOG_DAEMON=""
in /etc/sysconfig/syslog to
SYSLOG_DAEMON="rsyslogd"
reboot and then back to
SYSLOG_DAEMON=""
and reboot.
Now it shows properly the status and everything works:
# systemctl status syslog.service
syslog.service - System Logging Service
Loaded: loaded (/lib/systemd/system/syslog.service; enabled)
Active: active (running) since Thu, 20 Oct 2011 16:18:54 +0200; 31s ago
Process: 725 ExecStart=/sbin/rsyslogd -c 5 -f /etc/rsyslog.early.conf (code=exited, status=0/SUCCESS)
Process: 715 ExecStartPre=/var/run/rsyslog/addsockets (code=exited, status=0/SUCCESS)
Process: 688 ExecStartPre=/bin/systemctl stop systemd-kmsg-syslogd.service (code=exited, status=0/SUCCESS)
Main PID: 737 (rsyslogd)
CGroup: name=systemd:/system/syslog.service
└ 737 /sbin/rsyslogd -c 5 -f /etc/rsyslog.early.conf
I have no more polkit blob in my kernel messages. Thanks.
Hmm... could it be that there were no syslog daemon installed for a while? e.g. because all daemons has been uninstalled (with breaking deps?) Then the fallback to another installed one may fail and rpm -e will stop it... or something like that. (In reply to comment #11) > Hmm... could it be that there were no syslog daemon installed for a while? > e.g. because all daemons has been uninstalled (with breaking deps?) No, I found what probably causes that. A kernel without initrd. I'm using a monolith without any modules. When I boot that kernel everything breaks. This is in a virtual machine. The weird thing is I don't see it on the host as it runs the very same system (factory with this monolith). AFAIK we do not support systems without initrd a few years now. Nevertheless this should (IMHO) not be reason for a not running syslogger daemon. Please have a look at /run/systemd/syslog.core this is the core file which will be included by /lib/systemd/system/syslog.service This core file will be generated by /lib/systemd/system-generators/syslog-service-generator by using /etc/sysconfig/syslog that is for SYSLOG_DAEMON=syslog-ng the syslog-ng is used, for SYSLOG_DAEMON=rsyslogd the rsyslogd is used, and for any other value and even if empty the syslogd is used. (In reply to comment #13) > Please have a look at /run/systemd/syslog.core this is the core > file which will be included by /lib/systemd/system/syslog.service It contains this: ExecStart=/sbin/rsyslogd -c 5 -f /etc/rsyslog.early.conf ExecReload=/sbin/killproc -p /var/run/rsyslogd.pid -HUP /sbin/rsyslogd But with initrd I see this: [Service] Type=forking PIDFile=/var/run/rsyslogd.pid Sockets=syslog.socket StandardOutput=null ExecStartPre=/bin/systemctl stop systemd-kmsg-syslogd.service ExecStartPre=-/var/run/rsyslog/addsockets ExecStart=/sbin/rsyslogd -c 5 -f /etc/rsyslog.early.conf ExecReload=/sbin/killproc -p /var/run/rsyslogd.pid -HUP /sbin/rsyslogd So I redirected stderr of "(/bin/cat > $tmpcore)<<-EOF" to a file in /run. And voila: /lib/systemd/system-generators/syslog-service-generator: line 194: cannot create temp file for here-document: Read-only file system It means bash wants to store the contents of the file to /tmp before it is passed to cat. And /tmp is ro at that time. And it explains why my desktop doesn't suffer from that -- I use rw kernel parameter. This indeed fixes it: @@ -176,6 +176,7 @@ # trap 'rm -f "$service"' EXIT tmpcore=$(/bin/mktemp $RUN_PATH/syslog.XXXXXXXX) || exit 1 +TMPDIR=/run (/bin/cat > $tmpcore)<<-EOF # Warning: Do not edit as this file has been and will be autogenerated # by $0 good catch ... I've added
--- syslog-service-generator (revision 65)
+++ syslog-service-generator (working copy)
@@ -18,6 +18,9 @@
#
umask 0022
+TMPDIR=/run
+
+export TMPDIR
: ${SBINDIR:=/sbin}
: ${RUN_PATH:=/run/systemd}
which should avoid the problem (and due export this may help
any future changes adding external programs using TMPDIR.
This is an autogenerated message for OBS integration: This bug (724610) was mentioned in https://build.opensuse.org/request/show/88943 Factory / syslogd This is an autogenerated message for OBS integration: This bug (724610) was mentioned in https://build.opensuse.org/request/show/89126 Factory / syslogd 5 days after the accepted SR it's not in factory ? Reopen due to non publication on OBS https://build.opensuse.org/package/binary?arch=i586&filename=syslog-service-1.4.1-752.3.noarch.rpm&package=syslogd&project=openSUSE%3AFactory&repository=standard http://download.opensuse.org/factory/repo/oss/suse/noarch/syslog-service-1.4.1-749.1.noarch.rpm When I try to fix it manually, by pushing the TMP=/run
Reinstalling all service rsyslog syslog-service systemd
I continue to have an error and get a wrong /run/systemd/syslog.core generated file
cat /etc/sysconfig/syslog
## Path: System/Logging
## Description: System logging
## Type: list(syslogd,syslog-ng,rsyslogd,"")
## Default: ""
## Config: ""
## ServiceRestart: syslog
#
# The name of the syslog daemon to use as syslog service:
# "syslogd", "syslog-ng", "rsyslogd" or "" for autodetect.
#
SYSLOG_DAEMON="rsyslogd"
## Type: list(5)
## Default: "5"
## Config: ""
## ServiceRestart: syslog
#
# The native version compatibility level of the current rsyslogd.
#
# Note, that this variable is read-only -- please do not change it!
# Instead, please adopt the RSYSLOGD_COMPAT_VERSION variable.
#
# This variable will be updated while every installation/upgrade of
# the rsyslog daemon package.
#
RSYSLOGD_NATIVE_VERSION="5"
## Type: integer(0:5)
## Default: ""
## Config: ""
## ServiceRestart: syslog
#
# Version compatibility level to run rsyslogd with (-c parameter).
# Set to the desired version number rsyslogd shall be compatible with.
#
# Default is to run in native mode if the currently installed rsyslog
# daemon version.
#
# Note: Changes to this variable may need adoption of the config file
# or break features used in the /etc/init.d/syslog script by default.
#
RSYSLOGD_COMPAT_VERSION=""
## Type: string
## Default: ""
## Config: ""
## ServiceRestart: syslog
#
# Parameters for rsyslogd, except of the version compatibility (-c)
# and the config file (-f), because they're used by sysconfig and
# earlysysconfig init scripts.
#
# See also the RSYSLOGD_COMPAT_VERSION variable in this file, the
# documentation provided in /usr/share/doc/packages/rsyslog/doc by
# the rsyslog-doc package and the rsyslogd(8) and rsyslog.conf(5)
# manual pages.
#
RSYSLOGD_PARAMS=""
cat /run/systemd/syslog.core
ExecStart=/sbin/rsyslogd -c 5 -f /etc/rsyslog.early.conf
ExecReload=/sbin/killproc -p /var/run/rsyslogd.pid -HUP /sbin/rsyslogd
cat /lib/systemd/system/syslog.service
# /lib/systemd/system/syslog.service
#
# This file is part of package klogd.
#
# Copyright (c) 2011 SuSE LINUX Products GmbH, Germany.
# Author: Werner Fink
# Please send feedback to http://www.suse.de/feedback
#
# Description:
#
# Used to start one of the System Logging Service daemons
# depending on the configuration found in /etc/sysconfig/syslog.
#
[Unit]
Description=System Logging Service
Requires=var-run.mount syslog.target
After=var-run.mount
Before=syslog.target
OnFailure=systemd-kmsg-syslogd.service
Conflicts=syslog-ng.service rsyslog.service
#
# Now systemd include the further dependency rules and
# Service section. This include will be automatically
# updated depending on the configuration.
#
.include /run/systemd/syslog.core
[Install]
WantedBy=multi-user.target
systemctl status syslog.service
syslog.service - System Logging Service
Loaded: error (Reason: Invalid argument)
Active: inactive (dead)
CGroup: name=systemd:/system/syslog.service
cat /proc/cmdline
root=/dev/vgsys/lvsuse keyboard=fr-ch-latin1 resume=/dev/vgsys/lvswap lang=en_US splash=silent quiet elevator=cfq rootfstype=ext4 rootflags=data=writeback video.allow_duplicates=1 file_caps=1 nomodeset blacklist=nouveau,radeon reboot=pci intel_iommu=on init=/bin/systemd vga=0x34d ro
cat /etc/fstab
/dev/vgsys/lvsuse / ext4 data=writeback,acl,user_xattr,barrier=1,commit=60,noatime,usrjquota=aquota.user,grpjquota=aquota.group,jqfmt=vfsv0 1 1
UUID=f25ecb65-b690-4c17-8572-fb7a74a1f546 /boot ext4 noatime,acl,user_xattr,barrier=1 1 2
/dev/vgsys/lvhome /home ext4 data=writeback,acl,user_xattr,barrier=1,commit=60,noatime,usrjquota=aquota.user,grpjquota=aquota.group,jqfmt=vfsv0 1 2
/dev/vgsys/lvsrv /srv ext4 data=writeback,acl,user_xattr,barrier=1,commit=30,noatime,usrjquota=aquota.user,grpjquota=aquota.group,jqfmt=vfsv0 1 2
/dev/mapper/vgsys-lvswap swap swap defaults 0 0
/dev/sda2 /media/rescue-sda vfat noatime,users,noauto,iocharset=utf8,codepage=437,users,gid=users,umask=0002,utf8=true 0 0
/dev/sdb2 /media/rescue-sdb vfat noatime,users,noauto,iocharset=utf8,codepage=437,users,gid=users,umask=0002,utf8=true 0 0
proc /proc proc defaults 0 0
sysfs /sys sysfs noauto 0 0
debugfs /sys/kernel/debug debugfs noauto 0 0
usbfs /proc/bus/usb usbfs noauto 0 0
devpts /dev/pts devpts mode=0620,gid=5 0 0
# Montage ipv6 NFS ioda-net
yoda:/ioda/data /ioda/data.nfs nfs noauto,defaults,soft,rw,posix,noatime,nodiratime,mountproto=tcp6 0 0
yoda:/ioda/home /ioda/home nfs noauto,defaults,soft,rw,posix,noatime,nodiratime,mountproto=tcp6 0 0
yoda:/ioda/install /ioda/install nfs noauto,defaults,soft,rw,posix,noatime,nodiratime,mountproto=tcp6 0 0
yoda:/ioda_saves /ioda/saves nfs noauto,defaults,soft,rw,posix,noatime,nodiratime,mountproto=tcp6 0 0
yoda:/ioda/archives /ioda/archives nfs noauto,defaults,soft,rw,posix,noatime,nodiratime,mountproto=tcp6 0 0
yoda:/srv/mirror /ioda/mirror nfs noauto,defaults,soft,rw,posix,noatime,nodiratime,mountproto=tcp6 0 0
# usb3-external backup
UUID=f60ba616-e306-4568-82e1-2cd37ef0ad9d /media/backup btrfs noauto,users,noatime,nodiratime 0 0
LABEL=lvsigeom /sigeom btrfs noauto,rw,users,noexec,nodev,suid,noatime,nodiratime 0 0
LABEL=lvobsbuild /media/obsbuild ext4 noauto,rw,users,exec,dev,suid,noatime,nodiratime,acl,user_xattr,barrier=0,commit=10 0 0
LABEL=lvobsswap swap swap noauto,defaults 0 0
My hardrive layout is the following
See graph picture
md1 is fully encrypted, and then is opened at boot time by entering my keypass
Created attachment 459449 [details]
Hardrive layout
Created attachment 459450 [details]
dmesg of last boot
dmesg after applying the TMP=/run fix
Created attachment 459451 [details]
bootchart of system
systemd Bootchart
Testing on a traditional factory system, the script work as expected cat /run/systemd/syslog.core # Warning: Do not edit as this file has been and will be autogenerated # by /lib/systemd/system-generators/syslog-service-generator [Service] Type=forking PIDFile=/var/run/rsyslogd.pid Sockets=syslog.socket StandardOutput=null ExecStartPre=/bin/systemctl stop systemd-kmsg-syslogd.service ExecStartPre=-/var/run/rsyslog/addsockets ExecStart=/sbin/rsyslogd -c 5 -f /etc/rsyslog.early.conf ExecReload=/sbin/killproc -p /var/run/rsyslogd.pid -HUP /sbin/rsyslogd So there's a missing piece somewhere when you run on a full encrypted/md/vg system After copying pasting the good content of syslog.core
I've this result
systemctl status syslog.service
syslog.service - System Logging Service
Loaded: loaded (/lib/systemd/system/syslog.service; enabled)
Active: inactive (dead)
CGroup: name=systemd:/system/syslog.service
c-3po:~ # systemctl start syslog.service
c-3po:~ # systemctl status syslog.service
syslog.service - System Logging Service
Loaded: loaded (/lib/systemd/system/syslog.service; enabled)
Active: active (running) since Sun, 30 Oct 2011 13:47:11 +0100; 2s ago
Process: 14025 ExecStart=/sbin/rsyslogd -c 5 -f /etc/rsyslog.early.conf (code=exited, status=0/SUCCESS)
Process: 14023 ExecStartPre=/var/run/rsyslog/addsockets (code=exited, status=203/EXEC)
Process: 14020 ExecStartPre=/bin/systemctl stop systemd-kmsg-syslogd.service (code=exited, status=0/SUCCESS)
Main PID: 14026 (rsyslogd)
CGroup: name=systemd:/system/syslog.service
└ 14026 /sbin/rsyslogd -c 5 -f /etc/rsyslog.early.conf
IMHO this *is* published as I've just checked |