What's new

Entware Where is Entware started upon reboot?

  • SNBForums Code of Conduct

    SNBForums is a community for everyone, no matter what their level of experience.

    Please be tolerant and patient of others, especially newcomers. We are all here to share and learn!

    The rules are simple: Be patient, be nice, be helpful or be gone!

bibikalka

Senior Member
Alright, I was chasing the mysterious error I was getting from dnsmasq - link.

And it took me down this rabbit hole below. I've taken this out of the post in the Diversion thread, for better visibility. The story is below. But the key question is where are different Entware related things are launched, given that I try to delay commands in the obvious candidate script [/jffs/addons/amtm/mount-entware.mod], and it never waits to start all the other Entware related stuff such as diversion.

###
I was trying to chase which script starts Diversion, and could not find it. I am still chasing that "dnsmasq: failed to create listening socket for 192.168.1.1: Address already in use" error. My present thought is that it could be a boot up timing issue, where cold boots probably boot slower compared to warm ones.

I thought it was this line in post-mount:
Code:
. /jffs/addons/amtm/mount-entware.mod # Added by amtm

But if I add a bunch of sleeps to this script, it still seems to start Diversion without any sleep.
/jffs/addons/amtm/mount-entware.mod

Code:
mount_entware(){
        if [ -f "${opkgFile%/opkg}/diversion" ]; then
                logger -t Entware "Starting Entware and Diversion services on $1"
                ln -nsf "${opkgFile%/bin/opkg}" /tmp/opt
                logger -t Entware "Sleep01"
                sleep 15
                logger -t Entware "Sleep02"
                service restart_dnsmasq
                logger -t Entware "Sleep03"
                sleep 15
                logger -t Entware "Sleep04"
                /opt/etc/init.d/rc.unslung start $0
                logger -t Entware "Sleep11"
                sleep 15
                logger -t Entware "Sleep12"
                service restart_dnsmasq
                logger -t Entware "Sleep13"
                sleep 15
                logger -t Entware "Sleep14"
        else
                logger -t Entware "Starting Entware services on $1"
                ln -nsf "${opkgFile%/bin/opkg}" /tmp/opt
                /opt/etc/init.d/rc.unslung start $0
        fi
}

Here is an example from the log, where I don't see the expected 15 seconds. It seems something else starts Diversion elsewhere?
Code:
Sep 29 04:06:33 Entware: Starting Entware and Diversion services on /tmp/mnt/ac86u
Sep 29 04:06:33 Entware: Sleep01
...
Sep 29 04:06:38 RT-AC86U-9988 Diversion: created br0:ad_blocking_excl for 192.168.1.16
...
Sep 29 04:06:38 RT-AC86U-9988 Diversion: started separate Dnsmasq instance for ad-blocking exclusion on IP 192.168.1.16
...

Update:
For some strange reason things never even get to "Sleep02" message, it just keeps running stuff elsewhere!
Code:
Sep 30 04:06:33 custom_script: Running /jffs/scripts/post-mount (args: /tmp/mnt/ac86u)
Sep 30 04:06:33 Entware: Starting Entware and Diversion services on /tmp/mnt/ac86u
Sep 30 04:06:33 Entware: Sleep01
Sep 30 04:06:33 avahi-daemon[3513]: Server startup complete. Host name is RT-AC86U-9988.local. Local service cookie is 1338142308.
Sep 30 04:06:33 avahi-daemon[3513]: Alias name "RT-AC86U" successfully established.
Sep 30 04:06:33 Skynet: [i] Startup Initiated... ( skynetloc=/tmp/mnt/ac86u/skynet )
Sep 30 04:06:35 custom_script: Running /jffs/scripts/firewall-start (args: eth0)
Sep 30 04:06:35 rc_service: udhcpc_wan 1404:notify_rc stop_samba
Sep 30 04:06:35 custom_script: Running /jffs/scripts/service-event (args: stop samba)
Sep 30 04:06:35 wsdd2[3527]: Terminated received.
Sep 30 04:06:35 wsdd2[3527]: terminating.
Sep 30 04:06:36 kernel: klogd: exiting
Sep 30 04:06:36 syslogd exiting
Sep 30 04:06:37 RT-AC86U-9988 uiScribe: Mounting WebUI page for uiScribe
Sep 30 04:06:37 RT-AC86U-9988 uiScribe: Mounted uiScribe WebUI page as Main_LogStatus_Content.asp
Sep 30 04:06:37 RT-AC86U-9988 avahi-daemon[3513]: Registering new address record for 192.168.1.16 on br0.IPv4.
Sep 30 04:06:37 RT-AC86U-9988 Diversion: created br0:ad_blocking_excl for 192.168.1.16
 
