kpv:

Here is the same output from a more recent LEDE x86 trunk build (same diffconfig) with ujail still running:

BusyBox v1.26.2 () built-in shell (ash)

 _________
/        /\      _    ___ ___  ___

kpv:

Same build, after reboot, no lingering ujail process and dnsmasq error.

Note: Behavior is inconsistent, changes from boot to boot.

BusyBox v1.26.2 () built-in shell (ash)

 _________
/        /\      _    ___ ___  ___

root@LEDE:# ps
PID USER VSZ STAT COMMAND
1 root 1024 S /sbin/procd
2 root 0 SW [kthreadd]
3 root 0 SW [ksoftirqd/0]
4 root 0 SW [kworker/0:0]
5 root 0 SW< [kworker/0:0H]
6 root 0 SW [kworker/u2:0]
7 root 0 SW [rcu_sched]
8 root 0 SW [rcu_bh]
9 root 0 SW [migration/0]
10 root 0 SW< [netns]
11 root 0 SW< [perf]
12 root 0 SW [kworker/u2:1]
13 root 0 SW< [writeback]
318 root 0 SW< [crypto]
319 root 0 SW< [bioset]
321 root 0 SW< [kblockd]
384 root 0 SW< [ata_sff]
496 root 0 SW [kworker/0:1]
509 root 0 SW [kswapd0]
510 root 0 SW< [vmstat]
580 root 0 SW [fsnotify_mark]
597 root 0 SW< [pencrypt]
599 root 0 SW< [pdecrypt]
619 root 0 SW< [acpi_thermal_pm]
657 root 0 SW< [bioset]
660 root 0 SW< [bioset]
663 root 0 SW< [bioset]
666 root 0 SW< [bioset]
669 root 0 SW< [bioset]
672 root 0 SW< [bioset]
675 root 0 SW< [bioset]
678 root 0 SW< [bioset]
692 root 0 SW [scsi_eh_0]
693 root 0 SW< [scsi_tmf_0]
696 root 0 SW [scsi_eh_1]
707 root 0 SW< [scsi_tmf_1]
710 root 0 SW [scsi_eh_2]
711 root 0 SW< [scsi_tmf_2]
714 root 0 SW< [kpsmoused]
771 root 0 SW< [ipv6_addrconf]
780 root 0 SW< [deferwq]
781 root 0 SW< [bioset]
785 root 0 SW< [bioset]
787 root 0 SW< [kworker/0:1H]
799 root 0 SW< [ext4-rsv-conver]
1052 root 776 S /sbin/ubusd
1059 root 968 S /bin/ash --login
1345 root 0 SW< [cfg80211]
1610 root 880 S /sbin/logd -S 64
1657 root 1172 S /sbin/netifd
1696 root 964 S /usr/sbin/odhcpd
1741 root 848 S /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300
1909 root 964 S udhcpc -p /var/run/udhcpc-eth1.pid -s /lib/netifd/dhcp.script -f -t 0 -i eth1 -C -O 121
1926 root 736 S odhcp6c -s /lib/netifd/dhcpv6.script -P0 -t120 eth1
2032 root 1588 S /usr/lib/ipsec/starter --daemon charon
2034 root 4120 S /usr/lib/ipsec/charon --use-syslog
2113 root 968 S < /usr/sbin/ntpd -n -N -S /usr/sbin/ntpd-hotplug -p 0.lede.pool.ntp.org -p 1.lede.pool.ntp.org -p 2.lede.pool.ntp.org -p 3.lede.pool.ntp.org
2410 root 968 S {mwan3track} /bin/sh /usr/sbin/mwan3track wan eth1 2 1 2 5 3 8 208.67.220.220 208.67.222.222 8.8.8.8 8.8.4.4
2650 dnsmasq 1024 S /usr/sbin/dnsmasq -C /var/etc/dnsmasq.conf.cfg02411c -k -x /var/run/dnsmasq/dnsmasq.cfg02411c.pid
3578 root 920 S /usr/sbin/dropbear -F -P /var/run/dropbear.1.pid -p 22 -K 300
3584 root 968 S -ash
3601 root 964 S sleep 5
3606 root 964 R ps
root@LEDE:# logread |fgrep dnsm
Sun Feb 5 00:47:38 2017 daemon.info dnsmasq[1]: started, version 2.76 cachesize 150
Sun Feb 5 00:47:38 2017 daemon.info dnsmasq[1]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP conntrack ipset no-auth no-DNSSEC no-ID loop-detect inotify
Sun Feb 5 00:47:38 2017 daemon.info dnsmasq[1]: DNS service limited to local subnets
Sun Feb 5 00:47:38 2017 daemon.info dnsmasq-dhcp[1]: DHCP, IP range 192.168.1.100 -- 192.168.1.249, lease time 12h
Sun Feb 5 00:47:38 2017 daemon.info dnsmasq[1]: using local addresses only for domain lan
Sun Feb 5 00:47:38 2017 daemon.info dnsmasq[1]: reading /tmp/resolv.conf.auto
Sun Feb 5 00:47:38 2017 daemon.info dnsmasq[1]: using local addresses only for domain lan
Sun Feb 5 00:47:38 2017 daemon.info dnsmasq[1]: using nameserver 10.0.3.1#53
Sun Feb 5 00:47:38 2017 daemon.info dnsmasq[1]: read /etc/hosts - 4 addresses
Sun Feb 5 00:47:38 2017 daemon.info dnsmasq[1]: read /tmp/hosts/dhcp.cfg02411c - 2 addresses
Sun Feb 5 00:47:38 2017 daemon.info dnsmasq-dhcp[1]: read /etc/ethers - 0 addresses
Sun Feb 5 00:48:13 2017 daemon.crit dnsmasq[1]: failed to bind DHCP server socket: Address in use
Sun Feb 5 00:48:13 2017 daemon.crit dnsmasq[1]: FAILED to start up
Sun Feb 5 00:48:18 2017 daemon.crit dnsmasq[1]: failed to bind DHCP server socket: Address in use
Sun Feb 5 00:48:18 2017 daemon.crit dnsmasq[1]: FAILED to start up
Sun Feb 5 00:48:23 2017 daemon.crit dnsmasq[1]: failed to bind DHCP server socket: Address in use
Sun Feb 5 00:48:23 2017 daemon.crit dnsmasq[1]: FAILED to start up
Sun Feb 5 00:48:28 2017 daemon.crit dnsmasq[1]: failed to bind DHCP server socket: Address in use
Sun Feb 5 00:48:28 2017 daemon.crit dnsmasq[1]: FAILED to start up
Sun Feb 5 00:48:33 2017 daemon.crit dnsmasq[1]: failed to bind DHCP server socket: Address in use
Sun Feb 5 00:48:33 2017 daemon.crit dnsmasq[1]: FAILED to start up
Sun Feb 5 00:48:33 2017 daemon.info procd: Instance dnsmasq::cfg02411c s in a crash loop 6 crashes, 0 seconds since last crash
root@LEDE:~#


