What's new

Found a strange behavior of script running with crontab cru on ac86u and ax86u 386.3_2

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

MissingTwins

Regular Contributor
Model ac86u ax86u 386.3_2
I'm trying to run a IPv6 to IPv4 port forwarding script, but I'm running into problems that related to crontab.
cru a RdpIPv6Daemon "*/1 * * * * /jffs/scripts/rdp-ipv6-mapping.sh"

When the script is run for the 1st time it producing these logs, because iptables rule and socat processes don't exist yet.
Bash:
Oct 31 02:59:00 rdp-ipv6-mapping.sh: Process not found socat TCP6-LISTEN:11111,fork TCP4:192.168.5.5:3389
Oct 31 02:59:03 rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 02:59:03 rdp-ipv6-mapping.sh: Success ip6tables -I INPUT -i ppp+ -p tcp --dport 11111 -j ACCEPT
Oct 31 02:59:03 rdp-ipv6-mapping.sh: Success ip6tables -I INPUT -i ppp+ -p udp --dport 11111 -j ACCEPT
Oct 31 02:59:03 rdp-ipv6-mapping.sh: Success ip6tables -I INPUT -i eth+ -p tcp --dport 11111 -j ACCEPT
Oct 31 02:59:03 rdp-ipv6-mapping.sh: Success ip6tables -I INPUT -i eth+ -p udp --dport 11111 -j ACCEPT

But when this script gets run for the 2nd time no log should be generated, because both iptables and socat processes should be existing. But it keeps telling me that socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389 doesn't exist every minute.
Bash:
Oct 31 01:23:01 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat TCP6-LISTEN:11111,fork TCP4:192.168.5.5:3389
Oct 31 01:23:01 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:24:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:25:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:26:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:27:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:28:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:29:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:30:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:31:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:32:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:33:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:34:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:35:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:36:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:37:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
Oct 31 01:38:00 RT-AX86U-14F8-9B47D4C-C rdp-ipv6-mapping.sh: Process not found socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389

Even more interesting is when I did this and watched socat in the htop, the log was still showing socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389 didn't exist.
Bash:
socat TCP6-LISTEN:11111,fork TCP4:192.168.5.5:3389 &
socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389 &
cru a RdpIPv6Daemon "*/1 * * * * /jffs/scripts/rdp-ipv6-mapping.sh"

The if [ $? != 0 ]; then in the 2nd call of psCHK() will always be true, even I have changed it into if [ -z "$RE" ]; then it is still testing true.

If I do this echo "$PS_LIST" > /tmp/ps_list_`sed 's/[. ].*//' /proc/uptime`.txt in psCHK() only one /tmp/ps_list_xxxx.txt will be generated every time, should be two.

I have checked the /tmp/ps_list_xxxx.txt` with `cat /tmp/ps_list_xxxx.txt | grep -i "socat" | grep -v grep, socat was in the ps list.
Bash:
15673 router    2544 S    socat TCP6-LISTEN:11111,fork TCP4:192.168.5.5:3389
15690 router    2544 S    socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389
If I ran my script manully or with while true; do /jffs/scripts/rdp-ipv6-mapping.sh ; sleep 5; done for testing, it was functioning normally as expected.

What I am doing wrong? I have no idea.
I'm lso trying to keep the child process running even after the parent process get killed with ( $CMD_STR & ), but it doesn't work.

Bash:
#!/bin/bash

# Log Tag
LOG_TAG=`basename "$0"`
echo "LOG_TAG=$LOG_TAG"

# -----------------------------------------
# Example : sysLOG "We have a problem!" error
# Argu    : $1 logs
#           $2 error/notice/warning
# Input   : None
# Return  : None
function sysLOG() {
    echo "$1" | tee /dev/tty | tr -d '\n' | logger -t $LOG_TAG -p user.$2;

}

# -----------------------------------------
# Example : psCHK "socat TCP6-LISTEN:11111,fork TCP4:192.168.5.5:3389"
# Argu    : $1 command
# Input   : None
# Return  : None
function psCHK() {
    local PS_CMD PS_LIST CMD_STR
    CMD_STR=$1
    ps aux  &>/dev/null
    [ $? != 0 ] && PS_CMD="ps" || PS_CMD="ps aux"
    PS_LIST=$( $PS_CMD 2>&1 )
    #echo "$PS_LIST" > /tmp/ps_list_`sed 's/[. ].*//' /proc/uptime`.txt
    RE=$( echo -n "$PS_LIST"  | grep -Fi "$CMD_STR" | grep -v grep )
    #echo -n "$PS_LIST"  | awk '$0 ~ /awk/{next} $0 ~ /'"$CMD_STR"'/{ print $0; err=0; exit} BEGIN{err=1} END{exit err}'
#=========================PROBLEM IS HERE=====================
   #if [ $? != 0 ]; then
    if [ -z "$RE" ]; then
        sysLOG "Process not found $CMD_STR" warning
        ( $CMD_STR & )
        sleep 1;
    #    PS_LIST=$( $PS_CMD 2>&1 )
    #    echo -n "$PS_LIST"  | grep -Fi "$CMD_STR" | grep -v grep
    #    [ $? != 0 ] && sysLOG "Launch Failed $CMD_STR" error || sysLOG "Started $CMD_STR" notice
    fi
}

