Re: [systemd-devel] Timestamps in journal during suspend/resume

2020-12-01 Thread Mantas Mikulėnas
On Tue, Dec 1, 2020 at 2:31 PM Mantas Mikulėnas  wrote:

> On Tue, Dec 1, 2020 at 1:46 PM Paul Menzel <
> pmenzel+systemd-de...@molgen.mpg.de> wrote:
>
>>
>> At least to me, some of the entries with timestamps from resuming should
>> have timestamps from suspending. Is the reason, that “suspend message“
>> was only written to the journal after resume?
>>
>
> Probably because the journald process (like all other userspace processes)
> had already been frozen when those messages were written to dmesg, so it
> couldn't really receive them.
>
>
>>
>> Is there a way to access the Linux kernel timestamp from within the
>> journal?
>>
>
> Yes, as the _SOURCE_MONOTONIC_TIMESTAMP field. (It's stored in
> microseconds, while dmesg shows it in seconds.)
>
> journalctl -o json _TRANSPORT=kernel | jq -r
> '"[\(._SOURCE_MONOTONIC_TIMESTAMP | tonumber / 100)] \(.MESSAGE)"'
>

(I forgot to include the SYSLOG_IDENTIFIER field in the output, but you get
the idea.)

-- 
Mantas Mikulėnas
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] Timestamps in journal during suspend/resume

2020-12-01 Thread Mantas Mikulėnas
On Tue, Dec 1, 2020 at 1:46 PM Paul Menzel <
pmenzel+systemd-de...@molgen.mpg.de> wrote:

>
> At least to me, some of the entries with timestamps from resuming should
> have timestamps from suspending. Is the reason, that “suspend message“
> was only written to the journal after resume?
>

Probably because the journald process (like all other userspace processes)
had already been frozen when those messages were written to dmesg, so it
couldn't really receive them.


>
> Is there a way to access the Linux kernel timestamp from within the
> journal?
>

Yes, as the _SOURCE_MONOTONIC_TIMESTAMP field. (It's stored in
microseconds, while dmesg shows it in seconds.)

journalctl -o json _TRANSPORT=kernel | jq -r
'"[\(._SOURCE_MONOTONIC_TIMESTAMP | tonumber / 100)] \(.MESSAGE)"'

Note that the kernel uses the monotonic clock for dmesg messages, which
does not advance at all while the system is suspended -- so trying to
convert it to realtime will often give wrong results (the same problem as
in 'dmesg -e') unless you do something smart with combining it with
journald's __REALTIME_TIMESTAMP.

-- 
Mantas Mikulėnas
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
https://lists.freedesktop.org/mailman/listinfo/systemd-devel