Last edited:
Diversion is "activated" via dnsmasq.postconf. But don't put sleeps in dnsmasq.postconf. You could mess up dnsmasq starting.
 
Last edited:
Diversion is "activated" via dnsmasq.postconf. But don't put sleeps in dnsmasq.postconf. You could mess up dnsmasq starting.
Interesting ...

So the script that links Entware directory (and diversion location!) is /jffs/addons/amtm/mount-entware.mod, but diversion is actually started elsewhere!

I now think that this "service restart_dnsmasq" command in mount-entware.mod was messing up the diversion setting itself up elsewhere, possibly causing my issues. Since random additions of other stuff that had to run would make the problem either appear or go away. But sticking sleep in there I pushed it back, so hopefully the timing is favorable now.
 
Last edited:
or some strange reason things never even get to "Sleep02" message, it just keeps running stuff elsewhere!
Stop that sleep nonsense. My scripts need no sleep stuff unless I coded it for specific reasons.

I have no intention to find out where your problem with br0:ad_blocking_excl not starting comes from. It must be a firmware / Dnsmasq or router problem.
So don't expect me to pipe in anymore with more input or ideas. My scripts work flawlessly on all the routers I can test them on.
 
@thelonelycoder

Not clear what is nonsense here, a few sleep spacers should not adversely impact the execution of a script, and may help with debugging ...

It does appear that Diversion is started outside of /jffs/addons/amtm/mount-entware.mod.

Today my reboot got through all Sleep messages, and still Diversion is started at 04:06:36 right after Entware was detected when it should be sleeping till later. Then the command I added [service restart_dnsmasq] ran at 6:50, and it restarted Diversion again.

It seems several things may call for dnsmasq restart, and each time that restarts Diversion.