# -----------------------------------------
# Example : ip6tablesINS "INPUT -i ppp+ -p tcp --dport 11111 -j ACCEPT"
# Argu    : $1 ip6tables-rules
# Input   : None
# Return  : None
function ip6tablesINS() {

    local reRAW RECODE
    reRAW=$( ip6tables -C $1 2>&1 )
    RECODE=$?
    reRAW=$( echo -n "$reRAW" | head -n 1  )
    # echo "=$RECODE |$1 | RE="$reRAW
    if [ $RECODE -ge 2 ]; then
        sysLOG "ip6tables -I $1 Err=$reRAW" error
    elif [ $RECODE -eq 1 ]; then
        ip6tables -I $1
        [ $? != 0 ] && sysLOG "Error ip6tables -I $1" error || sysLOG "Success ip6tables -I $1" notice
    fi
}

# Redirect TCP/UDP IPv6 11111 to IPv4 192.168.5.5: 3389
psCHK "socat TCP6-LISTEN:11111,fork TCP4:192.168.5.5:3389"
psCHK "socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.5.5:3389"

# ip6tables
ip6tablesINS "INPUT -i ppp+ -p tcp --dport 11111 -j ACCEPT"
ip6tablesINS "INPUT -i ppp+ -p udp --dport 11111 -j ACCEPT"

ip6tablesINS "INPUT -i eth+ -p tcp --dport 11111 -j ACCEPT"
ip6tablesINS "INPUT -i eth+ -p udp --dport 11111 -j ACCEPT"

Tested the same script with crontab on RPI4B ubuntu 20.04, no problem at all. It must be something wrong with the cru, a bug?
 
Last edited:
I did another experiment, abstracting log from cru
cru a RdpIPv6Daemon "*/1 * * * * /opt/etc/rdp-ipv6-mapping.sh >>/tmp/RdpIPv6Daemon.log 2>&1"

I made some changes in psCHK().
Bash:
function psCHK() {
    printf "\nEntering $1\n"
    local PS_CMD PS_LIST CMD_STR
    CMD_STR=$1
    ps aux  &>/dev/null
    [ $? != 0 ] && PS_CMD="ps" || PS_CMD="ps aux"
    PS_LIST=$( $PS_CMD 2>&1 )
    #echo "$PS_LIST" > /tmp/ps_list_`sed 's/[. ].*//' /proc/uptime`.txt
    printf "PS_LIST=${#PS_LIST}\n"
#=======PROBLEM IS HERE grep and awk=======
    echo -n "$PS_LIST"  | grep -Fi "$CMD_STR"
    echo -n "$PS_LIST"  | awk '$0 ~ /awk/{next} $0 ~ /'"$CMD_STR"'/{ print $0"<--awk"; err=0; exit} BEGIN{err=1} END{exit err}'
    RE=$( echo -n "$PS_LIST"  | grep -Fi "$CMD_STR" | grep -v grep )
    if [ -z "$RE" ]; then
        sysLOG "Process not found $CMD_STR" warning
        ( $CMD_STR &  <&- >&- 2>&- & )
    fi
    printf "Exiting $1\n"
}

Let's see the log.
1st psCHK() run we got PS_LIST=7867
2nd psCHK() run we got PS_LIST=7741
That means the ps command was OK, and we got the result.

1st psCHK() run, both grep and awk printed out the positive search results.
2nd psCHK() run, both grep and awk produced nothing.
That's super weird. What's going on?

Please ignore the differences between 192.168.9.5 and 192.168.5.5, that's because of I tested this code on different routers.
Bash:
tail -F /tmp/RdpIPv6Daemon.log

LOG_TAG=rdp-ipv6-mapping.sh Sun Oct 31 20:01:00 UCT 2021
Entering socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389
PS_LIST=7867
25734 router    2524 S    socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389
25734 router    2524 S    socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389<--awk
Exiting socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389\n

