StdoutRead() stops returning anything and doesn't set @error

[VAN0]

I have a loop that executes rasdial.exe every second. This command line program shows if computer connected to a VPN or not.

What happens is after random time, StdoutRead() stops returning anything and doesn't set @error, this makes the loop that reads out the output essentially hang the script.

I've implemented a timeout that exits the loop after 5 seconds, which fixed total freeze, however I'd like to know what could cause the issue in the first place and how to avoid it.

 

expandcollapse popup

#include <Misc.au3>

Local $iPrevTime = 0

While 1
    Local $iNow = @YEAR & @MON & @MDAY & @HOUR & @MIN & @SEC
    If $iPrevTime + 1 < $iNow Then ;execute every second
        $iPrevTime = $iNow
        exec("rasdial")
    EndIf
    Sleep(100)
WEnd

Func debug($sText)
    ConsoleWrite(BinaryToString(StringToBinary($sText & @CRLF, 4), 1))
EndFunc   ;==>debug

Func exec($sCmd)
    Local $iNow = @YEAR & @MON & @MDAY & @HOUR & @MIN & @SEC
    Local $sOut = ""
    Local $iPID = Run($sCmd, "", @SW_HIDE, $STDERR_MERGED)
    debug(">" & $iNow & ": " & $sCmd & " [PID:" & $iPID & "]" & " error: " & @error)
    If $iPID Then
        Local $iTimeout = $iNow + 4 ;5 seconds iTimeout
        While 1
            $sOut &= StdoutRead($iPID)
            If @error Then ; Exit the loop if the process closes or StdoutRead returns an error.
                ExitLoop
            EndIf
            If @YEAR & @MON & @MDAY & @HOUR & @MIN & @SEC > $iTimeout Then
                debug("---Timeout")
                ExitLoop
            EndIf
        WEnd
        WinKill($iPID)
    EndIf
    debug($sOut)
    Return $sOut
EndFunc   ;==>exec

So far, my best issue-reproducing method is to run multiple scripts at once and connect/disconnect VPN connection. After 5-30 minutes one script instance might start throwing timeouts. Once its timeout, that script instance stops receiving StdoutRead() until script restart

I don't believe this is related to rasdial.exe itself, I've tried executing hundreds of them at once in powershell with rasdial;rasdial;rasdial;rasdial;rasdial;rasdial;rasdial;rasdial;rasdial;rasdial;rasdial ... they all return something.

 

[EDIT]

Replacing StdoutRead() loop with

ProcessWaitClose($iPID)
Local $sOut = StdoutRead($iPID)

Seems to fix the issue, however the script seems to be less responsive. (for example running exec("rasdial") twice would output smoothly when loop used, or with pauses with processWaitClose())

Any ideas?

Thank you.

Edited September 19, 2022 by VAN0

[rudi]

If you loop launch an external EXE to read its output, pls. take care to use

 

StdioClose($PID)

 

otherwise it will "eat up" your RAM every time you leave another call unclosed.

[VAN0]

Although I have not noticed increase of memory usage, `StdioClose($PID)` didn't help.

[rudi]

try this one:

 

expandcollapse popup

#include <Array.au3>
#include <Misc.au3>



$TimeOut = 4000 ; ms
Dim $aPIDs[0][2] ; col 0 takes the PID, col 1 the timer
Enum $iPID, $iStart
$LoopTimer = TimerInit()

While 1
    Do
        Sleep(100)
    Until TimerDiff($LoopTimer) > 1000
    $LoopTimer = TimerInit() ; reset loop timer to start a new instance every second
    $NxPID = Run("rasdial.exe", "",  @SW_HIDE, $STDERR_MERGED)
    $Str2Add = $NxPID & "|" & TimerInit()
    _ArrayAdd($aPIDs, $Str2Add)
    _CheckPIDs()
WEnd




