BugId fails with error: "Command output does not start with marker b'=<[{START}]>=': b'*** ERROR: Sy'"

[maxcoderrrr]

Hi, I was running the latest release of BugId and encountered the following error:

┌───[ Software license warning ]─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
│ ▲ You have no license for BugId and your trial period will expire on March 4th, 2023
│ ▲ You have no license for mBugId and your trial period will expire on March 4th, 2023
└────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
→ Command line: C:\test\test.exe C:\test\test.input
+ Main process 732/0x2DC (test.exe, x86, IL:3): Attached ("C:\test\test.exe" C:\test\test.input).
┌───[ Fatal builtins.AssertionError Exception in thread 5896/0x1708 (cThread#3D8AA30{main = __fRun, #5896, running}) ]───────────────────────────────────────────────────────────────────────────────────
│ Command output does not start with marker b'=<[{START}]>=': b'*** ERROR: Sy'
│ 
│ Local variables:
│   asbFilteredLines = []#4BB0BC8
│   bAddOutputToHTMLReport = False
│   bApplicationWillBeRun = False
│   bEndOfCommandOutputMarkerFound = False
│   bIgnoreOutput = False
│   bOutputIsInformative = True
│   bStartOfCommandOutputMarkerFound = False
│   o0LineInterruptedByCdbError = None
│   oCdbWrapper = <mBugId.cCdbWrapper.cCdbWrapper.cCdbWrapper object at 0x03D6CD50>#3D6CD50
│   oPromptMatch = None
│   sb0EndOfCommandOutputMarker = <instance builtins:bytes "b'=<[{END}]>='">#3CEA700
│   sb0StartOfCommandOutputMarker = <instance builtins:bytes "b'=<[{START}]>='">#3CEA720
│   sbCurrentLine = <instance builtins:bytes "b'*** ERROR: Sy'">#4BB0DE0
│   sbFilteredCurrentLine = <instance builtins:bytes "b'*** ERROR: Sy'">#4BB0DA0
│   u0Byte = 121
│ 
│ Stack for thread 5896/0x1708 (cThread#3D8AA30{main = __fRun, #5896, running}):
│ ─┐ __fRun @ C:\BugId\modules\mBugId\cCdbWrapper\cCdbWrapper_cHelperThread.py:66
│  │ 65:      try:
│  │ 66:        oSelf.__fActivity(*oSelf.__axActivityArguments);
│  ├─┐ cCdbWrapper_fCdbStdInOutHelperThread @ C:\BugId\modules\mBugId\cCdbWrapper\cCdbWrapper_fCdbStdInOutHelperThread.py:54
│  ╷ │ 53:    oCdbWrapper.fbFireCallbacks("Log message", "Main loop #%d" % uMainLoopCounter);
│  ╷ │ 54:    (bEventIsFatal, bEventHasBeenHandled) = oCdbWrapper.ftbHandleLastCdbEvent(asbOutputWhileRunningApplication);
│  ╷ ├─┐ cCdbWrapper_ftbHandleLastCdbEvent @ C:\BugId\modules\mBugId\cCdbWrapper\cCdbWrapper_ftbHandleLastCdbEvent.py:57
│  ╷ ╷ │ 56:  # detect this truncated output and try the command again for any command that we can safely execute twice.
│  ╷ ╷ │ 57:  asbLastEventOutput = oCdbWrapper.fasbExecuteCdbCommand(
│  ╷ ╷ ├─┐ cCdbWrapper_fasbExecuteCdbCommand @ C:\BugId\modules\mBugId\cCdbWrapper\cCdbWrapper_fasbExecuteCdbCommand.py:89
│  ╷ ╷ ╷ │ 88:      if gbDebugIO: print(">stdin>%s" % sCommand);
│  ╷ ╷ ╷ │ 89:      return oCdbWrapper.fasbReadOutput(
│  ╷ ╷ ╷ ├─┐ cCdbWrapper_fasbReadOutput @ C:\BugId\modules\mBugId\cCdbWrapper\cCdbWrapper_fasbReadOutput.py:180
│  ╷ ╷ ╷ ╷ │ 179:              else:
│  ╷ ╷ ╷ ╷ │ 180:                assert len(sbFilteredCurrentLine) < len(sb0StartOfCommandOutputMarker), \
│  ╷ ╷ ╷ ╷ │ ▲ Assertion failed: "Command output does not start with marker b'=<[{START}]>=': b'*** ERROR: Sy'"
│  ╷ ╷ ╷ ╷ │ cCdbWrapper_fasbReadOutput @ C:\BugId\modules\mBugId\cCdbWrapper\cCdbWrapper_fasbReadOutput.py:202
│  ╷ ╷ ╷ ╷ │ 201:  finally:
│  ╷ ╷ ╷ ╷ │ 202:    if bApplicationWillBeRun:
│  ╷ ╷ ╷ ╒═╛
│  ╷ ╷ ╷ │ cCdbWrapper_fasbExecuteCdbCommand @ C:\BugId\modules\mBugId\cCdbWrapper\cCdbWrapper_fasbExecuteCdbCommand.py:103
│  ╷ ╷ ╷ │ 102:        nExecutionTimeInSeconds = time.time() - nStartTimeInSeconds;
│  ╷ ╷ ╷ │ 103:        oCdbWrapper.sCdbIOHTML += "Command executed in %.03f seconds.<br/>\n" % nExecutionTimeInSeconds;
│  ╒═════╛
│  │ __fRun @ C:\BugId\modules\mBugId\cCdbWrapper\cCdbWrapper_cHelperThread.py:74
│  │ 73:        cException, oException, oTraceBack = sys.exc_info();
│  │ 74:        if not oSelf.__oCdbWrapper.fbFireCallbacks("Internal exception", oSelf.__oThread, oException, oTraceBack):
│ ═╛ ▲ Application terminated because exception was not handled.
└────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────

Please report the above details at the below web-page so it can be addressed:
    https://github.com/SkyLined/BugId/issues/new
If you do not have a github account, or you want to report this issue
privately, you can also send an email to:
    BugId@skylined.nl

In your report, please copy ALL the information about the exception reported
above, as well as the stack trace and BugId version information. This makes
it easier to determine the cause of this issue and makes for faster fixes.

If you can reproduce the issue, it would help a lot if you can run BugId in
verbose mode by adding the --verbose command-line argument.
as in: BugId -v --isa=x86 --n0ApplicationMaxRunTimeInSeconds=30 C:\test\test.exe -- C:\test\test.input

  ____________________________________________________________________________
                              __
   ││▌║█▐▐║▌▌█│║║│      _,siSP**YSis,_       ╒╦╦══╦╗             ╒╦╦╕    ╔╦╕
   ││▌║█▐▐║▌▌█│║║│    ,SP*'`    . `'*YS,      ║╠══╬╣ ╔╗ ╔╗ ╔╦═╦╗  ║║  ╔╦═╬╣
   ╵2808197631337╵   dS'  _    |    _ 'Sb    ╘╩╩══╩╝ ╚╩═╩╝ ╚╩═╬╣ ╘╩╩╛ ╚╩═╩╝
                    dP     \,-` `-<` `  Y;                 ╚╩═╩╝    ╮╷╭
      ╮╷╭          ,S`  \+' \      \    `Sissssssssssssssssssss,   :O()    ╲ö╱
     :O()          (S   (   | --====)   :SSSSSSSSSSSSSSSSSSSSSSD    ╯╵╰    ─O─
      ╯╵╰  ╮╷╭     'S,  /+, /      /    ,S?********************'           ╱O╲
           ()O:     Yb    _/'-_ _-<._.  dP
           ╯╵╰       YS,       |      ,SP         https://bugid.skylined.nl
  ____________________`Sbs,_    ' _,sdS`______________________________________
                        `'*YSissiSY*'`
                              ``
┌───[ Version information ]──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
│ ▲ BugId version: 2022-12-12 12:05 (in trial period).
│ ▲ mBugId version: 2022-12-12 12:05 (in trial period).
│ √ mConsole version: 2022-12-12 12:05.
│ √ mDateTime version: 2022-12-12 12:04.
│ √ mDebugOutput version: 2022-12-12 12:05.
│ √ mFileSystemItem version: 2022-12-12 12:05.
│ √ mHumanReadable version: 2022-12-12 12:04.
│ √ mMultiThreading version: 2022-12-12 12:05.
│ √ mNotProvided version: 2022-12-12 12:04.
│ √ mProductDetails version: 2022-12-12 12:05.
│ √ mRegistry version: 2022-12-12 12:05.
│ √ mWindowsAPI version: 2022-12-12 12:05.
│ √ mWindowsSDK version: 2022-12-12 12:04.
│ • Windows version: Windows 10 Pro release 2009, build 19044 x86.
│ • Python version: 3.11.1 x86.
│ • cdb.exe (x86) version: 6.11.0001.404.
│ • cdb.exe (x64) version: not available.
└────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
Thank you in advance for helping to improve BugId!
√ A copy of the error report can be found in C:\BugId\Internal error reports\2023-02-06 17։45։33.278937 BugId error report #3.txt.

Any help to fix this issue would be great. Please let me know in case any further information is required.

[SkyLined]

Thanks for the report, I'll have a look!

[SkyLined]

Sorry for the delays. Sick kids are taking most of my spare time.

[maxcoderrrr]

No problem, thank you for the update!

[maxcoderrrr]

@SkyLined Do you have any update on this bug or a possible workaround?

I've also tried the two previous versions, BugId.release.2022-10-10.16.26 and BugId.release.2022-12-08.09.57, but they trigger the same bug. Going one more version back to BugId.release.2022-01-05.09.41, a different bug is triggered (NoneType instance has no attribute bAllocated), but that's one that has likely been fixed in one of the later versions.

Going back one more version to Release 2021-10-25, which is the latest version that supports Python2, will trigger the bug that was highlighted in the other ticket.

[SkyLined]

Hey, thank you for reminding me. I have been way too busy with other things and completely forgot to check back in here.

I think this can be "fixed" in the latest version by simply removing the assert. i.e. you have to "comment out" the 4 lines of code starting at line 179 by putting a # in front of each of them:

#              else:
#                assert len(sbFilteredCurrentLine) < len(sb0StartOfCommandOutputMarker), \
#                    "Command output does not start with marker %s: %s" % \
#                    (repr(sb0StartOfCommandOutputMarker), repr(sbCurrentLine));

Can you give this a try to see if that resolves your issue?

Note to self: this code attempts to process the output of cdb.exe, which is notoriously hard to do because it will output random symbol loading errors and other cruft in the middle of normal output. The code asks cdb.exe to output a marker before and after executing a command. I assumed that cdb.exe would not output a symbol loading error before the marker. Apparently that assumption is not true.

[maxcoderrrr]

I should have added that the suggested workaround was my initial attempt to resolve this issue as well.

I removed/commented the four lines from \modules\mBugId\cCdbWrapper\cCdbWrapper_fasbReadOutput.py, which will result in the following bug:

┌───[ Software license warning ]──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
│ ▲ You have no license for BugId and your trial period will expire on May 9th, 2023
│ ▲ You have no license for mBugId and your trial period will expire on May 9th, 2023
└─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
→ Command line: C:\test\test.exe C:\test\test.input
+ Main process 3460/0xD84 (test.exe, x86, IL:3): Attached ("C:\test\test.exe" C:\test\test.input).
► Main process 3460/0xD84 (test.exe, x86, IL:3): debug Invalid parameter passed to C runtime function.
► Main process 3460/0xD84 (test.exe, x86, IL:3): debug Invalid parameter passed to C runtime function.
┌───[ Fatal builtins.AttributeError Exception in thread 4680/0x1248 (cThread#3EA0A90{main = __fRun, #4680, running}) ]────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
│ NoneType instance has no attribute bAllocated.
│ instance: None.
│ 
│ Local variables:
│   cAddressType = <class 'mWindowsSDK.mWindowsPrimitiveTypes.UINT64'>#30E5B68
│   o0VirtualAllocation = None
│   oProcess = <mBugId.cProcess.cProcess.cProcess object at 0x03EDC270>#3EDC270
│   uMemoryAddress = 2877461536
│ 
│ Stack for thread 4680/0x1248 (cThread#3EA0A90{main = __fRun, #4680, running}):
│ ─┐ __fRun @ C:\bugid\modules\mBugId\cCdbWrapper\cCdbWrapper_cHelperThread.py:66
│  │ 65:      try:
│  │ 66:        oSelf.__fActivity(*oSelf.__axActivityArguments);
│  ├─┐ cCdbWrapper_fCdbStdInOutHelperThread @ C:\bugid\modules\mBugId\cCdbWrapper\cCdbWrapper_fCdbStdInOutHelperThread.py:54
│  ╷ │ 53:    oCdbWrapper.fbFireCallbacks("Log message", "Main loop #%d" % uMainLoopCounter);
│  ╷ │ 54:    (bEventIsFatal, bEventHasBeenHandled) = oCdbWrapper.ftbHandleLastCdbEvent(asbOutputWhileRunningApplication);
│  ╷ ├─┐ cCdbWrapper_ftbHandleLastCdbEvent @ C:\bugid\modules\mBugId\cCdbWrapper\cCdbWrapper_ftbHandleLastCdbEvent.py:214
│  ╷ ╷ │ 213:    oCdbWrapper.o0ReservedMemoryVirtualAllocation = None;
│  ╷ ╷ │ 214:  o0BugReport = cBugReport.fo0CreateForException(
│  ╷ ╷ ├─┐ cBugReport?.fo0CreateForException @ C:\bugid\modules\mBugId\cBugReport\cBugReport.py:134
│  ╷ ╷ ╷ │ 133:    # Create a preliminary error report.
│  ╷ ╷ ╷ │ 134:    o0BugReport = cBugReport.foCreate(
│  ╷ ╷ ╷ ├─┐ cBugReport?.foCreate @ C:\bugid\modules\mBugId\cBugReport\cBugReport.py:181
│  ╷ ╷ ╷ ╷ │ 180:    );
│  ╷ ╷ ╷ ╷ │ 181:    fApplyBugTranslationsToBugReport(oCdbWrapper, oBugReport);
│  ╷ ╷ ╷ ╷ ├─┐ fApplyBugTranslationsToBugReport @ C:\bugid\modules\mBugId\mBugTranslations\fApplyBugTranslationsToBugReport.py:65
│  ╷ ╷ ╷ ╷ ╷ │ 64:    for oBugTranslation in aoBugTranslations:
│  ╷ ╷ ╷ ╷ ╷ │ 65:      if oBugTranslation.fbApplyToBugReport(oCdbWrapper, oBugReport):
│  ╷ ╷ ╷ ╷ ╷ ├─┐ cBugTranslation?.fbApplyToBugReport @ C:\bugid\modules\mBugId\mBugTranslations\cBugTranslation.py:137
│  ╷ ╷ ╷ ╷ ╷ ╷ │ 136:    # If more top frames may be irrelevant, see if they are there and hide them:
│  ╷ ╷ ╷ ╷ ╷ ╷ │ 137:    if (oSelf.bAdditionalIrrelevantNoneTopStackFrames or oSelf.rb0AdditionalIrrelevantStackFrameSymbols) and oBugReport.o0Stack:
│  ╷ ╷ ╷ ╷ ╷ ╷ ├─┐ o0Stack @ C:\bugid\modules\mBugId\cBugReport\cBugReport.py:101
│  ╷ ╷ ╷ ╷ ╷ ╷ ╷ │ 100:    if oSelf.__o0Stack is None:
│  ╷ ╷ ╷ ╷ ╷ ╷ ╷ │ 101:      oSelf.__o0Stack = cStack.foCreate(oSelf.__oProcess, oSelf.__oWindowsAPIThread, oSelf.uStackFramesCount);
│  ╷ ╷ ╷ ╷ ╷ ╷ ╷ ├─┐ cStack?.foCreate @ C:\bugid\modules\mBugId\cStack.py:317
│  ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ │ 316:          oStack.__du0CallTargetAddress_by_uReturnAddress[u0ReturnAddress] = \
│  ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ │ 317:              oProcess.fu0GetTargetAddressForCallInstructionReturnAddress(u0ReturnAddress);
│  ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ ├─┐ cProcess_fu0GetTargetAddressForCallInstructionReturnAddress @ C:\bugid\modules\mBugId\cProcess\cProcess_fu0GetTargetAddressForCallInstructionReturnAddress.py:85
│  ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ │ 84:      uCallMemoryAddress = uReturnAddress + o0CallInstructionStructure.i32Offset;
│  ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ │ 85:      u0CallTargetAddress = fu0ReadAddressFromMemory(UINT64, uCallMemoryAddress);
│  ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ ├─┐ fu0ReadAddressFromMemory @ C:\bugid\modules\mBugId\cProcess\cProcess_fu0GetTargetAddressForCallInstructionReturnAddress.py:49
│  ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ │ 48:    o0VirtualAllocation = oProcess.fo0GetVirtualAllocationForAddress(uMemoryAddress);
│  ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ │ 49:    if not o0VirtualAllocation.bAllocated:
│  ╒═══════════════════╛ ▲ AttributeError("'NoneType' object has no attribute 'bAllocated'")
│  │ __fRun @ C:\bugid\modules\mBugId\cCdbWrapper\cCdbWrapper_cHelperThread.py:74
│  │ 73:        cException, oException, oTraceBack = sys.exc_info();
│  │ 74:        if not oSelf.__oCdbWrapper.fbFireCallbacks("Internal exception", oSelf.__oThread, oException, oTraceBack):
│ ═╛ ▲ Application terminated because exception was not handled.
└─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────

Please report the above details at the below web-page so it can be addressed:
    https://github.com/SkyLined/BugId/issues/new
If you do not have a github account, or you want to report this issue
privately, you can also send an email to:
    BugId@skylined.nl

In your report, please copy ALL the information about the exception reported
above, as well as the stack trace and BugId version information. This makes
it easier to determine the cause of this issue and makes for faster fixes.

If you can reproduce the issue, it would help a lot if you can run BugId in
verbose mode by adding the --verbose command-line argument.
as in: BugId -v --isa=x86 --n0ApplicationMaxRunTimeInSeconds=120 C:\test\test.exe -- C:\test\test.input

  ____________________________________________________________________________
                              __
   ││▌║█▐▐║▌▌█│║║│      _,siSP**YSis,_       ╒╦╦══╦╗             ╒╦╦╕    ╔╦╕
   ││▌║█▐▐║▌▌█│║║│    ,SP*'`    . `'*YS,      ║╠══╬╣ ╔╗ ╔╗ ╔╦═╦╗  ║║  ╔╦═╬╣
   ╵2808197631337╵   dS'  _    |    _ 'Sb    ╘╩╩══╩╝ ╚╩═╩╝ ╚╩═╬╣ ╘╩╩╛ ╚╩═╩╝
                    dP     \,-` `-<` `  Y;                 ╚╩═╩╝    ╮╷╭
      ╮╷╭          ,S`  \+' \      \    `Sissssssssssssssssssss,   :O()    ╲ö╱
     :O()          (S   (   | --====)   :SSSSSSSSSSSSSSSSSSSSSSD    ╯╵╰    ─O─
      ╯╵╰  ╮╷╭     'S,  /+, /      /    ,S?********************'           ╱O╲
           ()O:     Yb    _/'-_ _-<._.  dP
           ╯╵╰       YS,       |      ,SP         https://bugid.skylined.nl
  ____________________`Sbs,_    ' _,sdS`______________________________________
                        `'*YSissiSY*'`
                              ``
┌───[ Version information ]───────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
│ ▲ BugId version: 2022-12-12 12:05 (in trial period).
│ ▲ mBugId version: 2022-12-12 12:05 (in trial period).
│ √ mConsole version: 2022-12-12 12:05.
│ √ mDateTime version: 2022-12-12 12:04.
│ √ mDebugOutput version: 2022-12-12 12:05.
│ √ mFileSystemItem version: 2022-12-12 12:05.
│ √ mHumanReadable version: 2022-12-12 12:04.
│ √ mMultiThreading version: 2022-12-12 12:05.
│ √ mNotProvided version: 2022-12-12 12:04.
│ √ mProductDetails version: 2022-12-12 12:05.
│ √ mRegistry version: 2022-12-12 12:05.
│ √ mWindowsAPI version: 2022-12-12 12:05.
│ √ mWindowsSDK version: 2022-12-12 12:04.
│ • Windows version: Windows 10 Pro release 2009, build 19044 x86.
│ • Python version: 3.11.1 x86.
│ • cdb.exe (x86) version: 6.11.0001.404.
│ • cdb.exe (x64) version: not available.
└─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
Thank you in advance for helping to improve BugId!
√ A copy of the error report can be found in C:\bugid\Internal error reports\2023-04-09 08։27։39.363636 BugId error report #2.txt.

The bug is the one previously mentioned, "NoneType instance has no attribute bAllocated", which I thought had been resolved in one of the previous updates. It seems to be caused because BugId tries to work with a UNIT64 instead of x86/32-bit int (in an x86 environment).

Performing a couple more tests, I have discovered more bugs that seem to be independent from this one. I'll create separate tickets for these.

[maxcoderrrr]

@SkyLined Just wanted to check in and see if there's any update on the bugs that I had reported? I'd be happy to help by testing a fixed version of BugId in case you want to confirm the fixes before you push the updated version to the repository.

[SkyLined]

I have not had time to have a look. I hope to have more time in a few weeks as I hope to finish a few other projects by then.

[SkyLined]

I am looking at this now. The second issue is obvious: the o0 prefix in o0VirtualAllocation means it can be an object or None. I am clearly not handling the case where it is None. I am testing a fix.

[maxcoderrrr]

@SkyLined Do you have any update on the new version? :)

[SkyLined]

I fixed this in June of 2023 but forgot to close the bug. https://github.com/SkyLined/mBugId/commit/93605b05e4135f6b4d982a87b7503c90b3463c60

This fix is not yet in the release version. I will see if I can create a new release version soon