Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

"Ignored Exceptions" not always ignored #2241

Open
mappzor opened this issue Nov 1, 2019 · 11 comments
Labels

Comments

@mappzor
Copy link
Contributor

@mappzor mappzor commented Nov 1, 2019

I observed this problem with several exception-heavy targets and finally decided to write my own small, simple repro. Basically if you have any target which throws A LOT of exceptions x(32|64)dbg will catch them occasionally regardless of "Ignored Exceptions" settings. This can happen anytime. It doesn't matter if you let the program run freely or if you are single stepping (super annoying).

Another annoyance during debugging such targets is a DoS on UI but this is already reported as #2121

Repro steps:

  1. Open target in x32dbg
  2. Set breakpoints at both "Breakpoint me!\n" references
  3. Configure x32dbg to ignore all exceptions (00000000-FFFFFFFF)
  4. Run until 1st breakpoint
  5. Run until 2nd breakpoint - x32dbg will unexpectedly break several times at int3 from another thread

Code (binary attached for convenience):

#include <windows.h>
#include <cstdio>

DWORD CounterExceptions = 0;
DWORD CounterHandlers = 0;

DWORD WINAPI ExceptionThread(LPVOID lpParameter)
{
    while (true)
    {
        __try
        {
            CounterExceptions++;
            __debugbreak();
        }
        __except (EXCEPTION_EXECUTE_HANDLER)
        {
            CounterHandlers++;
        }
    }
    return 0;
}

int main(int argc, char *argv[])
{
    CreateThread(NULL, 0, ExceptionThread, NULL, 0, NULL);
    printf("Breakpoint me!\n");
    for (int i = 0; i < 50000; ++i)
        printf("Doing stuff (%d)...\n", i + 1);
    printf("Breakpoint me!\n");
    printf("CounterExceptions=%d CounterHandlers=%d\n", CounterExceptions, CounterHandlers);
    return 0;
}

MoarExceptions.zip

@mrexodia

This comment has been minimized.

Copy link
Member

@mrexodia mrexodia commented Nov 1, 2019

@mrexodia mrexodia closed this Nov 1, 2019
@mappzor

This comment has been minimized.

Copy link
Contributor Author

@mappzor mappzor commented Nov 1, 2019

Thanks for info, seems to work when I change the value but I have one question, why? What's the reason for having such thing as a hidden option with default value being anything different than "unlimited"? Also 10000 seems to be pretty arbitrary. So what am I missing?

@mrexodia

This comment has been minimized.

Copy link
Member

@mrexodia mrexodia commented Nov 1, 2019

It is because of #1341. But perhaps it makes sense to increase this limit to be a bigger arbitrary number...

@mappzor

This comment has been minimized.

Copy link
Contributor Author

@mappzor mappzor commented Nov 2, 2019

I'd approach this problem a bit differently and start from scratch. I consider maxSkipExceptionCount to be a workaround for unknown root cause. I'm having two major concerns about #1341:

  • 3 year old issue, a lot of things changed in meantime, so maybe root cause is already gone if there was one
  • it involved a plugin (pretty big & crashy one)