Func _CheckPIDs()
    For $p = UBound($aPIDs) - 1 To 0 Step -1 ; stepping backward, _arrayDelete is easier that way
        $ThisPID = $aPIDs[$p][$iPID]
        $ThisRunning = TimerDiff($aPIDs[$p][$iStart])
        If ProcessExists($ThisPID) Then ; still running
            If $ThisRunning > $TimeOut Then ; running too long: Kill and get output
                ProcessClose($ThisPID)
                $Result = StdoutRead($ThisPID)
                StdioClose($ThisPID)
                ConsoleWrite("Process " & $ThisPID & " timed out after " & Round($ThisRunning) & " ms -- StdOutRead = '" & $Result & "'" & @CRLF)
                _ArrayDelete($aPIDs, $p) ; remove this row from the array
            Else
                ; go on waiting
            EndIf
        Else ; Process ended itself
            $Result = StdoutRead($ThisPID)
            StdioClose($ThisPID)
            ConsoleWrite("Process " & $ThisPID & " ended itself after " & Round($ThisRunning) & " ms -- StdOutRead = '" & $Result & "'" & @CRLF)
            _ArrayDelete($aPIDs, $p) ; remove this row from the array
        EndIf
    Next
EndFunc   ;==>_CheckPIDs

 

[VAN0]

The thing is, the rasdial.exe process does not hang, it ends almost instantly (when created a loop that exits when `ProcessExists($iPID)` returns 0, it exits after 2-3 loops), because of that your code will never "timeout".

It's the StdoutRead that supposed to set @error flag when EOF is reached or when other errors occur, but it doesn't, because nothing received, therefore creating infinite loop.

[EDIT]

Can we assume, that if process is no longer exists, there no reason to continue loop?

Edited September 20, 2022 by VAN0

[HurleyShanabarger]

Can you check with this approach?

Func _exec($sCmd)
    Local $iTimer = TimerInit()
    Local Const $iTimeOut = 50
    Local $iPID = Run($sCmd , "", @SW_HIDE, $STDOUT_CHILD)
    While ProcessExists($iPID)
        Sleep(10)
        ; Check for timeout
        If TimerDiff($iTimer) > $iTimeOut Then
            ProcessClose($iPID)
            StdioClose($iPID)
            ConsoleWrite("! error" & @CRLF)
            Return SetError(0x01)
        EndIf
    WEnd
    Local $sOut = StdoutRead($iPID)
    StdioClose($iPID)
    Return $sOut
EndFunc   ;==>_exec

 

[VAN0]

This returns "! error" all the time, because rasdial finishes almost instantly.

So, having a loop that checks for process existence doesn't work either:

Func exec($sCmd)
    Local $iNow = @YEAR & @MON & @MDAY & @HOUR & @MIN & @SEC
    Local $sOut = ""
    Local $iTimeout = $iNow + 5 ;5 seconds iTimeout
    $i = 0
    Local $iPID = Run($sCmd, "", @SW_HIDE, $STDERR_MERGED)
    Do
        $sOut &= StdoutRead($iPID)
        $err = @error
        $i += 1
        If @YEAR & @MON & @MDAY & @HOUR & @MIN & @SEC >= $iTimeout Then
            debug("! Timeout")
            WinKill($iPID)
            ExitLoop
        EndIf
    Until Not ProcessExists($iPID)
    StdioClose($iPID)
    debug("loop count: " & $i & " | err: " & $err & " | Output: " & $sOut)
    Return $sOut
EndFunc   ;==>exec

9 out of 10 times it exits the loop before anything was captured.

it seems it requires at least 3 loops before it capture anything. This approach seems to work good:

Func exec($sCmd)
    Local $iNow = @YEAR & @MON & @MDAY & @HOUR & @MIN & @SEC
    Local $sOut = ""
    Local $iTimeout = $iNow + 5 ;5 seconds iTimeout
    $i = 0
    Local $iPID = Run($sCmd, "", @SW_HIDE, $STDERR_MERGED)
    Do
        $sOut &= StdoutRead($iPID)
        $err = @error
        $i += 1
        If @YEAR & @MON & @MDAY & @HOUR & @MIN & @SEC >= $iTimeout Then
            debug("! Timeout")
            WinKill($iPID)
            ExitLoop
        EndIf
    Until $err Or (Not ProcessExists($iPID) And $sOut)
    StdioClose($iPID)
    debug("loop count: " & $i & " | err: " & $err & " | Output: " & $sOut)
    Return $sOut
EndFunc   ;==>exec

 

