#1092 Access violation in rexxhide.exe or rexx.dll

open
nobody
None
5
2012-08-14
2012-08-03
No

An exec that I run most days just crashed at or near the end of its processing. In its final work before stopping it writes data to a logfile - which worked, as did all the real processing it did before that, then uses RxMessageBox() to display a final summary message - having used the same function many times while running. On this occasion the final summary message was not displayed in a message box, but XP (Pro SP3) reported rexxhide had ended. Dr Watson files are attached, in case they help. As the exec runs most days, and this does not normally happen, I have no idea how to recreate the problem.

Discussion

  • Jeremy C B Nicoll

    Event log record says: Faulting application rexxhide.exe, version 4.1.1.7797, faulting module rexx.dll, version 4.1.1.7797, fault address 0x00039903.

     
  • Mark Miesfeld

    Mark Miesfeld - 2012-08-04

    Jeremy, the DR Waston files don't help a lot.

    What does the Rexx script that was running look like? Can you tell from the log being wrtiten that it was completely written?

    From the Dr. Watson log, there were 2 separate Rexx programs running at the time of the crash. What was the other program doing? Did you have any communication going between the 2 programs, or where they completely separate?

     
  • Jeremy C B Nicoll

    Hi Mark. The exec that crashed was going through standard exit processing which culminates in:

    if log.0 > 0 then do
    call l "ending; began:" log.0sta || "," ,
    "logstart:" log.0lr1 || "."
    call l "." / append marker to chunk of log lines /
    / By opening a log in a SHARED mode, we let this exec update logs /
    / even if they are open in, for example, a 'tail'-capable viewer. /
    openit = stream(log.0fil,"COMMAND","OPEN WRITE APPEND SHARED")
    if openit \== "READY:" then do
    say g.0eleaf "could not open" log.0fil
    say " err:" openit
    say
    say "so here's the lines ("log.0") meant to be logged:"
    say
    do oo = 1 to log.0
    say log.oo
    end
    say
    g.0saids = .true
    end
    else do
    do oo = 1 to log.0
    call lineout log.0fil,log.oo
    end
    shutit = stream(log.0fil,"COMMAND","CLOSE")
    end
    drop log.
    log.0 = 0
    end

    if msg.0 > 0 then do
    titl = "Final message from: " g.0eleaf / note extra spaces /

    icon = "INFORMATION" / noisy! /
    icon = "QUERY" / quiet /

    text = ""
    do mm = 1 to msg.0
    text = text || msg.mm || d2c(10) / insert linefeeds /
    end

    show = RxMessageBox(text,titl,,icon)
    end

    if g.0saids then do
    say
    say "*** Hitenter..."
    parse pull hitenter
    say
    end

    exit

    and had successfully written the whole of the log out to the log file. The content of the log looks good. (The exec had been scanning through a set of podcasts doing things to them, so it's easy to tell that the log is good because it shows successive actions to a set of files. Also one of those actions was to re-tag and move them from one folder to another and they did all get moved ok. The stem "msg." would have been expected to contain at least one line of text - the final summary of actions message - and that should have been presented in a message box by the exit code just after the log file got written out. It never appeared. I've never seen it not do so before, in either this exec or any of the others that use the same standard exit code,

    I did look back in the event logs (I have process start/stop logged in 'Security' logs) to check that the dump, which happened for pid=1492, really was for the exec which was doing the podcast manipulation... it was. This was easy to verify because that exec calls several CLI tools to do MP3 ID3 tag extraction & manipulation in the podcasts and each of these CLI processes being started showed they had pid=1492 as their parent process.

    Scheduled tasks runs rexx execs more or less all the time, so the fact that something else was running is no surprise. It's most likely to be the code that looks for creation of DrWatson dumps, every few seconds. [Because XP only ever keeps a single .dmp file with the most recent dump in it (though it keeps a log file with summary dump info for multiple dumps), I like to have .dmp files and .log files moved elsewhere as soon as they're created; the files get renamed according to the time of the dump, pid etc from text extracted from the log files. It's not perfect but better than XP's default behaviour. I wrote something similar but much more complex for a bank's MVS systems a while ago.]

    Fortunately the log file for the thing that looks for DrW dumps does itself log the pid that that exec runs under, each time it runs... and it was the one running with pid=2516 as mentioned in the list of processes in the DrW file. And it worked properly, archiving the log files as required...

    None of my rexx execs communicate with each other.

    I wasn't expecting the DrW files to have much/anything that's useful, because I've learned that seems to be the case pretty much always. Nevertheless I feel like I should provide them in case one day they turn out to be useful to someone.

    I know there's nothing to go on, except a violation type and an offset...

    .

     
  • Mark Miesfeld

    Mark Miesfeld - 2012-08-04

    Jeremy,

    Thanks for the information. I wanted to know if the log was completely written out mostly to see if I could focus on the RxMessageBox() function. So that is good info that it was written out.

     
  • Jeremy C B Nicoll

    Actually, I can tell you a bit more... The end of the log file contains lines:

    20120803 22:33:05.101000 54 World Book Club #c=0

    20120803 22:33:05.101000 55 You and Yours - Disability #c=0

    20120803 22:33:05.101000 56 You and Yours - Environment #c=0

    20120803 22:33:05.101000 57 You and Yours - Health #c=0

    20120803 22:33:05.101000 Processed 57 podcast dirs; moved 25 files, totalling 393.0MB.

    20120803 22:33:05.101000 Sizes of moved files: 4.3MB 5.4MB 5.9MB 2.6MB 2.4MB 5.0MB 4.8MB 3.5MB 2.1MB 40.1MB 31.1MB 51.0MB 13.0MB 22.8MB 17.2MB 25.1MB 26.0MB 13.0MB 12.7MB 26.1MB 26.2MB 7.8MB 11.1MB 20.9MB 12.9MB.

    20120803 22:33:05.101000 Number of dir/file snags: 0

    20120803 22:33:05.226000 ending; began: 20120803 22:03:54.001000, logstart: 20120803 22:03:54.001000.

    20120803 22:33:05.226000 .

    which I've spaced out so that the longer one's wrapping doesn't confuse you - in the log these are all single lines starting with a date & time stamp. The second-last log line records the time the exec started running and the timestamp of the first logline it created. Quiet a lot of my code which puts messages into messageboxes also puts those messages into the log. Shortly before the lines of code I quoted before the exec does:

    byebye: /------------------------------------------------------------/
    if g.0fnmsg then do / should we create 'Processed...' final msg? /
    if msg.0 > 0 then call m / if msgs pending, write a separator /

    if v.0moves == 1 then tellmove = v.0moves "file"
    else tellmove = v.0moves "files"

    if v.0moves == 0 then tellmove = tellmove"."
    else tellmove = tellmove", totalling" v.0totmv"MB."

    call m "Processed" v.0psubs "podcast dirs; moved" tellmove
    call l "Processed" v.0psubs "podcast dirs; moved" tellmove

    if v.0moves > 0 then call m "Sizes of moved files:" v.0sizes"."
    if v.0moves > 0 then call l "Sizes of moved files:" v.0sizes"."

    call m
    call m "Number of dir/file snags:" v.0snags
    call l "Number of dir/file snags:" v.0snags
    end

    When this executed I would expect g.0fnmsg to be true, and msg.0 to be 0 (because it would have been reset zero after each of the progress messageboxes as the exec ran was displayed). You'll see that there's pairs of "call m" and "call l" subroutines... These show lines being added to the log. and msg. stem arrays, so we can conclude that the msg. stem that would have been input to the final RxMessageBox() code where the exec crashed would have contained almost the same set of lines as those at the end of the log (except that there's one empty message line that doesn't get logged). So msg. should have contained:

    "Processed 57 podcast dirs; moved 25 files, totalling 393.0MB."
    "Sizes of moved files: 4.3MB 5.4MB 5.9MB 2.6MB 2.4MB 5.0MB 4.8MB 3.5MB 2.1MB 40.1MB 31.1MB 51.0MB 13.0MB 22.8MB 17.2MB 25.1MB 26.0MB 13.0MB 12.7MB 26.1MB 26.2MB 7.8MB 11.1MB 20.9MB 12.9MB."
    ""
    "Number of dir/file snags: 0"

    in msg.1 thru msg.4 In the final code those texts would have been concatenated with linefeeds before being passed to RxMessageBox().

     


Anonymous

Cancel  Add attachments





Get latest updates about Open Source Projects, Conferences and News.

Sign up for the SourceForge newsletter:





No, thanks