We should look if previously reported problems (hanging, crashing, unresponsive GUI) can be reproduced today without any plugins, just clean x32dbg. One can just set this setting to something huge like 100kk and let exception generator spin for a while. I tried to do this and I managed to crash x32dbg... after 520000+ exceptions. Crashes were due to "Fatal GUI Exception: bad allocation!" clearly because of LogView (#2121 again). I don't know what allocation strategy is used there internally but if it doubles buffer size every realloc that would make sense because last alloc was around 500 MB and total private memory usage was around 1.05 GB. This would make next allocation attempt ask for extra 1 GB and for 32-bit app that's typically a game over. Until crash I did not observe reduced UI responsiveness or anything like that (unless you switch to Log tab of course).

I did my test with 4 exception-generating threads and repeated it with "verbose exception logging" disabled, so LogView doesn't grow so fast. Observations were consistent with previous test, it crashes on LogView allocations just much later (2700000+ exceptions). On x64dbg that would be simply a matter of RAM available. However I'm unable to identify anything that would justify "you have to break after X exceptions" logic.

This experiment leads me to conclusion that maybe removing maxSkipExceptionCount is the ultimate right way to resolve this. Can you reopen this issue? I think it's worth further investigation.

@mrexodia mrexodia reopened this Nov 2, 2019
@mrexodia

This comment has been minimized.

Copy link
Member

@mrexodia mrexodia commented Nov 2, 2019

I think the more interesting thing is this:

void LogView::flushTimerSlot()
{
if(logBuffer.isEmpty())
return;
setUpdatesEnabled(false);
static unsigned char counter = 100;
counter--;
if(counter == 0)
{
if(document()->characterCount() > 1024 * 1024 * 100) //limit the log to ~100mb
clear();
counter = 100;
}
QTextCursor cursor = textCursor();
cursor.movePosition(QTextCursor::End);
cursor.insertHtml(logBuffer);
if(autoScroll)
moveCursor(QTextCursor::End);
setUpdatesEnabled(true);
logBuffer.clear();
}

In theory the log should not keep growing in memory usage, I'll try and reproduce this.

With regards to the exception limit. The issue was happening without ScyllaHide too, but it was a private sample sent to me and I don't remember exactly what was inside of it. If memory serves it would throw infinite single chance exceptions but I forgot how. I'll also try to remove the limit and see what happens.

@mrexodia mrexodia added the enhancement label Nov 2, 2019
@mrexodia

This comment has been minimized.

Copy link
Member

@mrexodia mrexodia commented Nov 2, 2019

So I tried reproducing the weird issue when you let first chance exceptions run without pausing and after a while, try pressing pause. The debuggee will pause, but if you press F7/F8 to step the exceptions will keep going. Additionally using the skip command in the pause thread will let x64dbg go crazy on RAM usage and things start to get really unstable.

I did fix the log bug though, it was a bug introduced when adding the feature to only append text to the QTextEdit when the log view is visible.

@mappzor

This comment has been minimized.

Copy link
Contributor Author

@mappzor mappzor commented Nov 2, 2019

The debuggee will pause, but if you press F7/F8 to step the exceptions will keep going.

Hmm, I believe this might be the actual source of most of my problems. With such targets a common scenario I have is that exceptions are being generated often, although not as frequently as in provided sample, let's say every 1-2 seconds. I hit a breakpoint, keep stepping into/over 100-300 instructions and suddenly I lose control. Typically something crashes right away and I need to start over.

I did pause/skip thing and it's absolutely insane. My memory usage jumped from 700 MB to 2 GB, went down to 610 MB and debugger hanged completely. I also noticed that sometimes I have to press pause button a few times to actually pause. Weird things are going on here for sure.

I attempted another interesting thing. I let it run a bit, paused (got paused at int3) and just patched int3 with a nop. At this point I'm still in context of exception thread of course but I decided to put a breakpoint in main loop of main thread just to see that happens. Then I started stepping with F8. Debugger will keep switching between threads for 2-3 seconds maximum (if you are lucky). After that wild EXCEPTION_SINGLE_STEP will pop up out of nowhere and you will be stepping in the context of main thread ONLY from that point.

@mappzor

This comment has been minimized.

Copy link
Contributor Author

@mappzor mappzor commented Nov 2, 2019

Ok, I downloaded newest snapshot with your latest change and debugged skip issue again. Few observations:

  1. Now LogView enforces 100 MB limit in 2 places: flushTimerSlot to limit QTextBrowser's buffer size and addMsgToLogSlot to limit logBuffer size. Effectively buffer size for logs is limited to 200 MB not 100. Maybe it's worth to refactor flushTimerSlot to check combined size of LogView buffer and logBuffer against some predefined constant just to keep things clean.
  2. Magic number of 100 MB. It's clear for me that it's way too high. Let it fill and switch to Log tab. Trying to actually view that much data will make UI lag like hell for several seconds and memory allocation will peak as well. In my case those extra temporary allocations were around 500 MB, damn dangerous especially for 32-bit process. That's simply too much for this widget.
  3. When program runs ignoring exceptions things go well. You can see memory usage jumping +100 MB and another +100 MB in regular intervals as expected from current LogView implementation. However executing skip can still result in huge allocations. Apparently executing DebugUpdateGui causes some logging to occurr, this means executing flushTimerSlot -> insertHtml which will be responsible for allocating extra memory. Ok, it's fair that this call may temporarily need more than size of existing internal buffer + new buffer. What I don't understand is why this particular call makes such big allocations and previous calls when program was running did not. My theory is that DebugUpdateGui makes LogView widget behave as if it was visible during insertHtml and that (as we know from previous point) consumes shittons of memory when input data is around 200 MB. I won't dig in Qt sources to confirm that but I'm pretty convinced something like that happens. My record is allocating extra 1.5 GB memory (skip command executed with buffer close to maximum). Command took over 8 minutes to execute.

Here's how memory usage looked like during first test session (small, regular peaks -> LogView activity when target is running, large peak -> skip command triggered DebugUpdateGui):
mem

Here's my most-broken case (8 minutes of insertHtml):
inserthtml

@mrexodia

This comment has been minimized.

Copy link
Member

@mrexodia mrexodia commented Nov 3, 2019

Okay so I disabled the LogView altogether (by disconnecting the signal) and it seems like most things are working just fine with infinite exception skipping. The main issue is that when pressing pause and then F7/F8 will not peform a single step, but it will resume skipping. The 'Transparent Exception Stepping' feature is also not working properly, so that has to be addressed.

With regards to the LogView, I guess the only real solution (which I have been dreading for quite some time now) is to rewrite the LogView to be an AbstractStdTable instead. The major downside is that text selection is not working in this mode and some other features would have to be dropped as well, but the upside is that everything will be super fast. Another solution is to roll our own text view widget, which only renders the visible text area but this is a lot of work that seemingly nobody did before with a doubtful payoff.

Yet another idea is to implement a feature where skipped exceptions are not logged, or at least have reduced logging. The option 'Enable Verbose Exception Logging' is usually too verbose, because generally I only care about exceptions that I actually break on, so maybe that can be adapted.

With regards to changing from 100mb (which is actually 200 because of wchar_t, and as you noted peaks at 400 because of the buffering) to something lower, I'm not against it, but I'm afraid Qt won't gracefully handle anything more than ~1mb to be honest. I tried 1mb and the GUI becomes almost completely unresponsive with the log in the foreground already, anything more completely hangs x64dbg.

@mappzor

This comment has been minimized.

Copy link
Contributor Author

@mappzor mappzor commented Nov 4, 2019

After pausing I'm paused at int3, pressing F7/F8 generates breakpoint exception, so it will be skipped and execution resumes as normal. Isn't that expected in this case? If I patch int3 to nop and press F7/F8 I can single-step as usual.

Option that would avoid logging skipped exceptions surely would be a great improvement. I fully agree with your reasoning. Usually skipped exceptions are useless noise introduced by anti-debug routines or C++ exceptions. I don't even need to know about them.

To be honest 1 MB was exactly the first number I thought about when I saw insertHtml. I immediately assume that anything that uses html formatting probably won't deal with more data than that. Also it's a reasonable limit. If average line of output is 60 characters (quite long to be honest, most lines are shorter) that's still over 16k lines of logs. In my opinion if someone needs more than that he should rely on logfile instead of GUI widget.

I opened a pull request to introduce 1 MB limit and used a small trick for faster appending to QTextBrower. It really makes a huge difference in responsivness.

@mrexodia

This comment has been minimized.

Copy link
Member

@mrexodia mrexodia commented Nov 4, 2019

Thanks for the PR, I merged it but I will do some adjustments to the strategy for clearing the logs. Currently there is the unfortunate situation that if you log 1.00001mb you will only see the last entry in the log. I think a better strategy is to save the log position halfway and remove the beginning instead to at least have some kind of history.

With regards to F7/F8 being expected to continue execution, this is true but there was definitely various bugs with the exception skipping not being reset on certain events. I already fixed them locally, but forgot to push yesterday.

I will leave this issue open to address the situation with exception logging being too verbose. Perhaps a workaround is to disable the verbose logging when skipping, but keep the 'exception x' single line log. However instead of spamming the log, simply collapse repeating log lines.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
2 participants
You can’t perform that action at this time.