Re: [systemd-devel] odd seek_tail behaviour
Hi, here is a related bug report: https://bugs.freedesktop.org/show_bug.cgi?id=64614 Doing a next after seek_tail ends up in some unexpected behaviour. Just do a previous after seeking the tail and everything works fine. The problem is symmetrical: Same goes for previous after seek_head. You need to do a next immediately after seek_head. I hope that will help, Sascha - Original Message - From: Daurnimator q...@daurnimator.com To: systemd Mailing List systemd-devel@lists.freedesktop.org Sent: Monday, October 13, 2014 7:27:22 AM Subject: [systemd-devel] odd seek_tail behaviour Hi All, I was trying to write a program that tailed the journal, but found that sd_journal_seek_tail() didn't work as expected. That is: that it would seek to the last/most recent thing in the journal, and I could tail things from there. I whipped up a quick demonstration program, that shows that messages I 'next' through, are before the 'cutoff': #include stdio.h #include assert.h #include systemd/sd-journal.h int main() { sd_journal* j; assert(sd_journal_open(j, 0)==0); uint64_t from, to; assert(sd_journal_get_cutoff_realtime_usec(j, from, to)==1); printf(CUTOFF = %llu\n, to); printf(TAIL = %d\n, sd_journal_seek_tail(j)); for (int i=0; i10; i++) { printf(NEXT = %lld\n, sd_journal_next(j)); assert(sd_journal_get_realtime_usec(j, from)==0); printf(FOUND from %llu\n, from); } return 0; } Compiled with: gcc -std=c99 tail_logs.c -l systemd Example output: CUTOFF = 1413177397982789 TAIL = 0 NEXT = 1 FOUND from 1400437372012374 NEXT = 1 FOUND from 1400438753925868 NEXT = 1 FOUND from 1400438753926192 NEXT = 1 FOUND from 1400438753926257 NEXT = 1 FOUND from 1400438753926289 NEXT = 1 FOUND from 1400438753926309 NEXT = 1 FOUND from 1400438753926330 NEXT = 1 FOUND from 1400438753926353 NEXT = 1 FOUND from 1400438753926373 NEXT = 1 FOUND from 1400438753926395 Is this behaviour expected? I'm using systemd 216. Regards, Daurn. ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] odd seek_tail behaviour
Christian Hesse l...@eworm.de on Mon, 2014/10/13 23:56: Christian Hesse l...@eworm.de on Mon, 2014/10/13 20:22: Daurnimator q...@daurnimator.com on Mon, 2014/10/13 01:27: Hi All, I was trying to write a program that tailed the journal, but found that sd_journal_seek_tail() didn't work as expected. That is: that it would seek to the last/most recent thing in the journal, and I could tail things from there. I whipped up a quick demonstration program, that shows that messages I 'next' through, are before the 'cutoff': [code and output] Is this behaviour expected? I'm using systemd 216. I do see a similar problem in my code [0]. I do call sd_journal_previous() after sd_journal_seek_tail(), but I still do see some older message come up. sd_journal_next() is the first I call in while loop. Perhaps even this is a problem? [0] https://github.com/eworm-de/journal-notify/blob/master/journal-notify.c Looks like I was right. For any reason sd_journal_next() can jump to old journal entries (even if sd_journal_previous() has been called before). That happens before sd_journal_wait() is called the first time. Sadly I do not know how to reproduce. It happens very seldom and I could not find the culprit so far. Actually the problem happens before. I have an old entry selected after calling sd_journal_previous(). Mhh, does adding matches (sd_journal_add_match(), sd_journal_add_conjunction() and sd_journal_add_disjunction()) have an effect to sd_journal_seek_tail() and sd_journal_previous()? Looks like the problem goes away if I seek to tail first, then add my matches. -- main(a){char*c=/*Schoene Gruesse */B?IJj;MEH CX:;,b;for(a/*Chris get my mail address:*/=0;b=c[a++];) putchar(b-1/(/* gcc -o sig sig.c ./sig*/b/42*2-3)*42);} signature.asc Description: PGP signature ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] odd seek_tail behaviour
On 13 October 2014 07:22, Sascha Kattelmann skattelm...@tpip.net wrote: here is a related bug report: https://bugs.freedesktop.org/show_bug.cgi?id=64614 sd_journal_next() is documented as returning '0' if there are no more entries available after the current position. So this sounds like a bug to me. Doing a next after seek_tail ends up in some unexpected behaviour. Just do a previous after seeking the tail and everything works fine. The problem is symmetrical: Same goes for previous after seek_head. You need to do a next immediately after seek_head. If this is the API contract; why not perform next's functionality inside of seek_head? Thanks for the work around. I just commited an example script: https://github.com/daurnimator/lua-systemd/blob/master/examples/tail_logs.lua ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] odd seek_tail behaviour
Daurnimator q...@daurnimator.com on Mon, 2014/10/13 01:27: Hi All, I was trying to write a program that tailed the journal, but found that sd_journal_seek_tail() didn't work as expected. That is: that it would seek to the last/most recent thing in the journal, and I could tail things from there. I whipped up a quick demonstration program, that shows that messages I 'next' through, are before the 'cutoff': [code and output] Is this behaviour expected? I'm using systemd 216. I do see a similar problem in my code [0]. I do call sd_journal_previous() after sd_journal_seek_tail(), but I still do see some older message come up. sd_journal_next() is the first I call in while loop. Perhaps even this is a problem? [0] https://github.com/eworm-de/journal-notify/blob/master/journal-notify.c -- main(a){char*c=/*Schoene Gruesse */B?IJj;MEH CX:;,b;for(a/*Chris get my mail address:*/=0;b=c[a++];) putchar(b-1/(/* gcc -o sig sig.c ./sig*/b/42*2-3)*42);} signature.asc Description: PGP signature ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel
Re: [systemd-devel] odd seek_tail behaviour
Christian Hesse l...@eworm.de on Mon, 2014/10/13 20:22: Daurnimator q...@daurnimator.com on Mon, 2014/10/13 01:27: Hi All, I was trying to write a program that tailed the journal, but found that sd_journal_seek_tail() didn't work as expected. That is: that it would seek to the last/most recent thing in the journal, and I could tail things from there. I whipped up a quick demonstration program, that shows that messages I 'next' through, are before the 'cutoff': [code and output] Is this behaviour expected? I'm using systemd 216. I do see a similar problem in my code [0]. I do call sd_journal_previous() after sd_journal_seek_tail(), but I still do see some older message come up. sd_journal_next() is the first I call in while loop. Perhaps even this is a problem? [0] https://github.com/eworm-de/journal-notify/blob/master/journal-notify.c Looks like I was right. For any reason sd_journal_next() can jump to old journal entries (even if sd_journal_previous() has been called before). That happens before sd_journal_wait() is called the first time. Sadly I do not know how to reproduce. It happens very seldom and I could not find the culprit so far. -- main(a){char*c=/*Schoene Gruesse */B?IJj;MEH CX:;,b;for(a/*Chris get my mail address:*/=0;b=c[a++];) putchar(b-1/(/* gcc -o sig sig.c ./sig*/b/42*2-3)*42);} signature.asc Description: PGP signature ___ systemd-devel mailing list systemd-devel@lists.freedesktop.org http://lists.freedesktop.org/mailman/listinfo/systemd-devel