Created attachment 88519 [details] journalctl -b cat /etc/sysctl.d/10-printk.conf kernel.printk = 3 3 3 3 However after reboot i see: cat /proc/sys/kernel/printk 15 3 3 3 systemctl status systemd-sysctl systemd-sysctl.service - Apply Kernel Variables Loaded: loaded (/usr/lib/systemd/system/systemd-sysctl.service; static) Active: active (exited) since Fri 2013-11-01 23:18:47 CET; 1min 40s ago Docs: man:systemd-sysctl.service(8) man:sysctl.d(5) Process: 163 ExecStart=/usr/lib/systemd/systemd-sysctl (code=exited, status=0/SUCCESS) Main PID: 163 (code=exited, status=0/SUCCESS) Nov 01 23:18:47 dell1210 systemd[1]: Starting Apply Kernel Variables... Nov 01 23:18:48 dell1210 systemd[1]: Started Apply Kernel Variables. Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable. When I manually restart systemd-sysctl.service all works fine: cat /proc/sys/kernel/printk 3 3 3 3
Is it possible that something else is overriding this setting later in the boot? As a debugging option you might want to add something like [Service] ExecStartPost=/bin/cat /proc/sys/kernel/printk to /etc/systemd/system/systemd-sysctl.service.d/cat.conf. This will record the value in the logs.
I don't know how to check it systemd-sysctl.service - Apply Kernel Variables Loaded: loaded (/usr/lib/systemd/system/systemd-sysctl.service; static) Drop-In: /etc/systemd/system/systemd-sysctl.service.d └─cat.conf Active: active (exited) since Sat 2013-11-02 00:14:00 CET; 7min ago Docs: man:systemd-sysctl.service(8) man:sysctl.d(5) Process: 183 ExecStartPost=/bin/cat /proc/sys/kernel/printk (code=exited, status=0/SUCCESS) Process: 163 ExecStart=/usr/lib/systemd/systemd-sysctl (code=exited, status=0/SUCCESS) Main PID: 163 (code=exited, status=0/SUCCESS) Nov 02 00:13:59 dell1210 systemd[1]: Starting Apply Kernel Variables... Nov 02 00:14:00 dell1210 cat[183]: 3 3 3 3 Nov 02 00:14:00 dell1210 systemd[1]: Started Apply Kernel Variables. Warning: Journal has been rotated since unit was started. Log output is incomplete or unavailable. grep -r printk /etc /etc/sysctl.d/10-printk.conf:kernel.printk = 3 3 3 3 /etc/systemd/system/systemd-sysctl.service.d/cat.conf:ExecStartPost=/bin/cat /proc/sys/kernel/printk I disabled all my services from /etc/systemd/system/multi-user.target.wants/ and reboot but after login to console it's: 15 3 3 3 (I don't use ant graphical login manager/didn't start X after login)
(In reply to comment #2) > I don't know how to check it ... > Nov 02 00:13:59 dell1210 systemd[1]: Starting Apply Kernel Variables... > Nov 02 00:14:00 dell1210 cat[183]: 3 3 3 3 > Nov 02 00:14:00 dell1210 systemd[1]: Started Apply Kernel Variables. So you can see here, that after service has run, it is set properly. Is this from after a reboot, or is it after systemctl restart systemd-sysctl.service? Judging by the low PID (183), this line is from the boot, which would mean that something else resets the variable later on.
from boot: Nov 19 15:35:05 dell1210 cat[186]: 3 3 3 3 Nov 19 15:35:06 dell1210 systemd[1]: Started Apply Kernel Variables. (...) Nov 19 15:35:08 dell1210 kernel: ------------[ cut here ]------------ Nov 19 15:35:08 dell1210 kernel: WARNING: CPU: 0 PID: 215 at kernel/mutex.c:516 __mutex_lock_sl Nov 19 15:35:08 dell1210 kernel: DEBUG_LOCKS_WARN_ON(in_interrupt()) (...) Could this resets the variable to '15 3 3 3' ? I reported this kernel bug already here: https://bugzilla.kernel.org/show_bug.cgi?id=64221 Because I tested this kernel.printk variable on other machine without such kernel warnings at boot and it works fine
however another variable from /etc/sysctl.d/ don't apply at boot: net.ipv4.tcp_allowed_congestion_control = cubic reno lp Nov 19 16:03:14 server systemd[1]: Starting Apply Kernel Variables... Nov 19 16:03:14 server cat[248]: cubic reno Nov 19 16:03:14 server systemd[1]: Started Apply Kernel Variables. I read that this is related to udev: https://bugs.archlinux.org/task/33620
Created attachment 89842 [details] unit file to debug writes to kernel.printk setting (In reply to comment #4) > Could this resets the variable to '15 3 3 3' ? > I reported this kernel bug already here: > https://bugzilla.kernel.org/show_bug.cgi?id=64221 I think that's unlikely. > I read that this is related to udev: https://bugs.archlinux.org/task/33620 This is also unrelated. 33620 is about sysctl settings for network devices which are only created after those settings have been already set. printk is always there. Can you install the attached service in /etc/systemd/system/monitor_printk.service, enable it with 'systemctl enable monitor_printk', and post the output from the 'journalctl -b' after a reboot?
Created attachment 89866 [details] journalctl -b with monitor_printk.service
(In reply to comment #6) > > > I read that this is related to udev: https://bugs.archlinux.org/task/33620 > This is also unrelated. 33620 is about sysctl settings for network devices > which are only created after those settings have been already set. printk is > always there. yes and whole Comment 5 is about 'tcp_allowed_congestion_control' variable, not printk. should I open another bug report for this? > Can you install the attached service in > /etc/systemd/system/monitor_printk.service, enable it with 'systemctl enable > monitor_printk', and post the output from the 'journalctl -b' after a reboot? ok, log attached
(In reply to comment #8) > (In reply to comment #6) > > > > > I read that this is related to udev: https://bugs.archlinux.org/task/33620 > > This is also unrelated. 33620 is about sysctl settings for network devices > > which are only created after those settings have been already set. printk is > > always there. > yes and whole Comment 5 is about 'tcp_allowed_congestion_control' variable, > not printk. should I open another bug report for this? Just debug this one first. > > Can you install the attached service in > > /etc/systemd/system/monitor_printk.service, enable it with 'systemctl enable > > monitor_printk', and post the output from the 'journalctl -b' after a reboot? > ok, log attached From the log: Nov 26 22:06:15 dell1210 cat[190]: 3 3 3 3 Nov 26 22:06:15 dell1210 inotifywait[176]: /proc/sys/kernel/printk OPEN Nov 26 22:06:15 dell1210 inotifywait[176]: /proc/sys/kernel/printk ACCESS Nov 26 22:06:15 dell1210 inotifywait[176]: /proc/sys/kernel/printk CLOSE_NOWRITE,CLOSE Nov 26 22:06:15 dell1210 systemd[1]: Started Apply Kernel Variables. ... and it doesn't seem to be set afterwards. Could you please check again that it *is* actually set to something different after the boot? So maybe your hypothesis that it is reset during the kernel oops is true. What happens if you disable the restoring of the backlight, which should remove the oops (systemctl mask systemd-backlight@acpi_video0.service systemd-backlight@acpi_video1.service)?
(In reply to comment #9) > (In reply to comment #8) > > (In reply to comment #6) > > > Can you install the attached service in > > > /etc/systemd/system/monitor_printk.service, enable it with 'systemctl enable > > > monitor_printk', and post the output from the 'journalctl -b' after a reboot? > > ok, log attached > From the log: > Nov 26 22:06:15 dell1210 cat[190]: 3 3 3 3 > Nov 26 22:06:15 dell1210 inotifywait[176]: /proc/sys/kernel/printk OPEN > Nov 26 22:06:15 dell1210 inotifywait[176]: /proc/sys/kernel/printk ACCESS > Nov 26 22:06:15 dell1210 inotifywait[176]: /proc/sys/kernel/printk > CLOSE_NOWRITE,CLOSE > Nov 26 22:06:15 dell1210 systemd[1]: Started Apply Kernel Variables. > ... and it doesn't seem to be set afterwards. Could you please check again > that it *is* actually set to something different after the boot? it's still 15 3 3 3 after boot and kernel throws usual messages on screen > So maybe your hypothesis that it is reset during the kernel oops is true. > What happens if you disable the restoring of the backlight, which should > remove the oops > (systemctl mask systemd-backlight@acpi_video0.service > systemd-backlight@acpi_video1.service)? finally after setting this printk variable works as expected (it's 3 3 3 3 after boot and I have clean terminal)
> > So maybe your hypothesis that it is reset during the kernel oops is true. > > What happens if you disable the restoring of the backlight, which should > > remove the oops > > (systemctl mask systemd-backlight@acpi_video0.service > > systemd-backlight@acpi_video1.service)? > finally after setting this printk variable works as expected (it's 3 3 3 3 > after boot and I have clean terminal) however when I manually start X later it's 15 3 3 3 again, but this is surely related to the kernel oops which appears now in logs after X server start
This is not something we can fix in systemd. Please report it on the kernel bugtracker. I think it'll help if you submit an easy reproducer, without all the systemd-related details, hopefully something like this is enough to show the bug: 1. sysctl kernel.printk 2. /usr/lib/systemd/systemd-backlight load acpi_video0 (or acpi_video1?) 3. sysctl kernel.printk
Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.