Code:
Oct  1 04:06:35 hotplug[2630]: USB ext4 fs at /dev/sda1 mounted on /tmp/mnt/ac86u
Oct  1 04:06:35 usb: USB ext4 fs at /dev/sda1 mounted on /tmp/mnt/ac86u.
Oct  1 04:06:35 kernel: EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: user_xattr
Oct  1 04:06:35 custom_script: Running /jffs/scripts/post-mount (args: /tmp/mnt/ac86u)
Oct  1 04:06:35 Entware: Starting Entware and Diversion services on /tmp/mnt/ac86u
Oct  1 04:06:35 Entware: Sleep01
Oct  1 04:06:35 custom_script: Running /jffs/scripts/service-event (args: stop samba)
Oct  1 04:06:35 wsdd2[4178]: Terminated received.
Oct  1 04:06:35 wsdd2[4178]: terminating.
Oct  1 04:06:35 avahi-daemon[4159]: Server startup complete. Host name is RT-AC86U-9988.local. Local service cookie is 2088467721.
Oct  1 04:06:35 avahi-daemon[4159]: Alias name "RT-AC86U" successfully established.
Oct  1 04:06:36 Samba_Server: smb daemon is stopped
Oct  1 04:06:36 rc_service: udhcpc_wan 1388:notify_rc start_samba
Oct  1 04:06:36 custom_script: Running /jffs/scripts/service-event (args: start samba)
Oct  1 04:06:36 dnsmasq[1164]: exiting on receipt of SIGTERM
Oct  1 04:06:36 custom_config: Appending content of /jffs/configs/dnsmasq.conf.add.
Oct  1 04:06:36 custom_script: Running /jffs/scripts/dnsmasq.postconf (args: /etc/dnsmasq.conf)
Oct  1 04:06:36 (dnsmasq.postconf): Updating /etc/dnsmasq.conf for unbound.....
Oct  1 04:06:37 Diversion: Mounting Diversion WebUI page
Oct  1 04:06:37 Diversion: Mounted Diversion WebUI as user1.asp in LAN/Diversion
Oct  1 04:06:37 avahi-daemon[4159]: Registering new address record for 192.168.1.16 on br0.IPv4.
Oct  1 04:06:37 Diversion: created br0:ad_blocking_excl for 192.168.1.16
Oct  1 04:06:37 dnsmasq[4706]: started, version 2.90 cachesize 150
Oct  1 04:06:37 dnsmasq[4706]: read /etc/hosts - 22 names
Oct  1 04:06:37 Diversion: started separate Dnsmasq instance for ad-blocking exclusion on IP 192.168.1.16
Oct  1 04:06:37 Diversion: restarted Dnsmasq to apply settings
Oct  1 04:06:37 Samba_Server: daemon is started
Oct  1 04:06:37 wsdd2[4728]: starting.
Oct  1 04:06:37 wan_up: Restart DDNS
Oct  1 04:06:37 dhcp_client: bound 107.222.104.245/255.255.252.0 via 107.222.104.1 for 3600 seconds.
Oct  1 04:06:37 admin: Started /jffs/addons/scmerlin.d/tailtopd from .
Oct  1 04:06:37 scMerlin: Mounting WebUI tabs for scMerlin
Oct  1 04:06:38 scMerlin: Mounted Sitemap page as user3.asp
Oct  1 04:06:38 scMerlin: Mounted scMerlin WebUI page as user2.asp
Oct  1 04:06:43 Skynet: [i] Startup Initiated... ( skynetloc=/tmp/mnt/ac86u/skynet )
Oct  1 04:06:50 Entware: Sleep02
Oct  1 04:06:50 rc_service: service 5574:notify_rc restart_dnsmasq
Oct  1 04:06:50 custom_script: Running /jffs/scripts/service-event (args: restart dnsmasq)
Oct  1 04:06:50 Entware: Sleep03
Oct  1 04:06:50 dnsmasq[4706]: exiting on receipt of SIGTERM
Oct  1 04:06:50 custom_config: Appending content of /jffs/configs/dnsmasq.conf.add.
Oct  1 04:06:50 custom_script: Running /jffs/scripts/dnsmasq.postconf (args: /etc/dnsmasq.conf)
Oct  1 04:06:50 (dnsmasq.postconf): Updating /etc/dnsmasq.conf for unbound.....
Oct  1 04:06:50 Diversion: created br0:ad_blocking_excl for 192.168.1.16
Oct  1 04:06:50 dnsmasq[5793]: started, version 2.90 cachesize 150
Oct  1 04:06:50 dnsmasq[5793]: read /etc/hosts - 22 names
Oct  1 04:06:50 Diversion: started separate Dnsmasq instance for ad-blocking exclusion on IP 192.168.1.16
Oct  1 04:06:50 Diversion: restarted Dnsmasq to apply settings
Oct  1 04:06:53 kernel: Adding 2097148k swap on /tmp/mnt/ac86u/myswap.swp.  Priority:-1 extents:39 across:3260412k
Oct  1 04:06:58 rc_service: service 6123:notify_rc restart_dnsmasq
Oct  1 04:06:58 custom_script: Running /jffs/scripts/service-event (args: restart dnsmasq)
Oct  1 04:06:58 dnsmasq[5793]: exiting on receipt of SIGTERM
Oct  1 04:06:58 custom_config: Appending content of /jffs/configs/dnsmasq.conf.add.
Oct  1 04:06:58 custom_script: Running /jffs/scripts/dnsmasq.postconf (args: /etc/dnsmasq.conf)
Oct  1 04:06:58 (dnsmasq.postconf): Updating /etc/dnsmasq.conf for unbound.....
Oct  1 04:06:59 Diversion: created br0:ad_blocking_excl for 192.168.1.16
Oct  1 04:06:59 dnsmasq[6477]: started, version 2.90 cachesize 150
Oct  1 04:06:59 dnsmasq[6477]: read /etc/hosts - 22 names
Oct  1 04:06:59 Diversion: started separate Dnsmasq instance for ad-blocking exclusion on IP 192.168.1.16
Oct  1 04:06:59 Diversion: restarted Dnsmasq to apply settings
Oct  1 04:07:05 Entware: Sleep04
Oct  1 04:07:05 kernel: klogd: exiting
Oct  1 04:07:05 syslogd exiting
Oct  1 04:07:18 RT-AC86U-9988 admin: Failed to start unbound from /jffs/scripts/post-mount.
Oct  1 04:07:18 RT-AC86U-9988 admin: Started ntpd from /jffs/scripts/post-mount.
Oct  1 04:07:18 RT-AC86U-9988 admin: Started taildns from /jffs/scripts/post-mount.
Oct  1 04:07:18 RT-AC86U-9988 Entware: Sleep11
Oct  1 04:07:33 RT-AC86U-9988 Entware: Sleep12
Oct  1 04:07:33 RT-AC86U-9988 rc_service: service 8657:notify_rc restart_dnsmasq
Oct  1 04:07:33 RT-AC86U-9988 custom_script: Running /jffs/scripts/service-event (args: restart dnsmasq)
Oct  1 04:07:33 RT-AC86U-9988 Entware: Sleep13
Oct  1 04:07:33 RT-AC86U-9988 dnsmasq[6477]: exiting on receipt of SIGTERM
Oct  1 04:07:33 RT-AC86U-9988 custom_config: Appending content of /jffs/configs/dnsmasq.conf.add.
Oct  1 04:07:33 RT-AC86U-9988 custom_script: Running /jffs/scripts/dnsmasq.postconf (args: /etc/dnsmasq.conf)
Oct  1 04:07:33 RT-AC86U-9988 (dnsmasq.postconf): Updating /etc/dnsmasq.conf for unbound.....
Oct  1 04:07:33 RT-AC86U-9988 Diversion: created br0:ad_blocking_excl for 192.168.1.16
Oct  1 04:07:33 RT-AC86U-9988 dnsmasq[8907]: started, version 2.90 cachesize 150
Oct  1 04:07:33 RT-AC86U-9988 dnsmasq[8907]: compile time options: IPv6 GNU-getopt no-RTC no-DBus no-UBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset no-nftset no-auth cryptohash DNSSEC no-ID loop-detect no-inotify no-dumpfile
Oct  1 04:07:33 RT-AC86U-9988 dnsmasq[8907]: read /etc/hosts - 22 names
Oct  1 04:07:33 RT-AC86U-9988 Diversion: started separate Dnsmasq instance for ad-blocking exclusion on IP 192.168.1.16
Oct  1 04:07:33 RT-AC86U-9988 Diversion: restarted Dnsmasq to apply settings
Oct  1 04:07:48 RT-AC86U-9988 Entware: Sleep14
Oct  1 04:07:48 RT-AC86U-9988 uiDivStats: /tmp/mnt/ac86u contains Entware, starting uiDivStats
Oct  1 04:07:48 RT-AC86U-9988 dn-vnstat: /tmp/mnt/ac86u contains Entware, starting dn-vnstat
Oct  1 04:07:48 RT-AC86U-9988 uiScribe: /tmp/mnt/ac86u contains Entware, starting uiScribe
Oct  1 04:07:48 RT-AC86U-9988 ntpMerlin: /tmp/mnt/ac86u contains Entware, starting ntpMerlin
Oct  1 04:07:48 RT-AC86U-9988 connmon: /tmp/mnt/ac86u contains Entware, starting connmon
Oct  1 04:07:48 RT-AC86U-9988 uiScribe: Mounting WebUI page for uiScribe
Oct  1 04:07:48 RT-AC86U-9988 uiScribe: Mounted uiScribe WebUI page as Main_LogStatus_Content.asp
Oct  1 04:07:48 RT-AC86U-9988 rc_service: hotplug 2630:notify_rc restart_nasapps
Oct  1 04:07:48 RT-AC86U-9988 custom_script: Running /jffs/scripts/service-event (args: restart nasapps)
Oct  1 04:07:48 RT-AC86U-9988 avahi-daemon[4159]: Files changed, reloading.
Oct  1 04:07:48 RT-AC86U-9988 avahi-daemon[4159]: Loading service file /tmp/avahi/services/mt-daap.service.
Oct  1 04:07:48 RT-AC86U-9988 iTunes: daemon is stopped
Oct  1 04:07:48 RT-AC86U-9988 FTP_Server: daemon is stopped
Oct  1 04:07:48 RT-AC86U-9988 wsdd2[4728]: Terminated received.
Oct  1 04:07:48 RT-AC86U-9988 wsdd2[4728]: terminating.
Oct  1 04:07:49 RT-AC86U-9988 avahi-daemon[4159]: Service "RT-AC86U-9988" (/tmp/avahi/services/mt-daap.service) successfully established.
Oct  1 04:07:50 RT-AC86U-9988 Samba_Server: smb daemon is stopped
Oct  1 04:07:50 RT-AC86U-9988 avahi-daemon[4159]: Got SIGTERM, quitting.
Oct  1 04:07:50 RT-AC86U-9988 avahi-daemon[4159]: Leaving mDNS multicast group on interface br0.IPv4 with address 192.168.1.1.
Oct  1 04:07:50 RT-AC86U-9988 avahi-daemon[4159]: Leaving mDNS multicast group on interface lo.IPv4 with address 127.0.1.1.
Oct  1 04:07:50 RT-AC86U-9988 avahi-daemon[4159]: avahi-daemon 0.8 exiting.
...
 
