I have been taking a look at the fifolog(1) system in RELENG_7 and I must be missing something obvious. I created a file using default params e.g fifolog_create /var/log/all.fifo and then in /etc/syslog.conf I have *.* /var/log/all.log *.* | /usr/sbin/fifolog_writer /var/log/all.fifo It seems to work for the most part, but there are entries that are missing throughout the log e.g. in the traditional all.log I have # wc all.log 4833 55212 398099 all.log yet the fifo log file I have # fifolog_reader all.fifo | wc>From 0 Wed Dec 31 19:00:00 1969To 1225722724 Mon Nov 3 09:32:04 2008 Read from 0 223 2783 23271 There does not seem to be any pattern as to what it discards / keeps ---Mike -------------------------------------------------------------------- Mike Tancsa, tel +1 519 651 3400 Sentex Communications, mike@sentex.net Providing Internet since 1994 www.sentex.net Cambridge, Ontario Canada www.sentex.net/mike
At 10:28 AM 11/3/2008, Poul-Henning Kamp wrote:>In message <200811031448.mA3Em2Ow024387@lava.sentex.ca>, Mike Tancsa writes: > >I have been taking a look at the fifolog(1) system in RELENG_7 and I > >must be missing something obvious. I created a file using default params > >e.g > > > >fifolog_create /var/log/all.fifo > >and then in /etc/syslog.conf I have > >*.* /var/log/all.log > >*.* | /usr/sbin/fifolog_writer /var/log/all.fifo > > > >It seems to work for the most part, but there are entries that are > >missing throughout the log > > > >e.g. in the traditional all.log I have > ># wc all.log > > 4833 55212 398099 all.log > > > >yet the fifo log file I have > > > ># fifolog_reader all.fifo | wc > >>From 0 Wed Dec 31 19:00:00 1969 > >To 1225722724 Mon Nov 3 09:32:04 2008 > >Read from 0 > > 223 2783 23271 > > > >There does not seem to be any pattern as to what it discards / keeps > >Try using "cat" instead of fifolog_writer, so we can tell on which >side of the pipe we are looking for the trouble ?Hi, Seems to work fine with cat *.* /var/log/all.log *.* | /usr/sbin/fifolog_writer /var/log/all.fifo *.* | cat > /var/log/all.cat ---Mike>-- >Poul-Henning Kamp | UNIX since Zilog Zeus 3.20 >phk@FreeBSD.ORG | TCP/IP since RFC 956 >FreeBSD committer | BSD since 4.3-tahoe >Never attribute to malice what can adequately be explained by incompetence.
In message <200811031448.mA3Em2Ow024387@lava.sentex.ca>, Mike Tancsa writes:>I have been taking a look at the fifolog(1) system in RELENG_7 and I >must be missing something obvious. I created a file using default params >e.g > >fifolog_create /var/log/all.fifo >and then in /etc/syslog.conf I have >*.* /var/log/all.log >*.* | /usr/sbin/fifolog_writer /var/log/all.fifo > >It seems to work for the most part, but there are entries that are >missing throughout the log > >e.g. in the traditional all.log I have ># wc all.log > 4833 55212 398099 all.log > >yet the fifo log file I have > ># fifolog_reader all.fifo | wc >>From 0 Wed Dec 31 19:00:00 1969 >To 1225722724 Mon Nov 3 09:32:04 2008 >Read from 0 > 223 2783 23271 > >There does not seem to be any pattern as to what it discards / keepsTry using "cat" instead of fifolog_writer, so we can tell on which side of the pipe we are looking for the trouble ? -- Poul-Henning Kamp | UNIX since Zilog Zeus 3.20 phk@FreeBSD.ORG | TCP/IP since RFC 956 FreeBSD committer | BSD since 4.3-tahoe Never attribute to malice what can adequately be explained by incompetence.
In message <200811031547.mA3FlVVs024666@lava.sentex.ca>, Mike Tancsa writes:>Seems to work fine with catOk, and the loss is not from one end, it is random records in the middle ? -- Poul-Henning Kamp | UNIX since Zilog Zeus 3.20 phk@FreeBSD.ORG | TCP/IP since RFC 956 FreeBSD committer | BSD since 4.3-tahoe Never attribute to malice what can adequately be explained by incompetence.
At 11:34 AM 11/3/2008, Poul-Henning Kamp wrote:>In message <200811031547.mA3FlVVs024666@lava.sentex.ca>, Mike Tancsa writes: > > >Seems to work fine with cat > >Ok, and the loss is not from one end, it is random records in >the middle ?Yes, they seem to initially get written and then tail off for some reason. I am not sure why. Actually, if I SIGHUP syslogd, it seems to make a difference, in that I can generally see when newsyslog sig HUPs syslog to do log rotation. Perhaps this is confusing things ? e.g. 1225628270 Nov 2 07:17:50 st32278 ovpn-kit[1047]: Initialization Sequence Completed 1225641602 Nov 2 11:00:02 st32278 syslogd: restart 1225641608 Nov 2 11:00:08 st32278 ppp[927]: tun0: Chat: deflink: Redial timer expired. In this snippet the last entry was 07:17 for some reason and then the SIGHUP from newsyslog seems to wake things up for some reason. ---Mike>-- >Poul-Henning Kamp | UNIX since Zilog Zeus 3.20 >phk@FreeBSD.ORG | TCP/IP since RFC 956 >FreeBSD committer | BSD since 4.3-tahoe >Never attribute to malice what can adequately be explained by incompetence.
At 11:48 AM 11/3/2008, Mike Tancsa wrote:>At 11:34 AM 11/3/2008, Poul-Henning Kamp wrote: >>In message <200811031547.mA3FlVVs024666@lava.sentex.ca>, Mike Tancsa writes: >> >> >Seems to work fine with cat >> >>Ok, and the loss is not from one end, it is random records in >>the middle ? > > >Yes, they seem to initially get written and then tail off for some >reason. I am not sure why. Actually, if I SIGHUP syslogd, it seems >to make a difference, in that I can generally see when newsyslog sig >HUPs syslog to do log rotation. Perhaps this is confusing things ?I tried changing the config so that there is only the fifo log being written to and disabled newsyslog so that syslogd is not getting a HUP signal. The strange thing is that reading from it gives different results?!? Sometimes doing [ps0278]# fifolog_reader all.fifo | wc>From 0 Wed Dec 31 19:00:00 1969To 1225760679 Mon Nov 3 20:04:39 2008 Read from 1d800 59 413 3068 0[ps0278]# and a exactly for 1min it will show the correct results 0[ps0278]# fifolog_reader all.fifo | wc>From 0 Wed Dec 31 19:00:00 1969To 1225760538 Mon Nov 3 20:02:18 2008 Read from 0 10765 75995 556816 0[ps0278]# and then go back to showing just a subset for 4 min. I am guessing this coincides with when the flush runs This is a nanobsd image, so /var on /dev/md1 and RELENG_7 from a few days ago I have been running #!/bin/sh i=0 while true do i=`expr $i + 1` logger $i echo $i sleep 1 done and they seem to be there when it shows all the results, but for the most part it just shows a subset ---Mike
In message <200811040143.mA41hjaa029665@lava.sentex.ca>, Mike Tancsa writes:>I tried changing the config so that there is only the fifo log being >written to and disabled newsyslog so that syslogd is not getting a >HUP signal. The strange thing is that reading from it gives >different results?!? > >Sometimes doing >[ps0278]# fifolog_reader all.fifo | wc >>From 0 Wed Dec 31 19:00:00 1969 >To 1225760679 Mon Nov 3 20:04:39 2008 >Read from 1d800 > 59 413 3068 >0[ps0278]# > >and a exactly for 1min it will show the correct results > >0[ps0278]# fifolog_reader all.fifo | wc >>From 0 Wed Dec 31 19:00:00 1969 >To 1225760538 Mon Nov 3 20:02:18 2008 >Read from 0 > 10765 75995 556816 >0[ps0278]#I could fear that you have two fifologs running at the same time, possibly as a result of syslogd doing something strange on sighup... -- Poul-Henning Kamp | UNIX since Zilog Zeus 3.20 phk@FreeBSD.ORG | TCP/IP since RFC 956 FreeBSD committer | BSD since 4.3-tahoe Never attribute to malice what can adequately be explained by incompetence.
At 02:16 AM 11/10/2008, Poul-Henning Kamp wrote:>In message <200811040143.mA41hjaa029665@lava.sentex.ca>, Mike Tancsa writes: > > >I tried changing the config so that there is only the fifo log being > >written to and disabled newsyslog so that syslogd is not getting a > >HUP signal. The strange thing is that reading from it gives > >different results?!? > > > >Sometimes doing > >[ps0278]# fifolog_reader all.fifo | wc > >>From 0 Wed Dec 31 19:00:00 1969 > >To 1225760679 Mon Nov 3 20:04:39 2008 > >Read from 1d800 > > 59 413 3068 > >0[ps0278]# > > > >and a exactly for 1min it will show the correct results > > > >0[ps0278]# fifolog_reader all.fifo | wc > >>From 0 Wed Dec 31 19:00:00 1969 > >To 1225760538 Mon Nov 3 20:02:18 2008 > >Read from 0 > > 10765 75995 556816 > >0[ps0278]# > >I could fear that you have two fifologs running at the same time, >possibly as a result of syslogd doing something strange on sighup...There is nothing really strange about the config. Any idea on how to resolve? ---Mike
In message <200811170603.mAH63Q54011870@lava.sentex.ca>, Mike Tancsa writes:>>I could fear that you have two fifologs running at the same time, >>possibly as a result of syslogd doing something strange on sighup... > >There is nothing really strange about the config. Any idea on how to resolve?Not right now, there is nothing that rings a bell here and I have not seen it on any of my systems. As I said, I would fear that the SIGHUB to syslog results in some weird config where two writers are competing or something like that but that is purely a guess... -- Poul-Henning Kamp | UNIX since Zilog Zeus 3.20 phk@FreeBSD.ORG | TCP/IP since RFC 956 FreeBSD committer | BSD since 4.3-tahoe Never attribute to malice what can adequately be explained by incompetence.