journalctl --follow

[Wolfgang S. Rupprecht]

Chris Murphy <lists at colorremedies.com> writes:
> On Mon, Feb 9, 2015 at 11:59 PM, Wolfgang S. Rupprecht
> <wolfgang.rupprecht at gmail.com> wrote:
>>
>> Is journalctl in the tail -f mode called "follow" supposed to be
>> realtime?  I'm seeing it more or less output log lines in realtime for
>> many hours and then eventually it falls behind with half an hour or one
>> hour delay.
> I haven't seen this. If you quit and then issue a new journalctl -f,
> do you see a bunch of things that previously weren't there with
> (approximately) current time? It might be a bug worth inquiring about
> on systemd-devel at .

I do see journalctl output the delayed lines when I run either
journalctl by itself or with "-f".

(with slight editing, just to toy with the script kiddies probing the
system. ;-))

# journalctl -o short-precise -u ssh-ban -u sshd --lines 73
...
Feb 10 09:30:12.267795 xxx.example.com sshd[10846]: Set /proc/self/oom_score_adj to 0
Feb 10 09:30:12.278631 xxx.example.com sshd[10846]: Connection from 104.236.247.20 port 59270 on 192.168.35.32 port 22
Feb 10 09:49:22.061551 xxx.example.com sshd[10952]: Set /proc/self/oom_score_adj to 0
Feb 10 09:49:22.069974 xxx.example.com sshd[10952]: Connection from 219.153.36.198 port 41053 on 192.168.35.32 port 22
Feb 10 09:55:47.553083 xxx.example.com sshd[10966]: Set /proc/self/oom_score_adj to 0
Feb 10 09:55:47.556836 xxx.example.com sshd[10966]: Connection from 103.41.124.32 port 51058 on 192.168.35.32 port 22
Feb 10 09:55:47.560852 xxx.example.com ssh-ban[764]: Connection 104.236.247.20 Count: 1
Feb 10 09:55:47.561618 xxx.example.com ssh-ban[764]: Connection 219.153.36.198 Count: 2
Feb 10 09:55:47.562250 xxx.example.com ssh-ban[764]: Connection 103.41.124.32 Count: 4
Feb 10 09:55:47.562861 xxx.example.com ssh-ban[764]: SSHBANNED: 103.41.124.32

My script will print significant events to its output which systemd
will then throw into the logs.  This lets me see the original sshd
printf timestamp and the time that my script (ssh-ban) saw it at.

In this case the first connection, from  104.236.247.20 was logged at
09:30:12.278631 but the script saw it at 09:55:47.560852 .  That's a
delay of 25 minutes.

Thanks for the tip on systemd-devel@ mailing list.

-wolfgang