I'm having trouble with systemd journal cursors.
If I SeekTail(), I get a value for the cursor and can keep calling Next() and it behaves exactly as expected.
However, if I SeekCursor() and then call Next() entry it jumps back to the Head() and starts reading over again. Why would it do that? I can verify that it did locate the cursor correctly. But it's as though SeekCursor only worked for the specific item and thats all. This is not what I would expect reading the man pages and other documentation.
I'm using go-systemd from the CoreOS project which is a simple wrapper for the systemd C-API.
But the go wrapper is not the issue, the C library is. I can see that journalctl is doing the same thing on Ubuntu.
e.g. append to journal, show tail output, get full entry detail in json. Jump to cursor and show tail
matthewh@xen:~$ echo "Cursor example" | systemd-cat
matthewh@xen:~$ journalctl -f
-- Logs begin at Mon 2017-07-03 08:56:12 NZST. --
May 31 17:50:31 xen code.desktop[6771]: [main 17:50:31] update#setState idle
May 31 17:55:01 xen CRON[4468]: pam_unix(cron:session): session opened for user root by (uid=0)
May 31 17:55:01 xen CRON[4469]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
May 31 17:55:01 xen CRON[4468]: pam_unix(cron:session): session closed for user root
May 31 17:55:03 xen smokeping[2839]: RRDs::update ERROR: /var/lib/smokeping/Local/LocalMachine.rrd: illegal attempt to update using time 1527746103 when last update time is 4073847643 (minimum one second step)
May 31 17:55:22 xen cat[4479]: Hello
May 31 17:59:28 xen cat[4539]: Cursor example
May 31 18:00:03 xen smokeping[2839]: RRDs::update ERROR: /var/lib/smokeping/Local/LocalMachine.rrd: illegal attempt to update using time 1527746403 when last update time is 4073847643 (minimum one second step)
May 31 18:00:06 xen cat[4547]: Cursor example
May 31 18:01:09 xen cat[4597]: Cursor example
^C
matthewh@xen:~$ journalctl -f -o json-pretty -n1
{
"__CURSOR" : "s=b7f2a0f19c9946abab26788729a244c5;i=52a5;b=1ba1d5cabb5840adb02eedc4aba5b4d6;m=2d96b77f94;t=56d7a319ee462;x=8afac4ada39ae1fb",
"__REALTIME_TIMESTAMP" : "1527746469487714",
"__MONOTONIC_TIMESTAMP" : "195802136468",
"_BOOT_ID" : "1ba1d5cabb5840adb02eedc4aba5b4d6",
"_UID" : "1000",
"_GID" : "1000",
"_CAP_EFFECTIVE" : "0",
"_MACHINE_ID" : "f899a862e4aa4775b8995564d8da565d",
"_HOSTNAME" : "xen",
"_TRANSPORT" : "stdout",
"PRIORITY" : "6",
"_COMM" : "cat",
"MESSAGE" : "Cursor example",
"_STREAM_ID" : "d1fbcc3ff027401e9dc95b5648f9322e",
"_PID" : "4597"
}
^C
matthewh@xen:~$ journalctl -f --cursor="s=b7f2a0f19c9946abab26788729a244c5;i=52a5;b=1ba1d5cabb5840adb02eedc4aba5b4d6;m=2d96b77f94;t=56d7a319ee462;x=8afac4ada39ae1fb"
-- Logs begin at Mon 2017-07-03 08:56:12 NZST. --
May 31 18:01:09 xen cat[4597]: Cursor example
-- Reboot --
Feb 04 13:03:03 xen systemd-journald[420]: Runtime journal (/run/log/journal/) is 8.0M, max 241.0M, 233.0M free.
Feb 04 13:03:03 xen kernel: Initializing cgroup subsys cpuset
Feb 04 13:03:03 xen kernel: Initializing cgroup subsys cpu
Feb 04 13:03:03 xen kernel: Initializing cgroup subsys cpuacct
Feb 04 13:03:03 xen kernel: Linux version 4.4.0-116-generic (buildd@lgw01-amd64-021) (gcc version 5.4.0 20160609 (Ubuntu 5.4.0-6ubuntu1~16.04.9) ) #140-Ubuntu SMP Mon Feb 12 21:23:04 UTC 2018 (Ubuntu 4.4.0-116.140-generic 4.4.98)
Feb 04 13:03:03 xen kernel: Command line: BOOT_IMAGE=/boot/vmlinuz-4.4.0-116-generic root=UUID=f95a581f-2afb-4428-bade-c913f1c51741 ro quiet splash vt.handoff=7
Feb 04 13:03:03 xen kernel: KERNEL supported cpus:
Feb 04 13:03:03 xen kernel: Intel GenuineIntel
Feb 04 13:03:03 xen kernel: AMD AuthenticAMD
^C
Note the "--reboot--" text and the fact that it jumped back several days in the past. But prior to that, it located my entry via systemd-cat so it was found.
What am I doing wrong? is it a bug or an oversight on my part?
Oddly enough, I have a CoreOS server I was able to test this on and it behaves differently. It behaves as expected. The version of journalctl is the same on both. All the configuration is untouched stock standard.