#=======PROBLEM IS HERE grep and awk=======
Entering socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9.5:3389
PS_LIST=7741
tee: /dev/tty: No such device or address
2021/10/31 20:01:01 socat[11520] E bind(5, {AF=10 [0000:0000:0000:0000:0000:0000:0000:0000]:11111}, 28): Address already in use
Exiting socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9.5:3389\n
 
Last edited:
ps aux is not a valid Asus router command. If it works for you from an interactive command prompt that will be because you've installed the Entware version of ps. It is unlikely Entware will be in the PATH used by scripts invoked by cron.

Side note: It's inadvisable to "echo" output to stdout from cron scripts because there in no terminal attached. Either don't do it or redirect stdout/stderr to a file.
 
ps aux is not a valid Asus router command. If it works for you from an interactive command prompt that will be because you've installed the Entware version of ps.
Thank you for replying.

Yes I know ps aux is not a valid command for merlin-wrt. And the exit code $? will tell me it's an invalid command. I did that to determine ps for router or ps aux for RPI4B, because I would like this code can be run on both devices.

Side note: It's inadvisable to "echo" output to stdout from cron scripts because there in no terminal attached. Either don't do it or redirect stdout/stderr to a file.
Thanks, I will look into that.

It is unlikely Entware will be in the PATH used by scripts invoked by cron.
Actually it can access Entware bins from cru, it is functioning normally as far as I have tested.

And if Entware failed in cru, grep should be working. None of this make sense.
 
Last edited:
Why don’t you log $RE to see what’s in it when it fails?

Edit: never mind, it‘s empty. :rolleyes:
 
Why don’t you log $RE to see what’s in it when it fails?
I have done that, it returns nothing.
Did you noticing my second post? Right below #=======PROBLEM IS HERE grep and awk=======
Both these two produced nothing.
echo -n "$PS_LIST" | grep -Fi "$CMD_STR"
echo -n "$PS_LIST" | awk '$0 ~ /awk/{next} $0 ~ /'"$CMD_STR"'/{ print $0"<--awk"; err=0; exit} BEGIN{err=1} END{exit err}'
If there were anything it should be like this, since the UDP6 in the 2nd call of psCHK(), and it has never succeeded.
25734 router 2524 S socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9.5:3389
25734 router 2524 S socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9.5:3389<--awk
 
I don’t fully understand the need for the complicated awk code. Most people are happy to ps | grep socat. Trying to port bash to ash can be troublesome.

Putting ps into a variable gives a big mess without line breaks.
 
I don’t fully understand the need for the complicated awk code. Most people are happy to ps | grep socat. Trying to port bash to ash can be troublesome.

Putting ps into a variable gives a big mess without line breaks.
Since grep doesn't work properly, so I have to make alternative awk for testing.

awk '$0 ~ /awk/{next} $0 ~ /'"$CMD_STR"'/{ print $0"<--awk"; err=0; exit} BEGIN{err=1} END{exit err}'
Basically equals to this
Code:
err=1;
FOR (each line) {
   IF (this line contains word 'awk') THEN skip this line;
   IF (this line contains 'socat bla bla bla') THEN
        print this line;
        err=0;
        exit awk;
   END IF;
}
RETURN err;
 
Last edited:
Since grep doesn't work properly, so I have to make alternative awk for testing.

awk '$0 ~ /awk/{next} $0 ~ /'"$CMD_STR"'/{ print $0"<--awk"; err=0; exit} BEGIN{err=1} END{exit err}'
Basically equals to this
Code:
err=1;
FOR (each line) {
   IF (this line contains word 'awk') THEN skip this line;
   IF (this line contains 'socat bla bla bla') THEN
        print this line;
        err=0;
        exit awk;
   END IF;
}
RETURN err;
But it’s all one line when put in the PS_LIST variable. So if awk is running, it will skip the whole output, no?
 
But it’s all one line when put in the PS_LIST variable. So if awk is running, it will skip the whole output, no?
Since the grep didn't work in the 2nd call of psCHK() , and the awk also failed, there must be some malfunctioning.

I just don't get it, why the 1st call of psCHK() worked, but the 2nd call didn't. And I can see both socat in the htop, but grep and awk didn't recognize them.
 
