Failure in logrotate installation function

Just to let you know ...

pihole -up
  [i] Checking for updates...
  [i] Pi-hole Core:     update available
  [i] Web Interface:    up to date
  [i] FTL:              up to date
 [✓] Installing latest Cron script

  [i] Installing latest logrotate script...
        [i] Existing logrotate file found. No changes made.
  [✗] Failure in logrotate installation function.
  [i] Backing up /etc/dnsmasq.conf to /etc/dnsmasq.conf.old
  [✓] man pages installed and database updated
  • 1st time pihole -up -> install stopped after [i] Restarting pihole-FTL service..., Unable to complete update, please contact Pi-hole Support, pihole -FTL stopped, sudo service pihole-FTL start -> OK
  • 2de time pihole -up -> logrotate installation error (see above), but install continues, -> result apparently OK
Update Complete!

  Current Pi-hole version is release/v5.4 v5.3.1-66-gac7e64c5
  Current AdminLTE version is release/v5.6 v5.5-46-g690feb8
  Current FTL version is release/v5.9 vDev-1b4fdd4

#2 is cosmetic only

Yeah, #2 is expected, it could be cleaned up a bit.

#1 is something new, might have been a transient glitch.

Side Note: Did you get the ping for talking about moving logrotate to a standard location instead of inside Pi-hole's folders? You were part of the group that helped get logrotate set up so we wanted to make sure you were part of the current discussion.

rechecked the log files, nothing special there that would indicate a problem...

no, but I read about it, a while ago. Curious what the result will be. There was a time where pihole install created /var/log/pihole (store logs in separate folder) but the folder was never used.

Those are the hardest ones to debug.

Micha pinged you on it. We would like to get your input on it, I'll link the issue here if you have a chance to add some comments.

Give pihole its own logrotate state file by duxovni · Pull Request #4225 · pi-hole/pi-hole (github.com)

same again today, output from sudo service pihole-FTL status (not stopped?):

● pihole-FTL.service - LSB: pihole-FTL daemon
   Loaded: loaded (/etc/init.d/pihole-FTL; generated)
   Active: failed (Result: exit-code) since Thu 2021-07-29 08:59:41 CEST; 30s ago
     Docs: man:systemd-sysv-generator(8)
  Process: 10968 ExecStart=/etc/init.d/pihole-FTL start (code=exited, status=1/FAILURE)

Jul 29 08:59:36 raspberrypi systemd[1]: Starting LSB: pihole-FTL daemon...
Jul 29 08:59:41 raspberrypi pihole-FTL[10968]: .....
Jul 29 08:59:41 raspberrypi pihole-FTL[10968]: Not stopped; may still be shutting down or shutdown may have failed, killing now
Jul 29 08:59:41 raspberrypi systemd[1]: pihole-FTL.service: Control process exited, code=exited, status=1/FAILURE
Jul 29 08:59:41 raspberrypi systemd[1]: pihole-FTL.service: Failed with result 'exit-code'.
Jul 29 08:59:41 raspberrypi systemd[1]: Failed to start LSB: pihole-FTL daemon.

What does the pihole-FTL.log file tell you at this point? Are the last messages a shutdown or is FTL just never terminated?

here is yesterdays log, it has some strange entries that I've never seen before, but might explain the long stop time

[2021-07-29 09:07:08.106 12593M] Shutting down...
[2021-07-29 09:07:11.284 12593M] Finished final database update
[2021-07-29 09:07:11.284 12593M] Waiting for threads to join
[2021-07-29 09:07:11.284 12593M] Thread telnet-IPv4 (0) is idle, terminating it.
[2021-07-29 09:07:11.285 12593M] Thread telnet-IPv6 (1) is idle, terminating it.
[2021-07-29 09:07:11.285 12593M] Thread telnet-socket (2) is idle, terminating it.
[2021-07-29 09:07:11.285 12593M] Thread database (3) is idle, terminating it.
[2021-07-29 09:07:11.286 12593M] Thread housekeeper (4) is idle, terminating it.
[2021-07-29 09:07:11.286 12593M] Thread DNS client (5) is idle, terminating it.
[2021-07-29 09:07:11.286 12593M] All threads joined
[2021-07-29 09:07:11.290 12593M] ########## FTL terminated after 2m 27s  (code 0)! ##########

pihole-FTL.log.zip (4.2 KB)

The lines are normal, they are there now so we could more easily troubleshoot if there are issues with zombie threads.

I don't think this is out of the ordinary:

Just means it took three seconds to write queries to the database. This seems acceptable given the limited speed of SD cards and an unknown number of queries saved.

But last log line says

FTL terminated after 2m 27s (code 0)!

This seems to contradict the timestamps, or are there logs before those posted, matching the 2:27 minutes?

That means that the daemon was running for 2:27, not that it took 2:27 to shut down things. Its the difference between startup and final shutdown.

1 Like

Ah of course that makers sense.