I wonder if it's a bug in AutoIt itself?

 

Edited September 21, 2022 by VAN0

[Nine]

No it is not a bug.  Run is a non-blocking function.  Even if the exe is small, it takes a bit of time to load and execute.  Your loop has no sleep, so it is normal that it spins some before catching stream data.  

[VAN0]

@Nine, that's not the issue here though...the issue is that StdoutRead doesn't read anything in some cases and no @error triggered.

My original code was using example from https://www.autoitscript.com/autoit3/docs/functions/StdioClose.htm

[Nine]

Same goes with StdoutRead, this is also a non-blocking function.  If it doesn't have anything to read, it goes along (see help file).

[HurleyShanabarger]

3 hours ago, VAN0 said:

This returns "! error" all the time, because rasdial finishes almost instantly.

Did you try to adjust the timeout? 50 ms is maybe a littlebit to low, depending on your computer.

[pixelsearch]

In case it may help, I got a script where $STDERR_MERGED doesn't display anything and goes into an infinite loop, while $STDERR_CHILD + $STDOUT_CHILD displays everything correctly and the job ends normally.

[VAN0]

@NineI do understand what you are saying, but you might be missing my point...the resdial.exe is a Windows built-in application, it should return something, so there shouldn't be any situations when "there is nothing to read", at least in my tests in powershell it always returns something, regardless how many times per second I've executed them.  and besides, the docs state that @error flag should be set when process doesn't exist. In my tests sometimes process already closed by the time stdoutread() executed and normally it needs at most 2 loops before processexists() returns 0.

I thought maybe there is internal timing issue, but that doesn't explain why it occur consecutively and not randomly.

@pixelsearch

Interesting, so $STDERR_MERGED is not just a shortcut for lazy us? I'll test it later.

Edited September 22, 2022 by VAN0

[HurleyShanabarger]

I am unable to reproduce the error, even if I start rasdial ~500 times, wait for all processes to finish and read the StdOut data everything is working.

What OS are you running, is the script running as X86/X84 and when the error is happening, are you connected to the VPN or is something changing with the connection?

[VAN0]

2 hours ago, HurleyShanabarger said:

I am unable to reproduce the error, even if I start rasdial ~500 times, wait for all processes to finish and read the StdOut data everything is working.

What OS are you running, is the script running as X86/X84 and when the error is happening, are you connected to the VPN or is something changing with the connection?

With ProcessWaitClose() the issue is not reproducible. I'm using Windows 10 x64 and script runs as x86

 

So, here is a little discovery, with the last code from my reply I'm getting loop count of 2-3 and I can't reproduce the issue, however when I replace `until` condition with:

Until $err

I get 10k+ loops count and the issue is back.

Starting process #66

"E:\Program Files\AutoIt3\AutoIt3.exe" "E:\Program Files\AutoIt3\SciTE\AutoIt3Wrapper\AutoIt3Wrapper.au3" /run /prod /ErrorStdOut /in "e:\dev\AutoIt3\vpn\test.au3" /UserParams -connect [PID 276608]

+>17:40:17 Starting AutoIt3Wrapper (22.611.2153.6) from:Code.exe (1.71.2.0)  Keyboard:A0000409  OS:WIN_10/2009  CPU:X64 OS:X64  Environment(Language:0409)

>Running AU3Check (3.3.16.0)  from:E:\Program Files\AutoIt3  input:e:\dev\AutoIt3\vpn\test.au3

+>17:40:17 AU3Check ended. rc:0

>Running:(3.3.16.0):E:\Program Files\AutoIt3\autoit3.exe "e:\dev\AutoIt3\vpn\test.au3"

loop count: 13474 | err: 1 | Output: No connections

Command completed successfully.

 

loop count: 15386 | err: 1 | Output: No connections

Command completed successfully.

 

loop count: 11002 | err: 2 | Output: No connections

Command completed successfully.

 

loop count: 10535 | err: 1 | Output: No connections

Command completed successfully.

 

! Timeout

loop count: 640586 | err: 0 | Output:

! Timeout

loop count: 608743 | err: 0 | Output:

