[Solved] Sending SIGUSR1 to dnsmasq forces router to reboot (22.03.2)

[Barney]

I've installed OpenWrt 22.03.2 r19803-9a599fee93 on an Archer C2600.

When I send a SIGUSR1 to dnsmasq (2.86-14) the router reboots. Following is an extract from the logs:

Oct 27 17:05:12 user.notice root: send signal USR1 to dnsmasq
Oct 27 17:05:12 daemon.info procd: - shutdown -
Oct 27 17:05:12 daemon.err collectd[2686]: Exiting normally.
Oct 27 17:05:12 daemon.err collectd[2686]: collectd: Stopping 2 read threads.
Oct 27 17:05:12 daemon.err collectd[2686]: collectd: Stopping 5 write threads.
Oct 27 17:05:12 daemon.err collectd[2686]: rrdtool plugin: Shutting down the queue thread. This may take a while.
Oct 27 17:05:12 daemon.err hostapd: rmdir[ctrl_interface=/var/run/hostapd]: Permission denied
Connection to ipq.home.lan closed by remote host.
Connection to ipq.home.lan closed.

Extract from dnsmasq's man page:

When it receives a SIGUSR1, dnsmasq writes statistics to the system log.

So, rebooting is not the expected behaviour.

In OpenWRT 19.X and 21.02 dnsmasq behaves as described in the man page, but not in OpenWRT 22.03.2. Why?

My questions:

• Did anybody else observe this behaviour?
• If yes, is it OpenWRT specific or router specific?
• Any further information needed?

[hnyman]

@Barney

Oct 27 17:05:12 user.notice root: send signal USR1 to dnsmasq
Oct 27 17:05:12 daemon.info procd: - shutdown -

procd somehow interpreting that as shutdown sounds really strange

[hnyman]

How did you send the signal?

I used kill to send signal in master, and I only see the normal/expected stats output:

 -----------------------------------------------------
 OpenWrt SNAPSHOT, r21112-eb456aedfe
 -----------------------------------------------------

root@router1:/# ps | grep dns
 7139 root      2408 S    {dnsmasq} /sbin/ujail -t 5 -n dnsmasq -u -l -r /bin/
 7140 dnsmasq   4132 S    /usr/sbin/dnsmasq -C /var/etc/dnsmasq.conf.cfg01411c
20020 root      1148 S    grep dns
root@router1:/# kill -s USR1 7140
root@router1:/# ps | grep dns
 7139 root      2408 S    {dnsmasq} /sbin/ujail -t 5 -n dnsmasq -u -l -r /bin/
 7140 dnsmasq   4132 S    /usr/sbin/dnsmasq -C /var/etc/dnsmasq.conf.cfg01411c
20030 root      1148 S    grep dns
root@router1:/# kill -s USR1 7139
root@router1:/# ps | grep dns
 7139 root      2408 S    {dnsmasq} /sbin/ujail -t 5 -n dnsmasq -u -l -r /bin/
 7140 dnsmasq   4132 S    /usr/sbin/dnsmasq -C /var/etc/dnsmasq.conf.cfg01411c
20032 root      1148 S    grep dns

The log shows the expected stats:

root@router1:/# logread | tail -n 16
Fri Oct 28 18:27:27 2022 daemon.info dnsmasq[1]: time 1666970847
Fri Oct 28 18:27:27 2022 daemon.info dnsmasq[1]: cache size 1001, 0/9454 cache insertions re-used unexpired cache entries.
Fri Oct 28 18:27:27 2022 daemon.info dnsmasq[1]: queries forwarded 10801, queries answered locally 56334
Fri Oct 28 18:27:27 2022 daemon.info dnsmasq[1]: pool memory in use 0, max 0, allocated 0
Fri Oct 28 18:27:27 2022 daemon.info dnsmasq[1]: server 62.241.198.245#53: queries sent 4639, retried or failed 691
Fri Oct 28 18:27:27 2022 daemon.info dnsmasq[1]: server 62.241.198.246#53: queries sent 6194, retried or failed 59
Fri Oct 28 18:27:27 2022 daemon.info dnsmasq[1]: server 2001:14b8:1000::1#53: queries sent 1989, retried or failed 156
Fri Oct 28 18:27:27 2022 daemon.info dnsmasq[1]: server 2001:14b8:1000::2#53: queries sent 2266, retried or failed 12
Fri Oct 28 18:27:56 2022 daemon.info dnsmasq[1]: time 1666970876
Fri Oct 28 18:27:56 2022 daemon.info dnsmasq[1]: cache size 1001, 0/9454 cache insertions re-used unexpired cache entries.
Fri Oct 28 18:27:56 2022 daemon.info dnsmasq[1]: queries forwarded 10801, queries answered locally 56338
Fri Oct 28 18:27:56 2022 daemon.info dnsmasq[1]: pool memory in use 0, max 0, allocated 0
Fri Oct 28 18:27:56 2022 daemon.info dnsmasq[1]: server 62.241.198.245#53: queries sent 4639, retried or failed 691
Fri Oct 28 18:27:56 2022 daemon.info dnsmasq[1]: server 62.241.198.246#53: queries sent 6194, retried or failed 59
Fri Oct 28 18:27:56 2022 daemon.info dnsmasq[1]: server 2001:14b8:1000::1#53: queries sent 1989, retried or failed 156
Fri Oct 28 18:27:56 2022 daemon.info dnsmasq[1]: server 2001:14b8:1000::2#53: queries sent 2266, retried or failed 12

