What's new

My experience with the RT-AC86U

  • 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!

No. :)
The test output is still messed. I figured it out, it receives 0 0 instead of 0 because nvram get runs twice.
The system log changed a bit - there's an occasional 0 in there somehow, the rest is rc=1.

And you made sure you started everything fresh on each of your test? Meaning you updated scripts and ended old test runs. And started completely new test runs between file edits?
 
I run umount /bin/nvram after each test and start over.
Maybe go back to the first version and look for a different IF condition? I don't quite understand why the test output gets like this but we are now re-running nvram get every time, not only on errors.
 
@Oracle this one should allow for a proper retry.

Code:
#!/bin/sh

# copy original nvram executable to /tmp
cp /bin/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

run_cmd () {
    local to
    local start
    local child
    to=$1; shift
    $@ & local child=$! start=0
    usleep 1000
     while [ "$(kill -0 $child >/dev/null 2>&1; printf "%s" "$?")" = "0" ]; do
        start=$((start+1))
        if [ $start -ge $to ]; then
            kill -s 9 $child 2>/dev/null
            return 1
        fi
    done
    return 0
}

# make the new function accessible

run_cmd 1 /tmp/_nvram $@
rc=$?

#echo "$rc" >> /tmp/nvram.log

if [ "$rc" != "0" ]; then
   #echo "$rc" >> /tmp/nvram.log
   unset rc
   usleep 1000
   logger -t "nvram-override" "Couldn't execute nvram $@, exit status: $rc (124=timeout)"
   run_cmd 1 /tmp/_nvram $@
   rc=$?
   logger -t "nvram-override" "Retried executing nvram $@, exit status: $rc"
fi

exit $rc
EOF
chmod +x /tmp/nvram

# replace nvram in /usr/sbin w/ nvram wrapper in /tmp
mount -o bind /tmp/nvram /bin/nvram


Note I just edited it because there should have been a 0 in place of the 1
 
Last edited:
Well, the test output comes out again in 2 columns of 0s and the system log indicates it is retrying every time. Seems rc is now empty and after retry becomes 1.
This is a single iteration of the test loop:
Jun 16 20:12:43 nvram-override: Couldn't execute nvram get vpn_client1_state, exit status: (124=timeout)
Jun 16 20:12:43 nvram-override: Retried executing nvram get vpn_client1_state, exit status: 1
Jun 16 20:12:43 nvram-override: Couldn't execute nvram get vpn_client2_state, exit status: (124=timeout)
Jun 16 20:12:43 nvram-override: Retried executing nvram get vpn_client2_state, exit status: 1
Jun 16 20:12:43 nvram-override: Couldn't execute nvram get vpn_client3_state, exit status: (124=timeout)
Jun 16 20:12:43 nvram-override: Retried executing nvram get vpn_client3_state, exit status: 1
Jun 16 20:12:44 nvram-override: Couldn't execute nvram get vpn_client4_state, exit status: (124=timeout)
Jun 16 20:12:44 nvram-override: Retried executing nvram get vpn_client4_state, exit status: 1
Jun 16 20:12:44 nvram-override: Couldn't execute nvram get vpn_client5_state, exit status: (124=timeout)
Jun 16 20:12:44 nvram-override: Retried executing nvram get vpn_client5_state, exit status: 1
 
Well, the test output comes out again in 2 columns of 0s and the system log indicates it is retrying every time. Seems rc is now empty and after retry becomes 1.
This is a single iteration of the test loop:
I edited the if statement, make sure you are using the one where the if statement equals zero and not 1.
 
Here's the latest version tested that gave me unwanted output:
Bash:
#!/bin/sh

# copy original nvram executable to /tmp
cp /bin/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

run_cmd () {
    local to
    local start
    local child
    to=$1; shift
    $@ & local child=$! start=0
     while [ "$(kill -0 $child >/dev/null 2>&1; printf "%s" "$?")" = "0" ]; do
        usleep 1000
        start=$((start+1))
        if [ $start -ge $to ]; then
            kill -s 9 $child 2>/dev/null
            return 1
        fi
    done
    return 0
}

# make the new function accessible

run_cmd 1 /tmp/_nvram $@
rc=$?

#echo "$rc" >> /tmp/nvram.log

if [ "$rc" != "0" ]; then
   #echo "$rc" >> /tmp/nvram.log
   unset rc
   usleep 1000
   logger -t "nvram-override" "Couldn't execute nvram $@, exit status: $rc (124=timeout)"
   run_cmd 1 /tmp/_nvram $@
   rc=$?
   logger -t "nvram-override" "Retried executing nvram $@, exit status: $rc"