Given that you're running so many add-ons at the same time it would make sense to just factory reset, basic setup, restore nothing, setup amtm, install just Diversion as an add-on and test - now breath 😁
I know, my signature, but they're not all running, just installed. What you're experiencing is a sign of instability.
 
Given that you're running so many add-ons at the same time it would make sense to just factory reset, basic setup, restore nothing, setup amtm, install just Diversion as an add-on and test - now breath 😁
I know, my signature, but they're not all running, just installed. What you're experiencing is a sign of instability.

I know factory resets are recommended - but often the same issues do come back :(

I think I'll just go with something like this in /jffs/addons/amtm/mount-entware.mod
Code:
(sleep 15 && service restart_dnsmasq) &

This should let dnsmasq issues resolve themselves.
 
This should let dnsmasq issues resolve themselves.
What I would want to know as diagnostic information, is what else is listening on port 53 before dnsmasq starts?
Code:
netstat -nltup | grep ":53 " | logger -t "$(basename $0)[$$]"
Maybe put that in /jffs/scripts/dnsmasq.postconf and anywhere else you are poking around.
 
What I would want to know as diagnostic information, is what else is listening on port 53 before dnsmasq starts?
Code:
netstat -nltup | grep ":53 " | logger -t "$(basename $0)[$$]"
Maybe put that in /jffs/scripts/dnsmasq.postconf and anywhere else you are poking around.

I guess I add it after all the other stuff? Like this:

Code:
admin@RT-AC86U-9988:/jffs/scripts# more dnsmasq.postconf
#!/bin/sh
sh /jffs/addons/unbound/unbound.postconf "$1"           # unbound_manager
/jffs/scripts/uiDivStats dnsmasq & # uiDivStats

. /opt/share/diversion/file/post-conf.div # Added by Diversion
/opt/bin/netstat -nltup | grep ":53 " | logger -t "$(basename $0)[$$]"
 
Put it both before and after the post-conf.div for now. I’m guessing the extra interfaces are added during that script.

During the auto-reboot today /jffs/addons/amtm/mount-entware.mod just died in the middle of one of the sleep commands I inserted, LOL.

So far every warm reboot appears to proceed differently, judging by the log file.

Anyway, your script generally says this from the command line:
Code:
admin@RT-AC86U-9988:/# /opt/bin/netstat -nltup | grep ":53 "
tcp        0      0 127.0.0.1:53            0.0.0.0:*               LISTEN      8712/dnsmasq
tcp       33      0 192.168.1.1:53          0.0.0.0:*               LISTEN      8712/dnsmasq
tcp        0      0 192.168.1.16:53         0.0.0.0:*               LISTEN      8614/dnsmasq
udp        0      0 127.0.0.1:53            0.0.0.0:*                           8712/dnsmasq
udp        0      0 192.168.1.1:53          0.0.0.0:*                           8712/dnsmasq
udp        0      0 192.168.1.16:53         0.0.0.0:*                           8614/dnsmasq
admin@RT-AC86U-9988:/#

When unbound restarted dnsmasq (the one in mount-entware.mod script never ran since this died!), there was nothing before and not much after, just that .16 address. Also, it took /jffs/scripts/dnsmasq.postconf about 90 seconds to run through, it seems like this run waited for /opt to become available before it continued? Or did scribe eat my log messages? Anyway, will continue to monitor this!
Code:
admin@RT-AC86U-9988:/jffs/scripts# more dnsmasq.postconf
#!/bin/sh
sh /jffs/addons/unbound/unbound.postconf "$1"           # unbound_manager
/jffs/scripts/uiDivStats dnsmasq & # uiDivStats

logger -t post-conf.div "Before"
/opt/bin/netstat -nltup | grep ":53 " | logger -t "$(basename $0)[$$]"
. /opt/share/diversion/file/post-conf.div # Added by Diversion
logger -t post-conf.div "After"
/opt/bin/netstat -nltup | grep ":53 " | logger -t "$(basename $0)[$$]"

Parts of the log file during warm boot:
Code:
Oct  2 04:05:10 post-conf.div: Before
Oct  2 04:05:11 dnsmasq[1170]: started, version 2.90 cachesize 1500
...
Oct  2 04:06:32 Entware: Starting Entware and Diversion services on /tmp/mnt/ac86u
...
Oct  2 04:06:38 RT-AC86U-9988 avahi-daemon[3086]: Registering new address record for 192.168.1.16 on br0.IPv4.
Oct  2 04:06:38 RT-AC86U-9988 Diversion: created br0:ad_blocking_excl for 192.168.1.16
Oct  2 04:06:38 RT-AC86U-9988 dnsmasq[4144]: started, version 2.90 cachesize 150
Oct  2 04:06:38 RT-AC86U-9988 dnsmasq[4144]: compile time options: IPv6 GNU-getopt no-RTC no-DBus no-UBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP
Oct  2 04:06:38 RT-AC86U-9988 dnsmasq[4144]: read /etc/hosts - 22 names
...
Oct  2 04:06:38 RT-AC86U-9988 Diversion: started separate Dnsmasq instance for ad-blocking exclusion on IP 192.168.1.16
Oct  2 04:06:38 RT-AC86U-9988 Diversion: restarted Dnsmasq to apply settings
Oct  2 04:06:38 RT-AC86U-9988 post-conf.div: After
Oct  2 04:06:38 RT-AC86U-9988 dnsmasq.postconf[3592]: tcp        0      0 192.168.1.16:53         0.0.0.0:*               LISTEN      4144/dnsmas
Oct  2 04:06:38 RT-AC86U-9988 dnsmasq.postconf[3592]: udp        0      0 192.168.1.16:53         0.0.0.0:*                           4144/dnsmas
Oct  2 04:06:39 RT-AC86U-9988 admin: Started syslog-ng from /jffs/scripts/post-mount.
 
During the auto-reboot today /jffs/addons/amtm/mount-entware.mod just died in the middle of one of the sleep commands I inserted, LOL.
There’s a 120 second limit/timeout for post-mount and several other time-critical script hooks. Sleeping is bad.

Also, it took /jffs/scripts/dnsmasq.postconf about 90 seconds to run through, it seems like this run waited for /opt to become available before it continued? Or did scribe eat my log messages? Anyway, will continue to monitor this!
How are you measuring the start time of dnsmasq.postconf?

I do think there are too many addons installed, making troubleshooting more difficult.
 
There’s a 120 second limit/timeout for post-mount and several other time-critical script hooks. Sleeping is bad.

How are you measuring the start time of dnsmasq.postconf?

I do think there are too many addons installed, making troubleshooting more difficult.
I measure time by time stamps. I found something interesting today :) As in that chinese saying about interesting times.

