OllyDbg taking 100% CPU when target is running

[dELTA]

I know this has been discussed/mentioned/asked here before, but I don't remember if anything useful was ever concluded, and I can't seem to find any answer when searching neither the board nor Google.

The question is: Sometimes OllyDbg itself seems to take 100% CPU when the debugged process is running. Why is this, and can it be/has it been fixed somehow?

You will find references to this problem e.g. here:

http://www.woodmann.com/forum/showthread.php?t=8533

and here:

http://www.woodmann.com/forum/showthread.php?t=9846

[Kayaker]

Probably not related but highlights another Olly problem (well, AV problem)

OllyDbg, Windows XP SP2 (32-bit) and Kaspersky Antivirus

http://msmvps.com/blogs/v_scherbina/archive/2006/10/19/OllyDbg_2C00_-Windows-XP-SP2-_2800_32_2D00_bit_2900_-and-Kaspersky-Antivirus.aspx

[blurcode]

I had that problem when I had installed too many plugins in OllyDbg. I now stick to the minimum plugins as possible. Also I have noted that if you debug some targets in a VMWare OllyDbg use 100% CPU, on real enviroment it works fine. And sometimes again in VMWare when I am tracing a target and OllyDbg uses full CPU I click the taskbar to remove the focus from OllyDbg's window and it go faster.

[dELTA]

Thanks for the info! I'll check if any of these situations apply (it's a friend of mine who's experiencing this at the moment).

[dELTA]

I've now checked, and the mystery continues, because:

• No plugins at all are installed in the problematic OllyDbg instance.
• The debugging is performed directly on a physical host, not inside a virtual machine like VMware etc.
• The target is started from OllyDbg, not attached to (as mentioned as a possible problem in one of the threads I'm referring to above). The exact same thing happens if the target is attached to after being started on its own though, so this factor does not seem to make a difference at all.
• No Kaspersky antivirus is being used on the machine.

We have now also confirmed that it happens for all targets (e.g. Notepad etc), so it's not an anti-debug trick of the target itself either. And, we just verified that the same thing happens inside a VMware-machine without any antivirus at all, so that should exclude the possibility of an AV conflict too.

Here are the exact steps to reproduce the problem, it would be great if a bunch of people here could try this and report if the same thing happens to them or not:

1. Download a fresh OllyDbg 1.10.
2. Start Notepad from inside OllyDbg.
3. Press F9 to let it run.
4. Switch window focus to the Notepad window.
5. Start Task Manager, and look at the CPU usage of the ollydbg process. If the problem occurs, it should be near 100% (or 50% if you have dual core/hyper threading etc...).

If a modal dialog or menu inside OllyDbg is open (i.e. while the target is still running), the CPU usage goes back to normal though, so the window focus steps above are important.

Looking forward to hear about your results.

Any and all ideas or words of experience from similar situations are of course also very welcome (or even the next step, if anyone can find out the possible bug/problem inside OllyDbg that causes this behavior).

[blurcode]

Ah, now I understand what you are talking about. I'm pretty sure it is a bug in the VCL of C++ Builder, something to do with repaint of the custom components.

[naides]

I'm looking into it Master dELTA. first suggestion is to use Russinovich's Process Explorer which provides some more information:

For instance, the bulk of the CPU time used by Olly is Kernel time, not user time. If you look at Olly threads, Olly itself takes 86% of the CPU time with a high level of context switch.

taking a snapshot to the call stack, one usually gets:

1.ntdll.dll!KiFastSystemCallRet
2.kernel32.dll!WaitForDebugEvent+0x21
3.OLLYDBG.EXE!Go+0x4c0e
4.OLLYDBG.EXE!Createpatchwindow+0xe0f7

If I make Notepad.exe have an open dialog or pause olly

1.ntdll.dll!KiFastSystemCallRet
2.kernel32.dll!Sleep+0xf
3.OLLYDBG.EXE!Go+0x4bfd
4.OLLYDBG.EXE!Createpatchwindow+0xe0f7

My wild guess: WaitforDebugEvent is being hit relentlessly. . .

I am going to try two approaches:

Repeat the same exercise using windbg (and other debuggers) instead and check if WaitforDebugEvent is always so expensive.

Debug Olly-> debugging notepad and keep a eye around the code around OLLYDBG.EXE!Go+0x4c0e which seems to be the area of the code where most of the time is spent.

[dELTA]

Blurcode, thanks for this very interesting clue. From where did you get this information, and do you have any kind of further details to corroborate this, or that could bring us closer to the solution or source of this problem?

And naides, I'm very much looking forward to hearing more about your results! I'd be a little surprised though if OllyDbg would be so stupid as to continuously call WaitForDebugEvent() with an extremely low dwMilliseconds parameter in the same thread as the GUI is handled in, thus hammering it in a high CPU loop, contrary to calling it in a separate thread with a higher timeout delay?

If the separate thread technique is actually used by Olly, your call stack would indicate that you have monitored/breaked in the wrong thread, and I guess you already thought about that when checking it out, right?

On the other hand, perhaps such a tight loop of low-timeout WaitForDebugEvent() calls would have a similar effect to a tight loop of Sleep() calls, i.e. that the high CPU usage is only "virtual", while in reality the resulting explicit context switches would be so numerous that the process hosting the loop would rather just be similar to the "System Idle Process", i.e. eating up all available CPU cycles, but giving them away as soon as some other process needs them?

And naides, if you're gonna debug OllyDbg itself, it would be super if you could confirm both the single/double thread question, and also the actual value of the dwMilliseconds parameter to WaitForDebugEvent() inside OllyDbg. These things would most likely shed some light on a bunch of things.

Damn, I'd really like to run this mystery code (i.e. OllyDbg itself in this situation) in a real binary profiler... Does anyone know of a good binary code profiler (i.e. for use on code that you don't have the source code of), and have used it for reversing/pinpointing purposes before? Please see the following separate thread for more info and questions on this latter subject: http://www.woodmann.com/forum/showthread.php?t=11306

