On Sun, 6 Oct 2024, at 20:05, Otto Moerbeek wrote: > On Sun, Oct 06, 2024 at 05:18:18PM +0200, Otto Moerbeek wrote: > >> On Sun, Oct 06, 2024 at 04:35:52PM +0200, Thomas wrote: >> >> > Hello everyone, >> > >> > I may have run into a corner case with newsyslog. Long story short, I set >> > up >> > a second pflog interface to capture all traffic coming to/from my phone to >> > investigate an issue. >> > >> > I want to keep 1-2 days of log. I have set-up /etc/newsyslog.conf as such: >> > /var/log/pflog1 600 24 * 2 ZB "rcctl reload pflogd1" >> > >> > When I put my phone in offline mode at night, there's no traffic, so the >> > only >> > mtime of the rotated files is its creation time. stat -f '%Sm%t%z%t%N' >> > gives: >> > >> > Oct 6 06:00:33 2024 44 pflog1.2.gz >> > Oct 6 05:00:33 2024 44 pflog1.3.gz >> > Oct 6 04:00:33 2024 44 pflog1.4.gz >> > Oct 6 03:00:34 2024 44 pflog1.5.gz >> > Oct 6 02:00:33 2024 44 pflog1.6.gz >> > >> > I had included newsyslog -v in cron and the logs sent by cron are: >> > Date: Sun, 6 Oct 2024 02:00:02 +0200 (CEST) >> > /var/log/pflog1 <24ZB>: age (hr): 2 [2] --> trimming log.... >> > Date: Sun, 6 Oct 2024 03:00:03 +0200 (CEST) >> > /var/log/pflog1 <24ZB>: age (hr): 2 [2] --> trimming log.... >> > Date: Sun, 6 Oct 2024 04:00:02 +0200 (CEST) >> > /var/log/pflog1 <24ZB>: age (hr): 2 [2] --> trimming log.... >> > Date: Sun, 6 Oct 2024 05:00:02 +0200 (CEST) >> > /var/log/pflog1 <24ZB>: age (hr): 2 [2] --> trimming log.... >> > Date: Sun, 6 Oct 2024 06:00:02 +0200 (CEST) >> > /var/log/pflog1 <24ZB>: age (hr): 2 [2] --> trimming log.... >> > >> > So, it's always calculating 2 hours of duration (and trimming) although >> > it's only >> > been one hour. This issue does not happen during the day when the logs are >> > being filled with data. >> > >> > I'm no programmer, though looking through the source code of newsyslog >> > shows >> > this formula: return ((int)(timenow - sb.mt_time + 1800) / 3600 >> > >> > If mt_time is the modification time, my only explanation is newsyslog is >> > creating the file the same second, an hour later which would return 1.5: >> > >> > $ bc -e "scale = 3; ($(date -j +"%s" 0600.33) - $(date -j +"%s" 0500.33) + >> > 1800) / 3600" -e quit >> > $ 1.500 >> > >> > And that this is rounded up to 2 hrs and triggers newsyslog... I am not >> > sure >> > but cannot think of anything else >> >> That would suprise me, as the computation is done using integer >> arithmetic and no rounding up plays a role there. >> >> -Otto >> >> > >> > I think that I can work around this (and check the theory...) setting up >> > another >> > cron job to touch /var/log/pflog1 every hour so that the mtime of the >> > archive >> > cannot be exactly 5400 seconds later. >> > 59 * * * * /usr/bin/touch /var/log/pflog1 >> > >> > Greetings, >> > >> > Thomas >> > >> > > What is happening: the last mod time of the latest log file is > compared to the current time. In non B mode, a banner (logfile turned > over) is been written at rotation time, so that file always has time N > (rotation time). In B mode, that write does not happen, so if there > are also no log lines entries, written, it wil have time N-1 (in > hours). That's the reason why newsyslog thinks the current log file is > two hours old and it's time to rotate. > > -Otto
Thanks, that makes sense. The "fix" of adding an hourly cronjob to touch the log file shortly before it's rotated works the same and empty log files are now rotated every 2 hours. Greetings, Thomas