This means the process no longer exists after 2-3 loops, but StdoutRead() sets @error flag after 10k+ loops after the process no longer exists. And @error sometimes is set to 1 and sometime to 2...no clue what that means.

If I use 

Until Not ProcessExists($iPID)

Then it shows loop count 1 and no output read (it only shows output starting with loop count 2)

 

[HurleyShanabarger]

Why is the loop count for you relevant?

You can start rasdial using the Run command with  $STDOUT_CHILD. Once the process is closed you can wait e.g. for 30 seconds and wil still be able to retrieve the data with StdoutRead.

The only that I can imagine:

• rasdial is started with PID X
• StdoutRead is reading the data within the loop
• rasdial closed, but at the same time a new process is created with the same PID X
• this would result in a timeout and or an error from Stdout

Just one other remark: I have not found any clue, that you can use a PID for the function WinKill.

//EDIT: I think I found another issue

        Local $iNow = @YEAR & @MON & @MDAY & @HOUR & @MIN & @SEC

        Local $iTimeout = $iNow + 5 ;5 seconds iTimeout

This can create invalid timestamp and resulting in a way to short monitoring time.

For example is $iNow = 20220922093359 and you add five it will result in 20220922093364. Once one second has passes your compare value within the loop will be 20220922093400 and this is already greater than 20220922093364. Hence better use TimerInit/TimerDiff

 

Edited September 22, 2022 by HurleyShanabarger

[Jos]

19 hours ago, VAN0 said:

Until $err Or (Not ProcessExists($iPID) And $sOut)

Are you using this to stop that loop? If so, i think that and isn't correct in this way as that $sOut is true after you received and text.

[VAN0]

@HurleyShanabarger loop count is irrelevant, it's just for debugging, loop itself however is faster than using processwaitclose(). The PID collision would make sense, if it was a random fluke, but this issue once started its a consecutively occurrence. Good point about the timestamp and winkill, thanks.

 

@Jos In this particular case, I have not seen StdoutRead() return part of the data, it either returns full data or nothing at all, hens this condition seem to work. But it also works with Until $err and not ProcessExists($iPID) however it's takes 10k+ loops to exit the loop, vs 2 loops (aka it's 5k times slower  )

Edited September 22, 2022 by VAN0

[jugador]

Something similar, now if run the below example
__exec1()  ==>  will hang at time of exit
__exec2()  ==>  will run ok.

Now why it hang during __exec1() I don't know.
how to solve it?

expandcollapse popup

#include <Constants.au3>

__ExampleA()
Func __ExampleA()
    Local $i = 0
    While 1
        If $i = 50 Then ExitLoop
        ConsoleWrite('loop Count: ' & $i & @Crlf)
        __exec1('dir')  ;~ it hang at time of exit
        ;__exec2('dir') ;~ run ok
        Sleep(50)
        $i += 1
    WEnd
ConsoleWrite('>>>> Exit' & @CRLF)
EndFunc

Func __exec1($sCmd)
    Local $iPID = Null
    Local $sOutput = ""
    $iPID = Run(@ComSpec & ' /c ' & $sCmd, "", @SW_HIDE, $STDERR_MERGED)
    StdioClose($iPID)   ;<<<<==================== deliberately close the Stdio stream
    While 1
        $sOutput &= StdoutRead($iPID)
        If @error Then ExitLoop
    WEnd

    If ProcessExists($iPID) Then ProcessClose($iPID)
    Sleep(10)
EndFunc

Func __exec2($sCmd)
    Local $iPID = Null
    Local $sOutput = ""
    $iPID = Run(@ComSpec & ' /c ' & $sCmd, "", @SW_HIDE, $STDERR_MERGED)
    While 1
        $sOutput &= StdoutRead($iPID)
        If @error Then ExitLoop
    WEnd
    StdioClose($iPID)   ;<<<<====================

    If ProcessExists($iPID) Then ProcessClose($iPID)
    Sleep(10)
EndFunc

 

[VAN0]

@jugador it doesn't check if stream exists, so it seems?

 

On 9/22/2022 at 8:09 AM, VAN0 said:

@Jos In this particular case, I have not seen StdoutRead() return part of the data, it either returns full data or nothing at all, hens this condition seem to work.

I was wrong, it does split output into chunks sometimes.