#1081 rexx abends when hostemu execio attempted

4.1.2
closed
Mark Miesfeld
none
5
2012-09-07
2012-06-17
No

Under Win XP Pro SP3 etc, on AMD Sempron CPU, using ooRexx version: REXX-ooRexx_4.1.1(MT) 6.03 16 May 2012

Every time I try to use hostemu execio to read a disk file, the rexx interpreter crashes.

Discussion

  • In the text exec I attached the simplest instance is an abend when trying to read "C:\testfile.txt" using an execio command that is entirely a literal string. However my earlier failures used commands assembled from various mixes of variables and literals - those are also in the test exec but the abend happens at the simplest case which occurs at "try(0)".

    Something else very strange happens too... I have another exec which runs every minute whose purpose is to find DrWatson log & dmp files (in the standard place) and move them elsewhere with a time-of-move timestamp in their names. This has been running fine for months. Now, when I have DrW files created by the test exec here abending, the exec that runs soon after that abend sees the newly created DrW files, moves them ok, goes through my standard terminating code (which nearly all my execs have) and writes lines to a log and stops. Except... the rexxhide.exe under which the file-mover-exec was running keeps on running. I've had to force it out of the system by using "end process" in task manager.

    When I first saw this the test exec (ie the one that abends) was also running under rexxhide.exe, but I've also seen rexxhide.exe 'stall' when running the file-mover-exec when the abending exec ran under rexx.exe or rexxpaws.exe.

    I have another exec which uses WMI to list the processes for any rexx-related task (written when I was previously investigating multiple rxapi tasks). This shows, typically, something like:

    Win32 processes running rexx.exe or rexxhide.exe or rexxpaws.exe or rxapi.exe:

    1) cmd=C:\My Dropbox\Programs-IPCLP\~open-source ooRexx V4-1-1\rxapi.exe
    prm=
    ProcessID: 1096
    SessionID: 0
    Priority: 8
    ParentProcessID: 712
    Name: rxapi.exe
    CreationDate: 20120617233339.296875+060
    Description: rxapi.exe
    ThreadCount: 4
    .
    1] Handle: 1100
    ] Priority: 8
    ] Name: The NIL object
    ] Caption: The NIL object
    ] Description: The NIL object
    ] ElapsedTime: 4423000 (mS of CPU time)
    ] ExecutionState: The NIL object
    ] Status: The NIL object
    ] ThreadState: 5 Waiting
    ] ThreadWaitReason: 0 Executive (if ThreadState = 6? or 5?)
    .
    2] Handle: 768
    ] Priority: 8
    ] Name: The NIL object
    ] Caption: The NIL object
    ] Description: The NIL object
    ] ElapsedTime: 4420000 (mS of CPU time)
    ] ExecutionState: The NIL object
    ] Status: The NIL object
    ] ThreadState: 5 Waiting
    ] ThreadWaitReason: 6 PageIn (if ThreadState = 6? or 5?)
    .
    3] Handle: 3516
    ] Priority: 8
    ] Name: The NIL object
    ] Caption: The NIL object
    ] Description: The NIL object
    ] ElapsedTime: 802000 (mS of CPU time)
    ] ExecutionState: The NIL object
    ] Status: The NIL object
    ] ThreadState: 5 Waiting
    ] ThreadWaitReason: 6 PageIn (if ThreadState = 6? or 5?)
    .
    4] Handle: 3916
    ] Priority: 8
    ] Name: The NIL object
    ] Caption: The NIL object
    ] Description: The NIL object
    ] ElapsedTime: 0 (mS of CPU time)
    ] ExecutionState: The NIL object
    ] Status: The NIL object
    ] ThreadState: 5 Waiting
    ] ThreadWaitReason: 6 PageIn (if ThreadState = 6? or 5?)

    2) cmd=C:\My Dropbox\Programs-IPCLP\~open-source ooRexx V4-1-1\rexxhide.exe
    prm=C:\My Dropbox\JN_RexxPathLib\SchedTask-Archive-DrWatson's-Files.rexh
    ProcessID: 3112
    SessionID: 0
    Priority: 8
    ParentProcessID: 1220
    Name: rexxhide.exe
    CreationDate: 20120618003400.044125+060
    Description: rexxhide.exe
    ThreadCount: 1
    .
    1] Handle: 2636
    ] Priority: 10
    ] Name: The NIL object
    ] Caption: The NIL object
    ] Description: The NIL object
    ] ElapsedTime: 803000 (mS of CPU time)
    ] ExecutionState: The NIL object
    ] Status: The NIL object
    ] ThreadState: 5 Waiting
    ] ThreadWaitReason: 13 PageIn (if ThreadState = 6? or 5?)

    3) cmd=C:\My Dropbox\Programs-IPCLP\~open-source ooRexx V4-1-1\rexx.exe
    prm=C:\My Dropbox\Notes-folders\More than one rxapi task\WMI list of rexx tasks.rex
    ProcessID: 632
    SessionID: 0
    Priority: 8
    ParentProcessID: 348
    Name: rexx.exe
    CreationDate: 20120618004721.911625+060
    Description: rexx.exe
    ThreadCount: 4
    .
    1] Handle: 3032
    ] Priority: 8
    ] Name: The NIL object
    ] Caption: The NIL object
    ] Description: The NIL object
    ] ElapsedTime: 1000 (mS of CPU time)
    ] ExecutionState: The NIL object
    ] Status: The NIL object
    ] ThreadState: 5 Waiting
    ] ThreadWaitReason: 6 PageIn (if ThreadState = 6? or 5?)
    .
    2] Handle: 1572
    ] Priority: 11
    ] Name: The NIL object
    ] Caption: The NIL object
    ] Description: The NIL object
    ] ElapsedTime: 0 (mS of CPU time)
    ] ExecutionState: The NIL object
    ] Status: The NIL object
    ] ThreadState: 5 Waiting
    ] ThreadWaitReason: 16 LPCReceive (if ThreadState = 6? or 5?)
    .
    3] Handle: 3256
    ] Priority: 8
    ] Name: The NIL object
    ] Caption: The NIL object
    ] Description: The NIL object
    ] ElapsedTime: 0 (mS of CPU time)
    ] ExecutionState: The NIL object
    ] Status: The NIL object
    ] ThreadState: 5 Waiting
    ] ThreadWaitReason: 4 ExecutionDelay (if ThreadState = 6? or 5?)
    .
    4] Handle: 784
    ] Priority: 11
    ] Name: The NIL object
    ] Caption: The NIL object
    ] Description: The NIL object
    ] ElapsedTime: 0 (mS of CPU time)
    ] ExecutionState: The NIL object
    ] Status: The NIL object
    ] ThreadState: 5 Waiting
    ] ThreadWaitReason: 16 LPCReceive (if ThreadState = 6? or 5?)
    .
    5] Handle: 3020
    ] Priority: 11
    ] Name: The NIL object
    ] Caption: The NIL object
    ] Description: The NIL object
    ] ElapsedTime: 0 (mS of CPU time)
    ] ExecutionState: The NIL object
    ] Status: The NIL object
    ] ThreadState: 5 Waiting
    ] ThreadWaitReason: 16 LPCReceive (if ThreadState = 6? or 5?)

    In this instance, the file-mover exec was shown as:

    2) cmd=C:\My Dropbox\Programs-IPCLP\~open-source ooRexx V4-1-1\rexxhide.exe
    prm=C:\My Dropbox\JN_RexxPathLib\SchedTask-Archive-DrWatson's-Files.rexh
    ProcessID: 3112
    SessionID: 0
    Priority: 8
    ParentProcessID: 1220
    Name: rexxhide.exe
    CreationDate: 20120618003400.044125+060

    and had been running for 803 seconds. In the logfile created by this exec are the log lines:

    20120618 00:34:00.887000 Exec starting, under pid=3112, tid=2636.
    20120618 00:34:00.887000 Found: C:\Documents and Settings\All Users\Application Data\Microsoft\Dr Watson\drwtsn32.log
    20120618 00:34:00.903000 + archived file successfully as C:\MiscExeclogs\DrWatson (20120618 003400-887000) - drwtsn32.log
    20120618 00:34:00.903000 Found: C:\Documents and Settings\All Users\Application Data\Microsoft\Dr Watson\user.dmp
    20120618 00:34:01.059000 + archived file successfully as C:\MiscExeclogs\DrWatson (20120618 003400-903000) - user.dmp
    20120618 00:34:01.059000 ending; began: 20120618 00:34:00.887000, logstart: 20120618 00:34:00.887000.
    20120618 00:34:01.059000 .

     
  • Hmm, those log line have wrapped oddly. They're meant to look like

    20120618 00:34:00.887000 Exec starting, under pid=3112, tid=2636.

    20120618 00:34:00.887000 Found: C:\Documents and Settings\All
    Users\Application Data\Microsoft\Dr Watson\drwtsn32.log

    20120618 00:34:00.903000 + archived file successfully as
    C:\MiscExeclogs\DrWatson (20120618 003400-887000) - drwtsn32.log

    20120618 00:34:00.903000 Found: C:\Documents and Settings\All
    Users\Application Data\Microsoft\Dr Watson\user.dmp

    20120618 00:34:01.059000 + archived file successfully as
    C:\MiscExeclogs\DrWatson (20120618 003400-903000) - user.dmp

    20120618 00:34:01.059000 ending; began: 20120618 00:34:00.887000,
    logstart: 20120618 00:34:00.887000.

    20120618 00:34:01.059000 .

    which means that in practical terms this exec ran from 20120618 00:34:00.887000 to 20120618 00:34:01.059000 which is far less than 800+ seconds.

    This "feels" to me as if there is something - a semaphore perhaps? - acquired by the rexx[xxxx].exe that runs the exec (which abends) which is not released when it abends. Perhaps something held on its behalf by rxapi? Then when a following exec runs it in turn waits for the thing that the preceding exec should have released, if you see what I mean.

    Hmm. I've discovered something... If I put dummy files in the DrW location - ie in XP in:

    C:\Documents and Settings\All Users\Application Data\Microsoft\Dr Watson

    they get moved ok, by a scheduled-task-initiated run of the file-mover... and that also stalls rexxhide.exe; if I run the file-mover manually then (a) it doesn't stall and (b) something I'm not seeing when the scheduled-task version runs happens... I get a message box telling me that some files have been moved. This strongly implies that the stalling rexxhide.exe processes are stalling because a message box (which I am not being shown) is waiting to be dismissed.

    The scheduled task running the file-mover is running under my userid, and other similar tasks running under the same userid are producing message boxes.

     
  • Damn! I was wrong! When I said:

    "The scheduled task running the file-mover is running under my userid, and other similar tasks running under the same userid are producing message boxes."

    it turns out that this task was running under "NT SYSTEM" whereas every other one I've created was running under my id. I've changed it and now the thing doesn't stall.

    Sorry for wasting your time on the stalling issue. The hostemu execio abend is genuine though!

     
  • Mark Miesfeld
    Mark Miesfeld
    2012-06-18

    Just a quick note. The example program works fine on my trunk 64-bit build. I'll try on 4.1.1 tomorrow.

     
  • hex
    hex
    2012-06-18

    in a mail2011-10-22 on developers list Jean-Louis wrote:
    "Hi David

    When using hostemu from ooRexxShell under WinXP, I had sometimes a crash or corrupted data.
    Fixed by changing the declaration of GrxHost to add RexxEntry.

    I can commit the changes done in the attached patch file, if you wish.
    Since RexxEntry is empty for Unix, I didn't touch unix/hostemu.cpp.

    Jean-Louis"
    Title of his mail is "hostemu for windows : missing RexxEntry in the declaration of GrxHost" and there is a patch attached to that mail.

    As I had to same problem on XP as Jeremy, I applied the patch to my SVN repository and recompiled OOrexx, After that HOSTEMU on xp worked (I am not a freqvent user of HOSTEMU) but before the patch HOSTEMU crashed each time on XP (worked on win7 64 before the patch and of course also after the patch)
    /hex

     
  • Mark Miesfeld
    Mark Miesfeld
    2012-06-18

    Committed revision 7918. trunk
    Committed revision 7919. 4.1 bug fixes

    Thanks /hex. It only crashed on the 32-bit release build, it didn't crash on a debug build. It doesn't crash after adding RexxEntry.

     


Anonymous


Cancel   Add attachments