So I observed yesterday that the early /jffs/scripts/dnsmasq.postconf invocation at 04:05:09 was not printing After:
Code:
Oct  3 04:05:09 post-conf.div: Before
Oct  3 04:06:53 RT-AC86U-9988 post-conf.div: Before
Oct  3 04:06:53 RT-AC86U-9988 post-conf.div: After
Oct  3 04:07:00 RT-AC86U-9988 post-conf.div: Before
Oct  3 04:07:00 RT-AC86U-9988 post-conf.div: After
Oct  3 04:25:04 RT-AC86U-9988 post-conf.div: Before
Oct  3 04:25:04 RT-AC86U-9988 post-conf.div: After

So it seemed that /jffs/scripts/dnsmasq.postconf script when called early might have been trying to access /opt/share/diversion before it was mounted. So I decided to fix that, here is the version of the script:
Code:
#!/bin/sh
sh /jffs/addons/unbound/unbound.postconf "$1"           # unbound_manager

logger -t post-conf.div "Before"
if [ -d "/opt/share/diversion" ]; then
/jffs/scripts/uiDivStats dnsmasq & # uiDivStats
/opt/bin/netstat -nltup | grep ":53 " | logger -t "$(basename $0)[$$]"
. /opt/share/diversion/file/post-conf.div # Added by Diversion
/opt/bin/netstat -nltup | grep ":53 " | logger -t "$(basename $0)[$$]"
else
logger -t post-conf.div "NO Entware yet"
fi
logger -t post-conf.div "After"

