[systemd-devel] systemd.journald.forward_to doesn't forward all journal messages

Wed Jul 31 18:30:01 UTC 2019

On Tue, Jul 30, 2019 at 3:39 PM Chris Murphy <lists at colorremedies.com>
wrote:

> On Mon, Jul 29, 2019 at 1:26 AM Lennart Poettering
> <lennart at poettering.net> wrote:
> >
> > On So, 28.07.19 22:11, Chris Murphy (lists at colorremedies.com) wrote:
> >
> > > Using either of the following:
> > >
> > > systemd.log_level=debug systemd.journald.forward_to_kmsg log_buf_len=8M
> > >
> > > systemd.log_level=debug systemd.log_target=kmsg log_buf_len=8M
> >
> > Note that this is not sufficient. You also have to pass
> > "printk.devkmsg=on" too, otherwise the kernel ratelimits log output
> > from usperspace ridiculously a lot, and you will see lots of dropped
> > messages.
> >
> > I have documented this now here:
> >
> > https://github.com/systemd/systemd/pull/13208
>
> BOOT_IMAGE=/images/pxeboot/vmlinuz
> root=live:CDLABEL=Fedora-WS-Live-rawh-20190728-n-1 rd.live.image
> systemd.wants=zram-swap.service systemd.log_level=debug
> systemd.journald.forward_to_kmsg log_buf_len=8M printk.devkmsg=on
>
> Many messages I see in the journal still do not appear in kmsg. For
> example from /dev/kmsg
>
> 6,20619,201107529,-;zram: Cannot change disksize for initialized device
> 12,23154,208596765,-;org.fedoraproject.Anaconda.Modules.Network[2498]:
> DEBUG:anaconda.modules.network.network:Applying boot options
> KernelArguments([('BOOT_IMAGE', '/images/pxeboot/vmlinuz'), ('root',
> 'live:CDLABEL=Fedora-WS-Live-rawh-20190728-n-1'), ('rd.live.image',
> None), ('systemd.wants', 'zram-swap.service'), ('systemd.log_level',
> 'debug'), ('systemd.journald.forward_to_kmsg', None), ('log_buf_len',
> '8M'), ('printk.devkmsg', 'on')])
> 12,25049,210822858,-;org.fedoraproject.Anaconda.Modules.Storage[2498]:
> DEBUG:anaconda.modules.storage.disk_selection.selection:Protected
> devices are set to '['/dev/zram0']'.
> ^C
> [root at localhost-live liveuser]# journalctl -o short-monotonic | grep zram
> [  203.224915] localhost-live systemd[1477]: Added job
> dev-zram0.device/nop to transaction.
> [  203.225017] localhost-live systemd[1477]: dev-zram0.device:
> Installed new job dev-zram0.device/nop as 295
> [  203.225143] localhost-live systemd[1477]: Added job
> sys-devices-virtual-block-zram0.device/nop to transaction.
> [  203.225245] localhost-live systemd[1477]:
> sys-devices-virtual-block-zram0.device: Installed new job
> sys-devices-virtual-block-zram0.device/nop as 296
> [  203.225355] localhost-live systemd[1477]:
> sys-devices-virtual-block-zram0.device: Job 296
> sys-devices-virtual-block-zram0.device/nop finished, result=done
> [  203.225570] localhost-live systemd[1477]: dev-zram0.device: Job 295
> dev-zram0.device/nop finished, result=done
> [  208.959944] localhost-live systemd[1477]: Added job
> dev-zram0.device/nop to transaction.
> [  208.961015] localhost-live systemd[1477]: dev-zram0.device:
> Installed new job dev-zram0.device/nop as 340
> [  208.961324] localhost-live systemd[1477]: Added job
> sys-devices-virtual-block-zram0.device/nop to transaction.
> [  208.961508] localhost-live systemd[1477]:
> sys-devices-virtual-block-zram0.device: Installed new job
> sys-devices-virtual-block-zram0.device/nop as 341
> [  208.961789] localhost-live systemd[1477]:
> sys-devices-virtual-block-zram0.device: Job 341
> sys-devices-virtual-block-zram0.device/nop finished, result=done
> [  208.962021] localhost-live systemd[1477]: dev-zram0.device: Job 340
> dev-zram0.device/nop finished, result=done
> [  209.822448] localhost-live systemd[1477]: Added job
> dev-zram0.device/nop to transaction.
> [  209.822625] localhost-live systemd[1477]: dev-zram0.device:
> Installed new job dev-zram0.device/nop as 377
> [  209.822757] localhost-live systemd[1477]: Added job
> sys-devices-virtual-block-zram0.device/nop to transaction.
> [  209.822861] localhost-live systemd[1477]:
> sys-devices-virtual-block-zram0.device: Installed new job
> sys-devices-virtual-block-zram0.device/nop as 378
> [  209.822983] localhost-live systemd[1477]:
> sys-devices-virtual-block-zram0.device: Job 378
> sys-devices-virtual-block-zram0.device/nop finished, result=done
> [  209.823106] localhost-live systemd[1477]: dev-zram0.device: Job 377
> dev-zram0.device/nop finished, result=done
> [  213.866820] localhost-live anaconda[2490]: blivet:
> DeviceTree.get_device_by_path: path: /dev/zram0 ; incomplete: False ;
> hidden: False ;
> [  213.868392] localhost-live anaconda[2490]: blivet: failed to
> resolve '/dev/zram0'
> [root at localhost-live liveuser]#
>
>
> Literally zero of those lines appear in kmsg
>
> 6,20619,201107529,-;zram: Cannot change disksize for initialized device
> 12,23154,208596765,-;org.fedoraproject.Anaconda.Modules.Network[2498]:
> DEBUG:anaconda.modules.network.network:Applying boot options
> KernelArguments([('BOOT_IMAGE', '/images/pxeboot/vmlinuz'), ('root',
> 'live:CDLABEL=Fedora-WS-Live-rawh-20190728-n-1'), ('rd.live.image',
> None), ('systemd.wants', 'zram-swap.service'), ('systemd.log_level',
> 'debug'), ('systemd.journald.forward_to_kmsg', None), ('log_buf_len',
> '8M'), ('printk.devkmsg', 'on')])
> 12,25049,210822858,-;org.fedoraproject.Anaconda.Modules.Storage[2498]:
> DEBUG:anaconda.modules.storage.disk_selection.selection:Protected
> devices are set to '['/dev/zram0']'.
>
> The first is a kernel message, the next two are anaconda messages that
> don't appear in the journal, where the two anaconda-blivet messages in
> the journal do not appear in kmsg. But none of the systemd messages in
> the journal appear in kmsg. It's like they each are missing some of
> what appears in the other.
>
> Between this behavior, and the journals being deleted on Lives bug,
> I'm totally stuck being unable to introspect early boot problems, or
> even confirm working things are working as intended and in the proper
> order.
> https://bugzilla.redhat.com/show_bug.cgi?id=1715699
>
> One of these has to give.
>
> ---
> Chris Murphy

I do not mean to sound like an ass here - especially since you have spent
hours of time ripping this stuff apart on Fedora live media (I actually
thought initially since you were digging so deep, you worked there), but I
mean really - what is the point?

Are you planning on using a Fedora Live Media image as production?  If so,
you clearly have not encountered all the stuff that usually does not work
on live media and should create your own anyhow.

I apologize, but I just do not get the effort spent here by anyone.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.freedesktop.org/archives/systemd-devel/attachments/20190731/c76ea06d/attachment-0001.html>