fi

exit $rc
EOF
chmod +x /tmp/nvram

# replace nvram in /usr/sbin w/ nvram wrapper in /tmp
mount -o bind /tmp/nvram /bin/nvram
 
Here's the latest version tested that gave me unwanted output:
Bash:
#!/bin/sh

# copy original nvram executable to /tmp
cp /bin/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

run_cmd () {
    local to
    local start
    local child
    to=$1; shift
    $@ & local child=$! start=0
     while [ "$(kill -0 $child >/dev/null 2>&1; printf "%s" "$?")" = "0" ]; do
        usleep 1000
        start=$((start+1))
        if [ $start -ge $to ]; then
            kill -s 9 $child 2>/dev/null
            return 1
        fi
    done
    return 0
}

# make the new function accessible

run_cmd 1 /tmp/_nvram $@
rc=$?

#echo "$rc" >> /tmp/nvram.log

if [ "$rc" != "0" ]; then
   #echo "$rc" >> /tmp/nvram.log
   unset rc
   usleep 1000
   logger -t "nvram-override" "Couldn't execute nvram $@, exit status: $rc (124=timeout)"
   run_cmd 1 /tmp/_nvram $@
   rc=$?
   logger -t "nvram-override" "Retried executing nvram $@, exit status: $rc"
fi

exit $rc
EOF
chmod +x /tmp/nvram

# replace nvram in /usr/sbin w/ nvram wrapper in /tmp
mount -o bind /tmp/nvram /bin/nvram
Try again, this time I edited where the placement of usleep was.
 
Maybe you got the right order this time. :)
The loop shows the expected output, it's just moving slowly.

I'll let it run, take a break and report later.
 
I did a few test runs. So far the output is all good. No stuck commands and no missing values.

Here are some averages per 3,000 iterations (15,000 nvram commands) over several runs:
1. clean nvram (getting stuck): < 2 min but it rarely reaches 3,000
2. nvram override using timeout addon: ~2:30 min
3. nvram override using timeout and keeping usage count: ~3 min
4. nvram override not using timeout and no usage statistics: > 4 min
The last runs with usleep 1000 include sleep time of 1 millisecond. That's 15 sec for 15,000 nvram commands - negligible.

I'd move the unset rc after the first logger message, now it shows no value.

I'm happy that now we have an alternative that doesn't require installing extra packages. The performance penalty is not terribly high.
 
Here are some averages per 3,000 iterations (15,000 nvram commands) over several runs:
1. clean nvram (getting stuck): < 2 min but it rarely reaches 3,000
2. nvram override using timeout addon: ~2:30 min
3. nvram override using timeout and keeping usage count: ~3 min
4. nvram override not using timeout and no usage statistics: > 4 min
The last runs with usleep 1000 include sleep time of 1 millisecond. That's 15 sec for 15,000 nvram commands - negligible.

I'm happy that now we have an alternative that doesn't require installing extra packages. The performance penalty is not terribly high.
If you wait a little bit I got some optimizations that may make it better. A couple of performance mods and what not. Just hard to do it from my cellphone at work.
 
If you wait a little bit I got some optimizations that may make it better. A couple of performance mods and what not. Just hard to do it from my cellphone at work.
You're doing this from a cellphone?
Hats off!