Bash:
function psCHK() {
    printf "\nEntering $1\n"
    local PS_CMD PS_LIST CMD_STR KEY_WORD
    CMD_STR=$1
    KEY_WORD=$( printf "$1" | awk -F',' '{print $1}' )
    ps aux  &>/dev/null
    [ $? != 0 ] && PS_CMD="ps" || PS_CMD="ps aux"
    PS_LIST=$( $PS_CMD 2>&1 )
    #echo "$PS_LIST" > /tmp/ps_list_`sed 's/[. ].*//' /proc/uptime`.txt
    printf "KEY_WORD=$KEY_WORD PS_LIST=${#PS_LIST}\n"
    printf "$PS_LIST"  | grep -Fi "$CMD_STR"
    printf "$PS_LIST"  | grep -Fi "$KEY_WORD"
    printf "$PS_LIST"  | awk '$0 ~ /awk/{next} $0 ~ /'"$KEY_WORD"'/{ print $0"<--awk"; err=0; exit} BEGIN{err=1} END{exit err}'
    printf "$PS_LIST"  | awk '$0 ~ /awk/{next} $0 ~ /'"$KEY_WORD"'/{ print $0"<--awk-keyword"; err=0; exit} BEGIN{err=1} END{exit err}'
    #RE=$( printf "$PS_LIST"  | grep -Fi "$CMD_STR" | grep -v grep )
    RE=$( printf "$PS_LIST"  | grep -Fi "$KEY_WORD" | grep -v grep )
    if [ -z "$RE" ]; then
        sysLOG "Process not found $CMD_STR" warning
        ( $CMD_STR &  <&- >&- 2>&- & )
    #    sleep 1;
    #    PS_LIST=$( $PS_CMD 2>&1 )
    #    echo -n "$PS_LIST"  | grep -Fi "$CMD_STR" | grep -v grep
    #    [ $? != 0 ] && sysLOG "Launch Failed $CMD_STR" error || sysLOG "Started $CMD_STR" notice
    fi
    printf "Exiting $1\n"
}

I have made another change to the grep KEY_WORD, only needs to match text before the comma socat TCP6-LISTEN:11111 this time grep can match. I think there must be some characters after comma causing grep mismatched.

cru a RdpIPv6Daemon "*/1 * * * * /opt/etc/rdp-ipv6-mapping.sh >>/tmp/RdpIPv6Daemon.log 2>&1"
Did this, port number 3389 is missing in UDP clause.
Bash:
LOG_TAG=rdp-ipv6-mapping.sh Sun Oct 31 23:08:00 UCT 2021
Entering socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389
KEY_WORD=socat TCP6-LISTEN:11111 PS_LIST=7867
25734 router    2524 S    socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389
25734 router    2524 S    socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389
25734 router    2524 S    socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389<--awk
25734 router    2524 S    socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389<--awk-keyword
Exiting socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389

Entering socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9.5:3389
KEY_WORD=socat UDP6-RECVFROM:11111 PS_LIST=7741
25758 router    2524 S    socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9
25758 router    2524 S    socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9<--awk
25758 router    2524 S    socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9<--awk-keyword
Exiting socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9.5:3389

> /opt/etc/rdp-ipv6-mapping.sh >>/tmp/RdpIPv6Daemon.log 2>&1
Did this, port number 3389 is intact in UDP clause.
Bash:
LOG_TAG=rdp-ipv6-mapping.sh Sun Oct 31 23:22:52 JST 2021
Entering socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389
KEY_WORD=socat TCP6-LISTEN:11111 PS_LIST=7816
25734 router    2524 S    socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389
25734 router    2524 S    socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389
25734 router    2524 S    socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389<--awk
25734 router    2524 S    socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389<--awk-keyword
Exiting socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389

Entering socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9.5:3389
KEY_WORD=socat UDP6-RECVFROM:11111 PS_LIST=7816
25758 router    2524 S    socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9.5:3389
25758 router    2524 S    socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9.5:3389
25758 router    2524 S    socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9.5:3389<--awk
25758 router    2524 S    socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9.5:3389<--awk-keyword
Exiting socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9.5:3389


I think I have found the problem, it is very unique only triggered with cru task.
Do you see the port number is missing in UDP grep returns.
TCP socat TCP6-LISTEN:11111,fork TCP4:192.168.9.5:3389 and
UDP socat UDP6-RECVFROM:11111,fork UDP4-SENDTO:192.168.9
 
Bash:
> ps -h
ps: invalid option -- 'h'
BusyBox v1.25.1 (2021-08-06 17:48:21 EDT) multi-call binary.

Usage: ps

Show list of processes

        w       Wide output
        T       Show threads

I blame the Wide output. :rolleyes:
Changed ps into ps -w, problem solved.

Bash:
[ $? != 0 ] && PS_CMD="ps -w" || PS_CMD="ps aux"
 

Latest threads

Sign Up For SNBForums Daily Digest

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