Well, with this "fix" things have gone to hell, I could barely login to the router to replace the script back through one of my static computers connected to an AiMesh node, nothing else worked!

It ate the first "Before" message somehow at around 04:06:39, and I got that "already in use" error. I am not even sure how the "After" at 04:06:40 appeared without the respective "Before" below!
Code:
Oct  4 04:05:09 post-conf.div: Before
Oct  4 04:05:09 post-conf.div: NO Entware yet
Oct  4 04:05:09 post-conf.div: After
Oct  4 04:06:39 RT-AC86U-9988 dnsmasq[5081]: failed to create listening socket for 192.168.1.16: Address already in use
Oct  4 04:06:40 RT-AC86U-9988 post-conf.div: After
Oct  4 04:06:40 RT-AC86U-9988 dnsmasq[5122]: failed to create listening socket for 192.168.1.1: Address already in use
Oct  4 04:09:22 RT-AC86U-9988 post-conf.div: Before
Oct  4 04:09:22 RT-AC86U-9988 dnsmasq[21292]: failed to create listening socket for 192.168.1.16: Address already in use
Oct  4 04:09:22 RT-AC86U-9988 post-conf.div: After
Oct  4 04:09:22 RT-AC86U-9988 dnsmasq[21301]: failed to create listening socket for 192.168.1.1: Address already in use

