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"
To: "systemd Mailing List"
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
#include
#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; i<10; 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 on Mon, 2014/10/13 23:56:
> Christian Hesse on Mon, 2014/10/13 20:22:
> > Daurnimator 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
Christian Hesse on Mon, 2014/10/13 20:22:
> Daurnimator 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
Re: [systemd-devel] odd seek_tail behaviour
Daurnimator 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
On 13 October 2014 07:22, Sascha Kattelmann 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
[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
#include
#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; i<10; 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
