Re: [systemd-devel] odd seek_tail behaviour

2014-10-24 Thread Sascha Kattelmann 
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

2014-10-14 Thread Christian Hesse 
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

2014-10-13 Thread Daurnimator 
 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

2014-10-13 Thread Christian Hesse 
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

2014-10-13 Thread Christian Hesse 
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

[systemd-devel] odd seek_tail behaviour

2014-10-12 Thread Daurnimator 
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