When I tried to reboot by complete power disconnect, it produced the identical behavior, and it would not serve IP addresses:
Code:
Oct  4 06:45:02 post-conf.div: Before
Oct  4 06:45:02 post-conf.div: NO Entware yet
Oct  4 06:45:02 post-conf.div: After
Oct  4 07:11:41 RT-AC86U-9988 dnsmasq[4655]: failed to create listening socket for 192.168.1.16: Address already in use
Oct  4 07:11:41 RT-AC86U-9988 post-conf.div: After
Oct  4 07:11:41 RT-AC86U-9988 dnsmasq[4671]: failed to create listening socket for 192.168.1.1: Address already in use
Oct  4 07:11:48 RT-AC86U-9988 post-conf.div: Before
Oct  4 07:11:49 RT-AC86U-9988 dnsmasq[9703]: failed to create listening socket for 192.168.1.16: Address already in use
Oct  4 07:11:49 RT-AC86U-9988 post-conf.div: After
Oct  4 07:11:49 RT-AC86U-9988 dnsmasq[9761]: failed to create listening socket for 192.168.1.1: Address already in use
 
Last edited:
There’s a 120 second limit/timeout for post-mount and several other time-critical script hooks. Sleeping is bad.
My sleeps are mild, no more that 15 seconds total. I did read about the timeout thing.