One more observation: there is an abnormally high number of retries. With the timeout function I saw 2-3 retry messages per test run (3000 loops). With latest code I see dozens per run.
Jun 16 21:55:05 nvram-override: Couldn't execute nvram get vpn_client2_state, exit status: 1 (124=timeout)
Jun 16 21:55:05 nvram-override: Retried executing nvram get vpn_client2_state, exit status: 0
Jun 16 21:55:11 nvram-override: Couldn't execute nvram get vpn_client5_state, exit status: 1 (124=timeout)
Jun 16 21:55:11 nvram-override: Retried executing nvram get vpn_client5_state, exit status: 0
Jun 16 21:55:29 nvram-override: Couldn't execute nvram get vpn_client4_state, exit status: 1 (124=timeout)
Jun 16 21:55:29 nvram-override: Retried executing nvram get vpn_client4_state, exit status: 0
Jun 16 21:55:29 nvram-override: Couldn't execute nvram get vpn_client1_state, exit status: 1 (124=timeout)
Jun 16 21:55:29 nvram-override: Retried executing nvram get vpn_client1_state, exit status: 0
Jun 16 21:55:55 nvram-override: Couldn't execute nvram get vpn_client2_state, exit status: 1 (124=timeout)
Jun 16 21:55:55 nvram-override: Retried executing nvram get vpn_client2_state, exit status: 0
Jun 16 21:55:57 nvram-override: Couldn't execute nvram get vpn_client2_state, exit status: 1 (124=timeout)
Jun 16 21:55:57 nvram-override: Retried executing nvram get vpn_client2_state, exit status: 0
Jun 16 21:55:59 nvram-override: Couldn't execute nvram get vpn_client2_state, exit status: 1 (124=timeout)
Jun 16 21:55:59 nvram-override: Retried executing nvram get vpn_client2_state, exit status: 0
Jun 16 21:56:05 nvram-override: Couldn't execute nvram get vpn_client4_state, exit status: 1 (124=timeout)
Jun 16 21:56:05 nvram-override: Retried executing nvram get vpn_client4_state, exit status: 0
Jun 16 21:56:11 nvram-override: Couldn't execute nvram get vpn_client2_state, exit status: 1 (124=timeout)
Jun 16 21:56:11 nvram-override: Retried executing nvram get vpn_client2_state, exit status: 0
Jun 16 21:56:14 nvram-override: Couldn't execute nvram get vpn_client4_state, exit status: 1 (124=timeout)
Jun 16 21:56:14 nvram-override: Retried executing nvram get vpn_client4_state, exit status: 0
Jun 16 21:56:25 nvram-override: Couldn't execute nvram get vpn_client1_state, exit status: 1 (124=timeout)
Jun 16 21:56:25 nvram-override: Retried executing nvram get vpn_client1_state, exit status: 0
Jun 16 21:56:35 nvram-override: Couldn't execute nvram get vpn_client2_state, exit status: 1 (124=timeout)
Jun 16 21:56:35 nvram-override: Retried executing nvram get vpn_client2_state, exit status: 0
Jun 16 21:56:37 nvram-override: Couldn't execute nvram get vpn_client5_state, exit status: 1 (124=timeout)
Jun 16 21:56:37 nvram-override: Retried executing nvram get vpn_client5_state, exit status: 0
Jun 16 21:56:39 nvram-override: Couldn't execute nvram get vpn_client4_state, exit status: 1 (124=timeout)
Jun 16 21:56:39 nvram-override: Retried executing nvram get vpn_client4_state, exit status: 0
Jun 16 21:56:41 nvram-override: Couldn't execute nvram get vpn_client3_state, exit status: 1 (124=timeout)
Jun 16 21:56:41 nvram-override: Retried executing nvram get vpn_client3_state, exit status: 0
Jun 16 21:57:04 nvram-override: Couldn't execute nvram get vpn_client2_state, exit status: 1 (124=timeout)
Jun 16 21:57:04 nvram-override: Retried executing nvram get vpn_client2_state, exit status: 1
Jun 16 21:57:06 nvram-override: Couldn't execute nvram get vpn_client1_state, exit status: 1 (124=timeout)
Jun 16 21:57:06 nvram-override: Retried executing nvram get vpn_client1_state, exit status: 0
Jun 16 21:57:11 nvram-override: Couldn't execute nvram get vpn_client2_state, exit status: 1 (124=timeout)
Jun 16 21:57:11 nvram-override: Retried executing nvram get vpn_client2_state, exit status: 0
Jun 16 21:57:23 nvram-override: Couldn't execute nvram get vpn_client2_state, exit status: 1 (124=timeout)
Jun 16 21:57:23 nvram-override: Retried executing nvram get vpn_client2_state, exit status: 0
Jun 16 21:57:25 nvram-override: Couldn't execute nvram get vpn_client5_state, exit status: 1 (124=timeout)
Jun 16 21:57:25 nvram-override: Retried executing nvram get vpn_client5_state, exit status: 0
Jun 16 21:57:27 nvram-override: Couldn't execute nvram get vpn_client2_state, exit status: 1 (124=timeout)
Jun 16 21:57:27 nvram-override: Retried executing nvram get vpn_client2_state, exit status: 0
Jun 16 21:57:28 nvram-override: Couldn't execute nvram get vpn_client2_state, exit status: 1 (124=timeout)
Jun 16 21:57:28 nvram-override: Retried executing nvram get vpn_client2_state, exit status: 0
Jun 16 21:57:37 nvram-override: Couldn't execute nvram get vpn_client3_state, exit status: 1 (124=timeout)
Jun 16 21:57:37 nvram-override: Retried executing nvram get vpn_client3_state, exit status: 0
Jun 16 21:57:39 nvram-override: Couldn't execute nvram get vpn_client2_state, exit status: 1 (124=timeout)
Jun 16 21:57:39 nvram-override: Retried executing nvram get vpn_client2_state, exit status: 0
Jun 16 21:57:48 nvram-override: Couldn't execute nvram get vpn_client1_state, exit status: 1 (124=timeout)
Jun 16 21:57:48 nvram-override: Retried executing nvram get vpn_client1_state, exit status: 0
Jun 16 21:57:55 nvram-override: Couldn't execute nvram get vpn_client4_state, exit status: 1 (124=timeout)
Jun 16 21:57:56 nvram-override: Retried executing nvram get vpn_client4_state, exit status: 0
 
