Viktor Jaep
Part of the Furniture
So would you recommend letting the script lock up... then running an strace on the hung "nvram get" PID to examine the hung process further?
I ranSo would you recommend letting the script lock up... then running an strace on the hung "nvram get" PID to examine the hung process further?
watch -n 0 strace -r nvram get wan0_enable
I guess I could run 5 different watch windows to monitor each of the vpnclient# state nvram values to see which one it randomly hangs on?I ranwatch -n 0 strace -r nvram get wan0_enable
It doesn’t really matter what variable you choose, as best as I can tell.I guess I could run 5 different watch windows to monitor each of the vpnclient# state nvram values to see which one it randomly hangs on?
It will keep redrawing until the watched command hangs. I wasn’t getting anywhere with a 1 second interval so I went to 0. But that makes it harder to stop the watch loop when you want to ctrl-c. It ends the hung nvram command and starts a new one. So I kill the watch pid in another window and copy/paste the last output in the other window.Well... I dunno. I didn't see a way to control the output of this strace info... it was flying across my screen. The vpn_client3_state locked, but the strace window monitoring that nvram command just kept on going. Not quite sure how to handle this.
Yeah, I was not able to ctrl-c out of that...It will keep redrawing until the watched command hangs. I wasn’t getting anywhere with a 1 second interval so I went to 0. But that makes it harder to stop the watch loop when you want to ctrl-c. It ends the hung nvram command and starts a new one. So I kill the watch pid in another window and copy/paste the last output in the other window.
#!/bin/sh
# copy original nvram executable to /tmp
cp /usr/sbin/nvram /tmp/_nvram
# create nvram wrapper that calls original nvram executable in /tmp
cat << 'EOF' > /tmp/nvram
#!/bin/sh
#set -x # comment/uncomment to disable/enable debug mode
# required for serialization when reentry is possible
LOCK="/tmp/$(basename $0).lock"
acquire_lock() { until mkdir $LOCK &>/dev/null; do sleep 2; done; }
release_lock() { rmdir $LOCK &>/dev/null; }
# one instance at a time
acquire_lock
# catch premature exit and cleanup
trap 'release_lock; exit 1' SIGHUP SIGINT SIGTERM
/tmp/_nvram $@
rc=$?
# any concurrent instance(s) may now run
release_lock
exit $rc
EOF
chmod +x /tmp/nvram
# replace nvram in /usr/sbin w/ nvram wrapper in /tmp
mount -o bind /tmp/nvram /usr/sbin/nvram
Every 0s: strace -r wl -i eth5 noise 2022-06-14 20:07:33
0.000000 execve("/usr/sbin/wl", ["wl", "-i", "eth5", "noise"], 0x7fe50f5f30 /* 18 vars */ <unfinished ...>
0.000662 [ Process PID=1163 runs in 32 bit mode. ]
strace: WARNING: Proper structure decoding for this personality is not supported, please consider building strace with mpers support enabled.
0.000040 <... execve resumed>) = 0
0.000066 brk(NULL) = 0x82f000
0.000057 uname({sysname="Linux", nodename="router", ...}) = 0
0.000096 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xf72fa000
0.000064 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
0.000127 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
0.000068 fstat64(3, 0xffd6d570) = 0
0.000319 mmap2(NULL, 10528, PROT_READ, MAP_PRIVATE, 3, 0) = 0xf72f7000
0.000044 close(3) = 0
0.000053 open("/lib/libnvram.so", O_RDONLY|O_CLOEXEC) = 3
0.000050 read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\08\t\0\0004\0\0\0"..., 512) = 512
0.000051 fstat64(3, 0xffd6d5b0) = 0
0.000041 mmap2(NULL, 69528, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xf72bb000
0.000047 mprotect(0xf72bc000, 61440, PROT_NONE) = 0
0.000049 mmap2(0xf72cb000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0) = 0xf72cb000
0.000058 close(3) = 0
0.000045 open("/lib/libwlcsm.so", O_RDONLY|O_CLOEXEC) = 3
0.000048 read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\200\34\0\0004\0\0\0"..., 512) = 512
0.000047 fstat64(3, 0xffd6d598) = 0
0.000038 mmap2(NULL, 90092, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xf72a5000
0.000044 mprotect(0xf72aa000, 61440, PROT_NONE) = 0
0.000046 mmap2(0xf72b9000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x4000) = 0xf72b9000
0.000067 close(3) = 0
0.000046 open("/usr/lib/libshared.so", O_RDONLY|O_CLOEXEC) = 3
0.000050 read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\214X\1\0004\0\0\0"..., 512) = 512
0.000048 fstat64(3, 0xffd6d580) = 0
0.000038 mmap2(NULL, 646528, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xf7207000
0.000044 mprotect(0xf7274000, 65536, PROT_NONE) = 0
0.000047 mmap2(0xf7284000, 45056, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6d000) = 0xf7284000
0.000059 mmap2(0xf728f000, 89472, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xf728f000
0.000060 close(3) = 0
0.000054 open("/lib/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
0.000047 read(3, "\177ELF\1\1\1\3\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0xm\1\0004\0\0\0"..., 512) = 512
0.000048 fstat64(3, 0xffd6d568) = 0
0.000038 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xf72f6000
0.000047 mmap2(NULL, 1299824, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xf70c9000
0.000045 mprotect(0xf71f1000, 65536, PROT_NONE) = 0
0.000052 mmap2(0xf7201000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x128000) = 0xf7201000
0.000059 mmap2(0xf7204000, 9584, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xf7204000
0.000056 close(3) = 0
0.000061 open("/lib/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
0.000050 read(3, "\177ELF\1\1\1\3\0\0\0\0\0\0\0\0\3\0(\0\1\0\0\0\\I\0\0004\0\0\0"..., 512) = 512
0.000048 fstat64(3, 0xffd6d460) = 0
0.000038 mmap2(NULL, 164436, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xf70a0000
0.000045 mprotect(0xf70b5000, 65536, PROT_NONE) = 0
0.000050 mmap2(0xf70c5000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x15000) = 0xf70c5000
0.000060 mmap2(0xf70c7000, 4692, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xf70c7000
0.000055 close(3) = 0
0.000073 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xf72f5000
0.000048 set_tls(0xf72f54c0) = 0
0.000257 mprotect(0xf7201000, 8192, PROT_READ) = 0
0.000088 mprotect(0xf70c5000, 4096, PROT_READ) = 0
0.000298 mprotect(0xf72fb000, 4096, PROT_READ) = 0
0.000051 munmap(0xf72f7000, 10528) = 0
0.000050 set_tid_address(0xf72f5068) = 1163
0.000036 set_robust_list(0xf72f5070, 12) = 0
0.000052 rt_sigaction(SIGRTMIN, {sa_handler=0xf70a4278, sa_mask=[], sa_flags=SA_RESTORER|SA_SIGINFO, sa_restorer=0xf70f5b10}, NULL, 8) = 0
0.000063 rt_sigaction(SIGRT_1, {sa_handler=0xf70a435c, sa_mask=[], sa_flags=SA_RESTORER|SA_RESTART|SA_SIGINFO, sa_restorer=0xf70f5b10}, NULL, 8) = 0
0.000064 rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
0.000059 ugetrlimit(RLIMIT_STACK, {rlim_cur=2048*1024, rlim_max=RLIM_INFINITY}) = 0
0.000215 socket(AF_INET, SOCK_DGRAM, IPPROTO_IP) = 3
0.000077 ioctl(3, SIOCDEVPRIVATE, 0xffd6db00) = 0
0.000257 close(3) = 0
0.000055 socket(AF_INET, SOCK_DGRAM, IPPROTO_IP) = 3
0.000041 ioctl(3, SIOCDEVPRIVATE, 0xffd6db00) = 0
0.000149 close(3) = 0
0.000069 stat64("/jffs", 0xffd6d9a8) = 0
0.000055 stat64("/jffs/nvram_war", 0xffd6d9a8) = 0
0.000086 socket(AF_NETLINK, SOCK_RAW, 0x1f /* NETLINK_??? */) = 3
0.000055 bind(3, {sa_family=AF_NETLINK, nl_pid=1163, nl_groups=00000000}, 12) = -1 EADDRINUSE (Address already in use)
0.000137 brk(NULL) = 0x82f000
0.000038 brk(0x850000) = 0x850000
0.000056 sendmsg(3, {msg_name=0xcffd6da38, msg_namelen=-2696656, msg_iov=NULL, msg_iovlen=0, msg_control=0xf72b9d7400090dd4, msg_controllen=3505436194745028, msg_flags=MSG_WAITALL|MSG_FIN|MSG_CONFIRM|MSG_RST|MSG_NOSIGNAL|MSG_MORE|MSG_SENDPAGE_NOTLAST|MSG_BATCH|MSG_ZEROCOPY|MSG_FASTOPEN|MSG_CMSG_CLOEXEC|MSG_CMSG_COMPAT|0x1bd00000}, 0) = 36
0.000148 recvmsg(3,
#!/bin/sh
trap '' HUP INT QUIT ABRT TERM
(i="0"
while true; do
i="$(( i + 1 ))";
for nv in 1 2 3 4 5; do
unset "state${nv}";
[ "$(ps -T | grep "nvram get" | wc -l )" -le "1" ] && eval "state${nv}"="$(/bin/nvram get vpn_client${nv}_state)";
done
clear
echo "$state1" "$state2" "$state3" "$state4" "$state5"
echo "$i"
done) > /tmp/mynvramerror.log 2>&1 &
exit 0
I figured you were going to go into lock file semantics, but mine are much simpler. However here we are talking about concurrent runs of nvram from separate parents and process's. therefore wouldn't our lock need to be applied to nvram process itself and not just the wrapper for one parent process?Here's an example of an nvram wrapper. Realize I quite literally threw this together a few minutes ago. So it might need some refinement. But I just wanted to provide a quick-n-dirty example.
Bash:#!/bin/sh # copy original nvram executable to /tmp cp /usr/sbin/nvram /tmp/_nvram # create nvram wrapper that calls original nvram executable in /tmp cat << 'EOF' > /tmp/nvram #!/bin/sh #set -x # comment/uncomment to disable/enable debug mode # required for serialization when reentry is possible LOCK="/tmp/$(basename $0).lock" acquire_lock() { until mkdir $LOCK &>/dev/null; do sleep 2; done; } release_lock() { rmdir $LOCK &>/dev/null; } # one instance at a time acquire_lock # catch premature exit and cleanup trap 'release_lock; exit 1' SIGHUP SIGINT SIGTERM /tmp/_nvram $@ rc=$? # any concurrent instance(s) may now run release_lock exit $rc EOF chmod +x /tmp/nvram # replace nvram in /usr/sbin w/ nvram wrapper in /tmp mount -o bind /tmp/nvram /usr/sbin/nvram
The idea is to FORCE every reference to the nvram executable threw the above script, which enforces one-at-a-time semantics.
I figured you were going to go into lock file semantics, but mine are much simpler. However here we are talking about concurrent runs of nvram from separate parents and process's. therefore wouldn't our lock need to be applied to nvram process itself?
That is if we account for the path of nvram to be to the serialized process? Help me here I am only trying to understand. I use something similar to manage one of my loops.If the parent process (nvram script) is serialized, then so is the child process (nvram executable).
AdGuardHome_Run () {
local lock_dir
local pid_file
lock_dir="/tmp/AdGuardHome"
pid_file="${lock_dir}/pid"
if ( mkdir ${lock_dir} ) 2> /dev/null; then
printf "%s\n" "$$" > $pid_file
trap 'rm -rf "$lock_dir"; exit $?' EXIT
start="$(date +%s)"
$1
end="$(date +%s)"
runtime="$((end-start))"
logger -st "$NAME" "$1 took $runtime second(s) to complete."
rm -rf "$lock_dir"
else
logger -st "$NAME" "Lock owned by $(cat $pid_file) exists; preventing duplicate runs!"
fi
}
Code:AdGuardHome_Run () { local lock_dir local pid_file lock_dir="/tmp/AdGuardHome" pid_file="${lock_dir}/pid" if ( mkdir ${lock_dir} ) 2> /dev/null; then printf "%s\n" "$$" > $pid_file trap 'rm -rf "$lock_dir"; exit $?' EXIT start="$(date +%s)" $1 end="$(date +%s)" runtime="$((end-start))" logger -st "$NAME" "$1 took $runtime second(s) to complete." rm -rf "$lock_dir" else logger -st "$NAME" "Lock owned by $(cat $pid_file) exists; preventing duplicate runs!" fi }
Now you are being more precise. I appreciate it. You cleared it up more.That is if we account for the path of nvram to be to the serialized process? Help me here I am only trying to understand. I use something similar to manage one of my loops.
What I'm serializing is the ability to create the lock, which is the directory /tmp/nvram.lock. That's an atomic operation.
I use a similar method to limit how many times my adguardhome can be called to start from a loop. I only wish the routers allowed trapping of the 'ERR'That is if we account for the path of nvram to be to the serialized process? Help me here I am only trying to understand. I use something similar to manage one of my loops.
What I'm serializing is the ability to create the lock, which is the directory /tmp/nvram.lock. That's an atomic operation.
Well, that's a weird one... not quite sure if it worked correctly or not... but for most of the log, each line was blank... Every so often, you would see an indication that it tried to do an nvram get call:@Viktor Jaep if you are up for one more test then here is an interesting one to test concurrency.
Code:#!/bin/sh trap '' HUP INT QUIT ABRT TERM (i="0" while true; do i="$(( i + 1 ))"; for nv in 1 2 3 4 5; do unset "state${nv}"; [ "$(ps -T | grep "nvram get" | wc -l )" -le "1" ] && eval "state${nv}"="$(/bin/nvram get vpn_client${nv}_state)"; done clear echo "$state1" "$state2" "$state3" "$state4" "$state5" echo "$i" done) > /tmp/mynvramerror.log 2>&1 & exit 0
maybe the CPU timing is wrong.. Something is seriously wrong if it cannot get past that.Well, that's a weird one... not quite sure if it worked correctly or not... but for most of the log, each line was blank... Every so often, you would see an indication that it tried to do an nvram get call:
View attachment 41881
#!/bin/sh
trap '' HUP INT QUIT ABRT TERM
(i="0"
while true; do
i="$(( i + 1 ))";
for nv in 1 2 3 4 5; do
unset "state${nv}";
[ "$(ps -T | grep "nvram get" | wc -l )" -le "2" ] && eval "state${nv}"="$(/bin/nvram get vpn_client${nv}_state)";
done
clear
echo "$state1" "$state2" "$state3" "$state4" "$state5"
echo "$i"
done) > /tmp/mynvramerror.log 2>&1 &
exit 0
#!/bin/sh
trap '' HUP INT QUIT ABRT TERM
(i="0"
until [ "$(ps -T | grep "nvram get" | wc -l )" -gt "2" ]; do
i="$(( i + 1 ))";
for nv in 1 2 3 4 5; do
unset "state${nv}";
[ "$(ps -T | grep "nvram get" | wc -l )" -le "2" ] && eval "state${nv}"="$(/bin/nvram get vpn_client${nv}_state)";
done
clear
echo "$state1" "$state2" "$state3" "$state4" "$state5"
echo "$i"
done) > /tmp/mynvramerror.log 2>&1 &
exit 0
Welcome To SNBForums
SNBForums is a community for anyone who wants to learn about or discuss the latest in wireless routers, network storage and the ins and outs of building and maintaining a small network.
If you'd like to post a question, simply register and have at it!
While you're at it, please check out SmallNetBuilder for product reviews and our famous Router Charts, Ranker and plenty more!