[blurcode]

I am making custom components and they have such bugs all over the place. I think when a menu popup or a modal dialog has focus it disable some messages to main window so it does not do repaints? Maybe I am wrong but I did this, opened notepad in OllyDbg put a breakpoint on LoadLibraryA (or bp somewhere else that can break manually by firing some menu in notepad), then while having OllyDbg's about box open I tried to open a file in notepad and it stopped at LoadLibraryA, but see the screenshots, window does not refresh untill I closed the about box.

Breakpoint hit but no refresh on window:
http://img201.imageshack.us/img201/3163/a1ia9.png

Refreshed:
http://img134.imageshack.us/img134/6953/a2jc7.png


Sorry for the large size of the screenshots.

[dELTA]

Ok, I guess that's yet another clue in favor of Olly using the same thread for the GUI and the debugging functionality (which in turn may speak for my theory mentioned above), if this behavior is not just by design of course, but I'm still not sure about what you mean is the possible relation between this and the high CPU usage blurcode?

[naides]

And naides, I'm very much looking forward to hearing more about your results! I'd be a little surprised though if OllyDbg would be so stupid as to continuously call WaitForDebugEvent() with an extremely low dwMilliseconds parameter in the same thread as the GUI is handled in, thus hammering it in a high CPU loop, contrary to calling it in a separate thread with a higher timeout delay?

I monitored windbg and IDA dbg. They are very "thin" in terms of CPU usage and don't consume CPU cycles unless there something going on in debugger/debugee.
AS far as Process Explorer can detect, Olly opens only one thread which has an incredible number of context switches (500 per second typically).
However Olly is not hugging the CPU per se, it easily give up CPU cycles if I start another CPU .intensive app on the side (My PERL little searcher scripts), so the computer performance does not appear to be heavily affected by Olly CPU "Bottleneck". The computer performance is if any, only marginally affected.

If the separate thread technique is actually used by Olly, your call stack would indicate that you have monitored/breaked in the wrong thread, and I guess you already thought about that when checking it out, right?

More to come. I am using an old computer at work, which gets overwhelmed easily. I am planing to use windbg to trace Ollydbg, but I am rather slow with windbg commands. WindDBG does open at least 2 threads, one that seems to take care of the interface, and another that seems to be delving with the debugging per se. Its stack is filled with calls to dbgeng.dll In fact, it does not call to WaitForDbgEvent by itself at all!

On the other hand, perhaps such a tight loop of low-timeout WaitForDebugEvent() calls would have a similar effect to a tight loop of Sleep() calls, i.e. that the high CPU usage is only "virtual", while in reality the resulting explicit context switches would be so numerous that the process hosting the loop would rather just be similar to the "System Idle Process", i.e. eating up all available CPU cycles, but giving them away as soon as some other process needs them?

And naides, if you're gonna debug OllyDbg itself, it would be super if you could confirm both the single/double thread question, and also the actual value of the dwMilliseconds parameter to WaitForDebugEvent() inside OllyDbg. These things would most likely shed some light on a bunch of things.

Yessir

In blue

[dELTA]

Thanks for the investigative work naides!

AS far as Process Explorer can detect, Olly opens only one thread which has an incredible number of context switches (500 per second typically).
However it is not hugging the CPU per se, it easily give up CPU cycles if I start another CPU intensive app on the side (My PERL little searcher scripts), so the computer performance does not appear to be heavily affected by Olly CPU "Bottleneck"

