Unbound frequent restarts

deHakkelaar · May 27, 2021, 6:55pm

Never mind.
Above message indicates something wrong with the power supplied to Pi:

Most likely this is the cause of the erratic behaviour your experiencing.
If you dont fix this, you'wont be able to run Pi-hole and/or unbound reliably!

Bucking_Horn · May 27, 2021, 7:18pm

Undoubtedly, it's eminently important to address that undervoltage issue.
EDIT:
It may also warrant a second look at:

Does it correlate with unbound restarting, though?
Also, there's no hint of relevant network changes this time (19:14), or is there?

jmccamb · May 27, 2021, 7:19pm

Leading up to the restart in journalctl

May 27 19:00:01 raspberrypi CRON[9678]: pam_unix(cron:session): session opened for user root by (uid=0)
May 27 19:00:01 raspberrypi CRON[9679]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
May 27 19:00:01 raspberrypi CRON[9678]: pam_unix(cron:session): session closed for user root
May 27 19:09:01 raspberrypi CRON[10347]: pam_unix(cron:session): session opened for user root by (uid=0)
May 27 19:09:01 raspberrypi CRON[10348]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib
May 27 19:09:01 raspberrypi CRON[10347]: pam_unix(cron:session): session closed for user root
May 27 19:09:01 raspberrypi systemd[1]: Starting Clean php session files...
May 27 19:09:02 raspberrypi systemd[1]: phpsessionclean.service: Succeeded.
May 27 19:09:02 raspberrypi systemd[1]: Started Clean php session files.
May 27 19:10:01 raspberrypi CRON[10457]: pam_unix(cron:session): session opened for user root by (uid=0)
May 27 19:10:01 raspberrypi CRON[10458]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
May 27 19:10:01 raspberrypi CRON[10457]: pam_unix(cron:session): session opened for user root by (uid=0)
May 27 19:10:01 raspberrypi CRON[10458]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
May 27 19:10:01 raspberrypi CRON[10457]: pam_unix(cron:session): session closed for user root
May 27 19:14:49 raspberrypi dhcpcd[462]: eth0: part of Router Advertisement expired
May 27 19:14:49 raspberrypi unbound[528]: [528:0] info: service stopped (unbound 1.9.0).
May 27 19:14:49 raspberrypi unbound[528]: [528:0] info: start of service (unbound 1.9.0).
May 27 19:14:49 raspberrypi unbound[528]: [528:0] info: service stopped (unbound 1.9.0).
May 27 19:14:49 raspberrypi unbound[528]: [528:0] info: start of service (unbound 1.9.0).

and another shortly after

May 27 20:00:01 raspberrypi CRON[14210]: pam_unix(cron:session): session opened for user root by (uid=0)
May 27 20:00:01 raspberrypi CRON[14211]: (root) CMD (   PATH="$PATH:/usr/sbin:/usr/local/bin/" pihole updatechecker local)
May 27 20:00:01 raspberrypi CRON[14210]: pam_unix(cron:session): session closed for user root
May 27 20:06:16 raspberrypi dhcpcd[462]: eth0: part of Router Advertisement expired
May 27 20:06:16 raspberrypi unbound[528]: [528:0] info: service stopped (unbound 1.9.0).
May 27 20:06:16 raspberrypi unbound[528]: [528:0] info: start of service (unbound 1.9.0).
May 27 20:06:16 raspberrypi unbound[528]: [528:0] info: service stopped (unbound 1.9.0).
May 27 20:06:16 raspberrypi unbound[528]: [528:0] info: start of service (unbound 1.9.0).

I feel like that power warning is right after a restart (approx 1 second after). Doesn't seem to exist other than immediately after booting

I will swap out the power supply just to be safe also.

deHakkelaar · May 27, 2021, 7:22pm

Filesystem could have been corrupted already ... who knows.
Its of no use diagnosing further if the power issue isnt fixed first.
Though below one would suggest that RA is related:

