Output ordering not always the same

Question

Context

I finally fixed my issue to have stdout & stderr to screen and a file plus having a separate file for the errors. See: Output stdout and stderr to file and screen and stderr to file in a limited environment

Issue

The problem is the ordering of lines.

Some times it is OK:

FIRST
ERROR
LAST
ERROR2
LAST2

Some times the errors are at the end:

FIRST
LAST
LAST2
ERROR
ERROR2

I can't figure out why (except maybe a semaphore underneath that... but... not sure. And if it is the case, there is no solution exception adding line numbers to each echo).

Part of the code where the problem occurs

{ "$0" "${mainArgs[@]}" 2>&1 1>&3 | tee -a "$logPath/$logFileName.err" 1>&3 ; } 3>&1 | tee -a "$logPath/$logFileName.log" &

Full testable code

m=0
declare -a mainArgs
if [ ! "$#" = "0" ]; then
    for arg in "$@"; do
        mainArgs[$m]=$arg
        m=$(($m + 1))
    done
fi

function containsElement()
# $1 string to find
# $2 array to search in
# return 0 if there is a match, otherwise 1
{
  local e match="$1"
  shift
  for e; do [[ "$e" == "$match" ]] && return 0; done
  return 1
}

function hasMainArg()
# $1 string to find
# return 0 if there is a match, otherwise 1
{
    local match="$1"
    containsElement "$1" "${mainArgs[@]}"
    return $?
}

function activateLogs()
# $1 = logOutput: What is the output for logs: SCREEN, DISK, BOTH. Default is DISK. Optional parameter.
{
    local logOutput=$1
    if [ "$logOutput" != "SCREEN" ] && [ "$logOutput" != "BOTH" ]; then
        logOutput="DISK"
    fi
    
    if [ "$logOutput" = "SCREEN" ]; then
        echo "Logs will only be output to screen"
        return
    fi
    
    hasMainArg "--force-log"
    local forceLog=$?
        
    local isFileDescriptor3Exist=$(command 2>/dev/null >&3 && echo "Y")
    
    if [ "$isFileDescriptor3Exist" = "Y" ]; then
        echo "Logs are configured"
    elif [ "$forceLog" = "1" ] && ([ ! -t 1 ] || [ ! -t 2 ]); then
        # Use external file descriptor if they are set except if having "--force-log"
        echo "Logs are configured externally"
    else
        echo "Relaunching with logs files"
        local logPath="logs"
        if [ ! -d $logPath ]; then mkdir $logPath; fi
        
        local logFileName=$(basename "$0")"."$(date +%Y-%m-%d.%k-%M-%S)
    
        exec 4<> "$logPath/$logFileName.log" # File descriptor created only to get the underlying file in any output option
        if [ "$logOutput" = "DISK" ]; then
            # FROM: https://stackoverflow.com/a/45426547/214898
            exec 3<> "$logPath/$logFileName.log"
            "$0" "${mainArgs[@]}" 2>&1 1>&3 | tee -a "$logPath/$logFileName.err" 1>&3 &
        else
            # FROM: https://stackoverflow.com/a/70790574/214898
            { "$0" "${mainArgs[@]}" 2>&1 1>&3 | tee -a "$logPath/$logFileName.err" 1>&3 ; } 3>&1 | tee -a "$logPath/$logFileName.log" &
        fi
        
        exit        
    fi
}

#activateLogs "DISK"
#activateLogs "SCREEN"
activateLogs "BOTH"


echo "FIRST"
echo "ERROR" >&2
echo "LAST"
echo "ERROR2" >&2
echo "LAST2"

score 0 · Answer 1 · answered Feb 20 '22 at 21:31

0

Stdout 1 and errout 2 pass by different file descriptors. If is very busy then very close calls like these can get mixed up.
You could use sleep 1 between your calls which would give the system time to process each call in order, but would slow down your script.
You can sleep less than a second : for example sleep 0.5.

answered Feb 20 '22 at 21:31

That’s a good idea, but I am not sure it would fix it definitely. I mean that the sleeping time seems pretty much arbitrary. Don’t you think? – Master DJon Feb 21 '22 at 00:29

Output ordering not always the same

1 Answers1