You're doing this from a cellphone?
Hats off!

One more observation: there is an abnormally high number of retries. With the timeout function I saw 2-3 retry messages per test run (3000 loops). With latest code I see dozens per run.
The problem with loops are that they need their own form of rate limiting, usually a lock file of sorts. Otherwise there is no way to tell if you have stumbled onto a racing condition between competing processes spawned from the same loop. Hence one of the needs for optimization.
 
The problem with loops are that they need their own form of rate limiting, usually a lock file of sorts. Otherwise there is no way to tell if you have stumbled onto a racing condition between competing processes spawned from the same loop. Hence one of the needs for optimization.

Which makes me wonder if it might be *safer* to serialize access, even if it wasn't the source of the problem. I doubt the performance impact would be significant since the likelihood of concurrency is still small.
 
Which makes me wonder if it might be *safer* to serialize access, even if it wasn't the source of the problem. I doubt the performance impact would be significant since the likelihood of concurrency is still small.
Correct, I got something in mind already. I have been brewing it in my mind for the past couple of hours.
 
We can do both timeout and serialization and see how that impacts performance.
Although I'd say the last version I tested was not bad at all.
The test case is extreme - there won't be 15,000 nvram operations in 3 min under normal conditions.
 
We can do both timeout and serialization and see how that impacts performance.
Although I'd say the last version I tested was not bad at all.
The test case is extreme - there won't be 15,000 nvram operations in 3 min under normal conditions.
This one should prove to be pretty interesting...
Bash:
#!/bin/sh

# copy original nvram executable to /tmp
cp /bin/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
INTERVAL="100"
MAXCOUNT="3"
run_cmd () {
    local to
    local start
    local child
    # here as the number of tries required increases our usleep increases in case the sleep is not long enough.
    to="$1"
    to="$((to*INTERVAL))"; shift
    $@ & local child="$!" start=0
    usleep "$to"
    while { [ "$(kill -0 $child >/dev/null 2>&1; printf "%s" "$?")" = "0" ] && [ "$start" -le "$to" ]; }; do
        # to account for killing too soon, as the number of tries required increases our count requirement increases before we attempt to kill the process.
        usleep 1
        start="$((start+1))"
        if [ $start -gt $to ]; then
            kill -s 9 $child 2>/dev/null
            return 1
        fi
    done
    return 0
}

# make the new function accessible, on the first run we want to exit right away if successful.
i="1"
if { run_cmd "$i" /tmp/_nvram "$@"; }; then
  exit 0
fi
# here we add an interval check and allow up to 3 retries.
while [ "$i" -le "$MAXCOUNT" ]; do
  logger -t "nvram-override" "Waiting for NVRAM (retry attempt ${i}/${MAXCOUNT})"
  usleep $INTERVAL
  if { run_cmd "$i" /tmp/_nvram "$@"; }; then
    exit 0
  fi
  i="$((i+1))"
done
logger -t "nvram-override" "NVRAM remained locked too long; continuing anyway."
exit 1
EOF
chmod +x /tmp/nvram

# replace nvram in /usr/sbin w/ nvram wrapper in /tmp
mount -o bind /tmp/nvram /bin/nvram
 
Last edited:
Oh, boy! Here we go again. :)
Btw, my router executes dozens of nvram operations per hour. I'll check later what are those.
No wonder it takes a day or two to get one stuck.

This last one ran like a blaze but didn't pick anything. Completely empty output, no messages in the log.
 
Last edited:
Oh, boy! Here we go again. :)
Btw, my router executes dozens of nvram operations per hour. I'll check later what are those.
No wonder it takes a day or two to get one stuck.
Well this one should speed things with your nvram right along because we will not get stuck waiting forever with this one before we attempt a retry.
 
Oh, boy! Here we go again. :)
Btw, my router executes dozens of nvram operations per hour. I'll check later what are those.
No wonder it takes a day or two to get one stuck.

This last one ran like a blaze but didn't pick anything. Completely empty output, no messages in the log.
So you didn't see any of the

0 0 0 0

you wanted to see?
 

Similar threads

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