Unbound and PiHole bug?

May 27 19:14:49 raspberrypi dhcpcd[462]: eth0: part of Router Advertisement expired
May 27 19:14:49 raspberrypi unbound[528]: [528:0] info: service stopped (unbound 1.9.0).

deHakkelaar · May 27, 2021, 7:23pm

Keep an eye on below ones after swapped power:

And possibly you would need to run a fsck on the SD card partitions inserted into another Linux host to check file corruption and possibly fix.
EDIT: If you dont have those means, best would be to flash the SD fresh and start over to be safe (after you made sure those under voltage messages are gone).

jmccamb · May 27, 2021, 7:29pm

Okay, I will look into this. Thank you both so much for your help. i will report back later.

bigpcjunky · May 28, 2021, 1:24am

I'll go out on a limb and say it's related to running 2 piholes and 2 unbound servers. I'm sure there's a proper way to do it but I haven't seen it documented in detail. I was running the same setup and until I shutdown one of the pi's running the second pihole/unbound servers unbound seemed to be constantly restarting and I wasn't seeing the benefits of a caching DNS server.

Bucking_Horn · May 28, 2021, 11:15am

Development has confirmed Pi-hole isn't sending any signals, apart from those controlling its own processes - specifically, it is not signalling other processes.

They also pointed me to What's the easiest way to detect what signals are being sent, to get a hold on the process that does initiate unbound's restart.

Note that tracing may slow down unbound.

If you do not already have that, install strace by running:

sudo apt install strace

Then run the following command from a separate terminal on your Pi-hole host machine:

sudo strace -tt -ffo /tmp/trace-unbound -e trace=%signal -p "`pidof unbound`"

This will capture all signals (-e trace=%signal) for unbound's process (-p "(...)") and write them to a file /tmp/trace-unbound.<pid> (or multiple such files in case unbound should fork child processes (-ff)) preceeded by a microsecond precision timestamp (-tt).

Leave that terminal window open until you encounter unbound restarting again.
From another terminal, monitor your system for that event.

You should be able to cat or tail /tmp/trace-unbound to locate a line similar to

12:12:36.152169 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=12345, ...

where the number following si_pid is the process id of the process that sent the signal. Correlate timestamps with unbound's service stopped log message if required to identify the correct line.

You can terminate strace by pressing CtrlC in its respective terminal window.

ps -p 12345 will then reveal the name of the process, hopefully (provided that process is still running).

jmccamb · May 28, 2021, 12:16pm

Thank you so much for getting back to me!

The trace is now running on the pihole. I will post here when a restart happens.

One thing that I noticed is that I can't tail the trace file. I am guessing because there has been nothing written to the file so far?

pi@raspberrypi-2:/tmp $ ls
pulse-PKdhtXMmr18n
ssh-***
ssh-***
systemd-private-9ebb1a96c2f64113a3135af641e6ec16-rtkit-daemon.service-IJrVUU
systemd-private-9ebb1a96c2f64113a3135af641e6ec16-systemd-timedated.service-DGVLbm
systemd-private-9ebb1a96c2f64113a3135af641e6ec16-systemd-timesyncd.service-1tZiXu
trace-unbound.431
pi@raspberrypi-2:/tmp $ tail trace-unbound.431 
pi@raspberrypi-2:/tmp $

deHakkelaar · May 28, 2021, 12:34pm

screen is very well suited to leave something running in the background while you can disconnect from SSH:

pi@ph5b:~ $ sudo apt install screen
[..]
Processing triggers for systemd (241-7~deb10u7+rpi1) ...

pi@ph5b:~ $ screen
GNU Screen version 4.06.02 (GNU) 23-Oct-17
[..]
pi@ph5b:~ $

pi@ph5b:~ $ sudo strace -tt -ffo /tmp/trace-unbound -e trace=%signal -p "`pidof unbound`"
strace: Process 3091 attached

Now you can press CtrlA and the D key to detach and leave this screen session running:

[detached from 2446.pts-0.ph5b]
pi@ph5b:~ $

You can now disconnect from SSH while the strace is still running in the background.
If login again via SSH and list screen sessions:

pi@ph5b:~ $ screen -ls
There is a screen on:
        2446.pts-0.ph5b (28/05/21 14:22:45)     (Detached)
1 Socket in /run/screen/S-pi.

You can re-attach to the screen session again to checkup progress/status:

pi@ph5b:~ $ screen -r 2446.pts-0.ph5b

EDIT: Ow, DL6ER pointed out a more contemporary alternative for screen for your daily bread:

jmccamb · May 28, 2021, 1:12pm

I will be able to stay at my machine today so I can keep these open, but I will save this for the future in case I need to get up and leave. Thank you!

jmccamb · May 28, 2021, 1:13pm

Here are the first set of results from the strace:

07:21:29.579886 rt_sigaction(SIGQUIT, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
07:21:29.580168 rt_sigaction(SIGHUP, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
07:21:37.755317 rt_sigprocmask(SIG_UNBLOCK, [HUP], NULL, 8) = 0
07:21:37.755893 rt_sigprocmask(SIG_UNBLOCK, [INT], NULL, 8) = 0
07:21:37.756205 rt_sigprocmask(SIG_UNBLOCK, [QUIT], NULL, 8) = 0
07:21:37.756485 rt_sigprocmask(SIG_UNBLOCK, [TERM], NULL, 8) = 0
07:21:37.756791 rt_sigaction(SIGHUP, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:37.757328 rt_sigaction(SIGQUIT, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:37.757670 rt_sigaction(SIGTERM, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:37.757998 rt_sigaction(SIGINT, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0

@Bucking_Horn

Bucking_Horn · May 28, 2021, 1:22pm

Do you have a corresponding match for unbound[]: service stopped in your journalctl?

If so, then I'd expect a matching --- SIGHUP in your unbound-trace a few lines before the ones you've posted.

jmccamb · May 28, 2021, 1:26pm

Yeah, here is the journalctl output:

-- Logs begin at Sat 2021-05-22 01:21:25 CDT. --
May 28 02:09:48 raspberrypi-2 unbound[431]: [431:0] info: service stopped (unbound 1.9.0).
May 28 02:09:48 raspberrypi-2 unbound[431]: [431:0] info: start of service (unbound 1.9.0).
May 28 07:21:21 raspberrypi-2 unbound[431]: [431:0] info: service stopped (unbound 1.9.0).
May 28 07:21:29 raspberrypi-2 unbound[431]: [431:0] info: start of service (unbound 1.9.0).
May 28 07:21:29 raspberrypi-2 unbound[431]: [431:0] info: service stopped (unbound 1.9.0).
May 28 07:21:37 raspberrypi-2 unbound[431]: [431:0] info: start of service (unbound 1.9.0).
May 28 08:22:04 raspberrypi-2 unbound[431]: [431:0] info: service stopped (unbound 1.9.0).
May 28 08:22:12 raspberrypi-2 unbound[431]: [431:0] info: start of service (unbound 1.9.0).
May 28 08:22:13 raspberrypi-2 unbound[431]: [431:0] info: service stopped (unbound 1.9.0).
May 28 08:22:21 raspberrypi-2 unbound[431]: [431:0] info: start of service (unbound 1.9.0).

Another instance happened since my last message, but here is the entire log for the trace file:

07:21:21.689640 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=6620, si_uid=0} ---
07:21:21.694986 sigreturn({mask=[]})    = -1 EINTR (Interrupted system call)
07:21:21.700002 rt_sigaction(SIGTERM, {sa_handler=0x1a15c, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:21.700921 rt_sigaction(SIGQUIT, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:21.701576 rt_sigaction(SIGHUP, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:21.702174 rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:21.702753 rt_sigaction(SIGINT, {sa_handler=0x1a15c, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:21.722247 rt_sigaction(SIGINT, {sa_handler=0x1a15c, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
07:21:21.724598 rt_sigaction(SIGTERM, {sa_handler=0x1a15c, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
07:21:21.725114 rt_sigaction(SIGQUIT, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
07:21:21.725546 rt_sigaction(SIGHUP, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
07:21:21.932711 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=6671, si_uid=0} ---
07:21:21.933045 sigreturn({mask=[]})    = 431
07:21:29.535115 rt_sigprocmask(SIG_UNBLOCK, [HUP], NULL, 8) = 0
07:21:29.535666 rt_sigprocmask(SIG_UNBLOCK, [INT], NULL, 8) = 0
07:21:29.535972 rt_sigprocmask(SIG_UNBLOCK, [QUIT], NULL, 8) = 0
07:21:29.536252 rt_sigprocmask(SIG_UNBLOCK, [TERM], NULL, 8) = 0
07:21:29.536561 rt_sigaction(SIGHUP, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:29.537123 rt_sigaction(SIGQUIT, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:29.537475 rt_sigaction(SIGTERM, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:29.537806 rt_sigaction(SIGINT, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:29.564467 rt_sigaction(SIGTERM, {sa_handler=0x1a15c, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:29.565080 rt_sigaction(SIGQUIT, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:29.565433 rt_sigaction(SIGHUP, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:29.565842 rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:29.566154 rt_sigaction(SIGINT, {sa_handler=0x1a15c, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:29.578975 rt_sigaction(SIGINT, {sa_handler=0x1a15c, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
07:21:29.579568 rt_sigaction(SIGTERM, {sa_handler=0x1a15c, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
07:21:29.579886 rt_sigaction(SIGQUIT, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
07:21:29.580168 rt_sigaction(SIGHUP, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
07:21:37.755317 rt_sigprocmask(SIG_UNBLOCK, [HUP], NULL, 8) = 0
07:21:37.755893 rt_sigprocmask(SIG_UNBLOCK, [INT], NULL, 8) = 0
07:21:37.756205 rt_sigprocmask(SIG_UNBLOCK, [QUIT], NULL, 8) = 0
07:21:37.756485 rt_sigprocmask(SIG_UNBLOCK, [TERM], NULL, 8) = 0
07:21:37.756791 rt_sigaction(SIGHUP, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:37.757328 rt_sigaction(SIGQUIT, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:37.757670 rt_sigaction(SIGTERM, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
07:21:37.757998 rt_sigaction(SIGINT, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:04.892311 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=13881, si_uid=0} ---
08:22:04.892963 sigreturn({mask=[]})    = -1 EINTR (Interrupted system call)
08:22:04.900006 rt_sigaction(SIGTERM, {sa_handler=0x1a15c, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:04.900761 rt_sigaction(SIGQUIT, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:04.901318 rt_sigaction(SIGHUP, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:04.901818 rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:04.902289 rt_sigaction(SIGINT, {sa_handler=0x1a15c, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:04.922898 rt_sigaction(SIGINT, {sa_handler=0x1a15c, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
08:22:04.923599 rt_sigaction(SIGTERM, {sa_handler=0x1a15c, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
08:22:04.924081 rt_sigaction(SIGQUIT, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
08:22:04.924644 rt_sigaction(SIGHUP, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
08:22:05.137224 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=13932, si_uid=0} ---
08:22:05.137545 sigreturn({mask=[]})    = 431
08:22:12.975311 rt_sigprocmask(SIG_UNBLOCK, [HUP], NULL, 8) = 0
08:22:12.975850 rt_sigprocmask(SIG_UNBLOCK, [INT], NULL, 8) = 0
08:22:12.976154 rt_sigprocmask(SIG_UNBLOCK, [QUIT], NULL, 8) = 0
08:22:12.976423 rt_sigprocmask(SIG_UNBLOCK, [TERM], NULL, 8) = 0
08:22:12.976719 rt_sigaction(SIGHUP, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:12.977263 rt_sigaction(SIGQUIT, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:12.977671 rt_sigaction(SIGTERM, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:12.978024 rt_sigaction(SIGINT, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:13.008918 rt_sigaction(SIGTERM, {sa_handler=0x1a15c, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:13.009509 rt_sigaction(SIGQUIT, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:13.009909 rt_sigaction(SIGHUP, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:13.010274 rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:13.010589 rt_sigaction(SIGINT, {sa_handler=0x1a15c, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x76dc9d88, sa_mask=~[KILL STOP RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:13.024148 rt_sigaction(SIGINT, {sa_handler=0x1a15c, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
08:22:13.024769 rt_sigaction(SIGTERM, {sa_handler=0x1a15c, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
08:22:13.025090 rt_sigaction(SIGQUIT, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
08:22:13.025377 rt_sigaction(SIGHUP, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, NULL, 8) = 0
08:22:21.318199 rt_sigprocmask(SIG_UNBLOCK, [HUP], NULL, 8) = 0
08:22:21.318744 rt_sigprocmask(SIG_UNBLOCK, [INT], NULL, 8) = 0
08:22:21.319135 rt_sigprocmask(SIG_UNBLOCK, [QUIT], NULL, 8) = 0
08:22:21.319416 rt_sigprocmask(SIG_UNBLOCK, [TERM], NULL, 8) = 0
08:22:21.319712 rt_sigaction(SIGHUP, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[HUP], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:21.320238 rt_sigaction(SIGQUIT, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[QUIT], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:21.320662 rt_sigaction(SIGTERM, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[TERM], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, 8) = 0
08:22:21.320996 rt_sigaction(SIGINT, {sa_handler=0x76dc9d88, sa_mask=~[RTMIN RT_1], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x76556120}, {sa_handler=0x1a15c, sa_mask=[INT], sa_flags=SA_RESTORER|SA_RESTART,

Bucking_Horn · May 28, 2021, 1:27pm

Good.

Unbound and PiHole bug?

07:21:21.689640 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=6620, si_uid=0} ---
07:21:21.932711 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=6671, si_uid=0} ---
08:22:04.892311 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=13881, si_uid=0} ---
08:22:05.137224 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=13932, si_uid=0} ---

(edited to include all SIGHUP lines)

Now you'd have to lookup the process for that matching pid (or for all of them).

jmccamb · May 28, 2021, 1:35pm

I ran:

ps aux | grep 6620

pi       14927  0.0  0.0   7348   528 pts/0    S+   08:30   0:00 grep --color=auto 6620
pi       15325  0.0  0.0   7348   540 pts/0    S+   08:34   0:00 grep --color=auto 6671
pi       15442  0.0  0.0   7348   576 pts/0    S+   08:35   0:00 grep --color=auto 13881
pi       15257  0.0  0.0   7348   556 pts/0    S+   08:33   0:00 grep --color=auto 13932

It doesn't seem to be grabbing the correct column though, right? Seems like the number after pi would be the pid

When running top I can't see it there either

edit: I think this is referencing the command that I just ran ^

Bucking_Horn · May 28, 2021, 1:38pm

There's more than one SIGHUP in your log.
I've edited my previous post once I noticed that.
(You may have to hit refresh in your browser to see those recent changes.)

Yes, use ps -p <pid> instead.

jmccamb · May 28, 2021, 1:40pm

It looks like the process stopped:

ps -p 13932

  PID TTY          TIME CMD

I have another pihole instance on my network. Should I also run strace on that?

Bucking_Horn · May 28, 2021, 1:50pm

Bugger.
Is that true for all four of them?

You could try to monitor top output, but you'd have to be lucky to spot that process without prior knowledge of the pid.

jmccamb · May 28, 2021, 1:58pm

Yeah it is true for all of them. I am trying to figure out a way to batch process names into a text file. I will post more info if I am able to capture what process this is