champtar:

Hi @KpapaD

ujail uses Linux kernel namespaces to "jail" processes (like all container technologies (docker/lxc) and other jail project like firejail)
http://man7.org/linux/man-pages/man7/namespaces.7.html

In a new namespace with CLONE_NEWPID, the processes in this new namespace doesn't see processes in the parent namespace, and the PID numbers start at 1 again inside this new namespaces,
so it's totally normal that dnsmasq with ujail thinks he is PID 1 (because that's what he is inside the namespace / from his point of view)
and it's also normal that you don't see dnsmasq having PID 1 with ps, because you are looking from the parent namespace (different point of view).

Now for the implementation details, procd (Lede PID 1 / init / process manager) launch ujail, which takes care of setting up the namespaces, and then launch dnsmasq. So it's normal to have an ujail process for each "jailed" process.

What is happening I think, is that for some reason the ujail process is killed/die, but doesn't kill his children dnsmasq, so procd not seeing his children, try to restart, but dnsmasq is still running, so the new dnsmasq can't bind

You can try to play with strace to see exactly what is happening (if you can launch strace before the reboot loop)

strace -f -p 1 -p $(pgrep dnsmasq) -p $(pgrep ujail) -o /tmp/trace

Regards
Etienne

None:

I've been able to replicate this on an Archer C7 v2 MIPS box. It's "interesting" because dnsmasq is still running (minus its ujail 'minder' process) and able to service queries, but procd has a few attempts at restarting and then gives up...as the new dnsmasq is unable to bind the port.