Anyway, to summarize. There is a very early call to /jffs/scripts/dnsmasq.postconf, which happens way before Entware is mounted. dnsmasq.postconf calls ". /opt/share/diversion/file/post-conf.div" without any conditions, seemingly assuming it will be there. Does @thelonelycoder assume that /jffs/scripts/dnsmasq.postconf would never get called before Entware is present?

This early call never seems to complete and print the "After" message without the test on diversion presence. Then, with the diversion presence "if" added somehow the next dnsmasq.postconf call does not print "Before" - and leads to "already in use" error.
 
Last edited:
That would just mean there are no dns instances running yet, which is fine early on.
But this message is from within the dnsmasq.postconf script! See this line in my dnsmasq.postconf :
Code:
logger -t post-conf.div "Before"

And it's somehow not executed ...

Can you check your logs, and see when dnsmasq is launched relative to this message: "kernel: Booting Linux on physical". It'd be interesting to see the timestamps.
 
And it's somehow not executed ...
What’s interesting and frustrating is that your logs seem to switchover to syslog-ng in the middle of the sequence. My boot logs have already rolled off my syslog files, so can’t compare with yours.

Have you ever tested this after a full reset and then only installing Diversion? Too many distractions from other addons.
 
Have to ask - what version of Diversion are you running? In your other thread you said you updated Entware Packages, but what about the add-on scripts?
 
What’s interesting and frustrating is that your logs seem to switchover to syslog-ng in the middle of the sequence. My boot logs have already rolled off my syslog files, so can’t compare with yours.

Have you ever tested this after a full reset and then only installing Diversion? Too many distractions from other addons.
Yep, agreed!

My impression now is that a lot of things simply pause and wait for /opt Entware stuff to be mounted. Then they hit with vengeance, including scribe, right after the mount occurs.

It looks there are about 90 seconds between boot and Entware mount, so anything that was waiting will run at once. The full boot appears to be done under ~2 minutes.

Anyway, I no longer have the original issue after I inserted the sleep spacers. I will monitor this for a bit now!

Code:
Oct  4 07:59:22 kernel: Booting Linux on physical CPU 0x0
...
Oct  4 08:00:51 Entware: Starting Entware and Diversion services on /tmp/mnt/ac86u
...
Oct  4 08:01:17 RT-AC86U-9988 uiDivStats: Mounting WebUI tab for uiDivStats
Oct  4 08:01:17 RT-AC86U-9988 uiDivStats: Mounted uiDivStats WebUI page as user8.asp
...
 
My impression now is that a lot of things simply pause and wait for /opt Entware stuff to be mounted.
That's because Entware starts services in numerical order that have an S* start file in /opt/etc/init.d/.
After amtm mounts the /opt folder it kicks off /opt/etc/init.d/rc.unslung which runs the above.
 

Latest threads

Support SNBForums w/ Amazon

If you'd like to support SNBForums, just use this link and buy anything on Amazon. Thanks!

Sign Up For SNBForums Daily Digest

Get an update of what's new every day delivered to your mailbox. Sign up here!
Top