Great, this even more confirms my theory about this seemingly high CPU use, as stated in my post above (and I'll quote myself, due to the apparent selective invisibility of my posts around this place lately ):

On the other hand, perhaps such a tight loop of low-timeout WaitForDebugEvent() calls would have a similar effect to a tight loop of Sleep() calls, i.e. that the high CPU usage is only "virtual", while in reality the resulting explicit context switches would be so numerous that the process hosting the loop would rather just be similar to the "System Idle Process", i.e. eating up all available CPU cycles, but giving them away as soon as some other process needs them?

At this point, I'm pretty sure that your further investigation will show that OllyDbg calls WaitForDebugEvent() with a very low or zeroed dwMilliseconds parameter, in a tight loop (having window message processing as part of it), which results in this "virtual" high CPU use, while not really being a problem or something that bogs down the system or other applications.

[naides]

OK master Yoda, Reprimand taken :P
I'll read your posts thoroughly at least three times before answering.

This is an excerpt of the code OLLY is cycling through:

004395F9   > 833D 5C5A4D00 >CMP DWORD PTR DS:[4D5A5C],3
00439600   . 74 14          JE SHORT OLLYDBG.00439616
00439602   . 6A 00          PUSH 0                                   ; /Arg1 = 00000000
00439604   . E8 43D50500    CALL OLLYDBG.00496B4C                    ; \OLLYDBG.00496B4C
00439609   . 59             POP ECX
0043960A   . 6A 01          PUSH 1                                   ; /Timeout = 1. ms
0043960C   . E8 AB5B0700    CALL <JMP.&KERNEL32.Sleep>               ; \Sleep
00439611   . E9 D80C0000    JMP OLLYDBG.0043A2EE
00439616   > 6A 00          PUSH 0                                   ; /Timeout = 0. ms
00439618   . 68 14574D00    PUSH OLLYDBG.004D5714                    ; |pDebugEvent = OLLYDBG.004D5714
0043961D   . E8 E85B0700    CALL <JMP.&KERNEL32.WaitForDebugEvent>   ; \WaitForDebugEvent
00439622   . 85C0           TEST EAX,EAX
00439624   . 75 44          JNZ SHORT OLLYDBG.0043966A
00439626   . 833D 543B4E00 >CMP DWORD PTR DS:[4E3B54],0
0043962D   . 74 27          JE SHORT OLLYDBG.00439656
0043962F   . 8B0D 583B4E00  MOV ECX,DWORD PTR DS:[4E3B58]
00439635   . 83C1 64        ADD ECX,64
00439638   . 3B4D CC        CMP ECX,DWORD PTR SS:[EBP-34]
0043963B   . 73 19          JNB SHORT OLLYDBG.00439656
0043963D   . 6A 00          PUSH 0                                   ; /lParam = 0
0043963F   . 6A 00          PUSH 0                                   ; |wParam = 0
00439641   . 6A 00          PUSH 0                                   ; |Message = WM_NULL
00439643   . A1 5C3B4E00    MOV EAX,DWORD PTR DS:[4E3B5C]            ; |
00439648   . 50             PUSH EAX                                 ; |ThreadId => 0
00439649   . E8 F25E0700    CALL <JMP.&USER32.PostThreadMessageA>    ; \PostThreadMessageA
0043964E   . 33D2           XOR EDX,EDX

from here it goes and peek some messages a few lines below then loops to itself somewhere above.
so yes, OLLY uses a loop to Query for both windows messages and check for debug events every few ms

[dELTA]

Excellent, just as suspected then, thanks for the investigation/verification naides!

One aggravating factor connected to this that I didn't think of previously though, is that this spinning loop differs from the System Idle Process in that the CPU will still crunches instructions at 100% speed in the Olly case, which will cause e.g. laptops to run at maximum fan speed (= noise) etc. One way to mitigate this would be to patch in an increased delay in the parameters for either for the Sleep() or the WaitForDebugEvent() call in this loop. Because of this single thread design, this will cause a decreased responsiveness in the GUI though, but you could probably find a compromise that's better than this maximum-spinning loop though (10-100 ms?). It's almost interesting enough to be tried, I'll be back with some experimental results shortly...

[dELTA]

OK, success! A patch from 0 to 10 ms of the WaitForDebugEvent() dwMilliseconds parameter decreases the OllyDbg CPU load from 100% to 0%, and with no noticeable GUI latency problems either!

That's a patch to remember I guess. Any of the authors of the well-known fix-a-bunch-of-miscellaneous-glitches-in-Olly plugin creators (OllyAdvanced etc) are welcome to integrate it into their plugins.