dnsmasq startup is increasingly hairy these days because a) it doesn't actually try to start at boot. 2) it starts on interface hotplug events of which there are probably quite a few.

The other 'fun' aspect of this is that the 'dnsmasq without ujail minder' wasn't killed when I tried /etc/init.d/dnsmasq stop. I think that suggests procd has really lost track of it.

I suspect this is a race condition....which is going to be fun :-/

stintel:

Increased severity and priority. If dnsmasq doesn't work, a lot of people are going to be unhappy. While procd-ujail is not installed by default, it can be easily installed, resulting in broken connectivity if the LEDE device is your main router.

As this was working before, please try to bisect the problem. It's best to do this semi-manually, instead of letting git bisect decide what commit to try next, pick one from "git log --oneline package/system/procd/" by running "git checkout [shorthash]" after "git bisect good" or "git bisect bad".

For me this is a blocker for the 17.01 release. This needs to be fixed, or the commit that broke it has to be reverted.

dtaht:

A suggestion might be to try out the newfangled jailing facilities on daemons less system critical and complicated than dnsmasq, and try to work out some of the bugs separately that way. It might be nice to jail lots of things in the long term.

stintel:

It's not about trying out new facilities, it worked fine for over a year according to the reporter. We just need to test {better,more} before merging breaking changes.

None:

Can someone humour me and try this total hack job 'locking around dnsmasq startup' patch that I botched together last night.

I've an AP that doesn't need to run dnsmasq, so rc.local has
"
/etc/init.d/dnsmasq disable
/etc/init.d/dnsmasq stop
#sleep 110
#/etc/init.d/dnsmaq stop
"

Without the patch it's a lottery as to whether dnsmasq is left running or not which indicates race type issues (hence the now commented sleep & another stop). I'm wondering if race+jail+dnsmasq is an even worse combination :-)

Just tested it on a ujail capable box - no joy. But definitely dnsmasq's ujail 'minder' process is dying as part of the boot process whilst dnsmasq does not.....which is why procd is trying to start more instances.

None:

OK, another theory, but this one's a corker and fits with available facts. Looking through the logfile it's a more a case of what's missing rather than what's present.... normally dnsmasq starts with 'dnssec timestamp checks' disabled and waits for a -SIGHUP (via procd) caused by a hotplug/ntpd script signalling time is now valid.

The logfile shows dnsmasq starting in 'no timestamp mode' but it never gets the signal that timestamps are valid (via the SIGHUP) even though ntpd has gone through it's 'time is valid' hotplug script. I suspect procd is signalling the procd jailer, rather than the procd jailee. And procd jailer responds to sighup by closing shop as it should.

No idea how to fix...but that's what I think is going on.

None:

A workaround fix lede-project/source#799

None:

Procd fixed: https://git.lede-project.org/?p=project/procd.git;a=summary

The fix into LEDE master
https://git.lede-project.org/?p=source.git;a=commit;h=1f3de9954726353177d044a2435af373ca4d2e8e

The fix into LEDE 17.01
https://git.lede-project.org/?p=source.git;a=commit;h=bd64568d27681d2a3d9fe469863a251bb0cb1f75