[Barney]

@hnyman

How did you send the signal?

With this little script:

#!/bin/sh

case "$(uname -n)" in
   H2O-AZURO|H2O-BLACK|H2O-PIANO|H2O-RPI4B|H2O-NANOP|H2O-ZEROP|H2O-ORION|H2O-IPQ80)
        PIDFILE='/var/run/dnsmasq/dnsmasq.cfg01411c.pid' ;;
   *)   PIDFILE='/tmp/notfound.pid' ;;
esac

if [ -r "$PIDFILE" ]
   then /usr/bin/logger "send signal USR1 to dnsmasq"
        /bin/kill -s USR1 "$(cat $PIDFILE)"
   else /usr/bin/logger "pidfile for dnsmasq does not exist: $PIDFILE"
fi

The difference between your way and my way is: you got the dnsmasq pid from the ps output, I got the dnsmasq pid from the file /var/run/dnsmasq/dnsmasq.cfg01411c.pid.

The file /var/run/dnsmasq/dnsmasq.cfg01411c.pid contained as pid the number 1 and not the real pid of the running dnsmasq process.

But why does dnsmasq write the number 1 in its pid file and not the real pid?

On the C2600 ps gives the following output:

3682 dnsmasq 1428 S /usr/sbin/dnsmasq -C /var/etc/dnsmasq.conf.cfg01411c -k -x /var/run/dnsmasq/dnsmasq.cfg01411c.pid`

With sending SIGUSR1 to dnsmasq with the pid from the ps output, I get the normal behaviour.

Strange, very strange.

[hnyman]

@Barney

Why does dnsmasq write the number 1 in its pid file and not the real pid?

Pure guess, but could it be due to the process being jailed?
Maybe it has no right to query for the correct number.

Ps.
No wonder that the router reboots nicely if you send the shutdown signal to the process manager itself

[hnyman]

See this

Ujail, process id's and scripting

I just recently upgraded to Openwrt 22.03.0-rc1 and noticed some of the processes such as dnsmasq, wpa_suppilicant, ntpd are using ujail wrapper. I have a script that will parse my custom dnsmasq log file specified by logfacility every 15 minutes, recreate the log file (to prevent it from growing) and send SIGUSR2 to dnsmasq. My script initially involved reading the ".pid" file generated by dnsmasq instance (you can have multiple instances of dnsmasq) and sending SIGUSR2 to that instance. This…

[Barney]

Very interesting link, thanks a lot.

As a result I think it's a matter of ujail and not of dnsmasq.

So pidof dnsmasq delivers 2 pids, the first is for the ujail process, the second for the dnsmasq process. Is this valid for every process started by ujail?

[hnyman]

See also this (apparently written some 20 hours ago)

/var/run/dnsmasq/dnsmasq.*.pid files are useless, possibly harmful

[Barney]

Another interesting link.

So, I'm not the only user having problems with ujailed processes.

If the pid files of ujailed processes are useless, then indeed we need another procedure for getting the pid of a ujailed process.

[sammo]

Try this
kill -s USR1 $(pgrep -n -f "dnsmasq.conf"|xargs)

[Barney]

Thanks for your reply. It really works, but

kill -s USR1 $(pgrep -n -x dnsmasq)

is sufficient.