Bug (?): 100% CPU

dy/dx · Post by *dy/dx » 2009-08-25, 21:42 UTC

Hi,

Ich beobachte reproduzierbar folgenden Bug im TC: Wenn ich als User Verzeichnisse kopiere auf die ich keinen Zugriff hab (oder Teile davon) weil sie z.B. dem admin gehören, dann springt die CPU auf 100%, Total Commander reagiert nicht mehr und kann nur über den Taskmanager gekillt werden.

Dabei scheint es belanglos zu sein ob ich das RunAsAdmin Feature des Totalcommanders verwende (was ich mache).

Rufe ich den TC mit dem admin-Benutzer auf geht alles.

Beobachtet das sonst noch wer?

lg,
dy/dx

EDIT: Tritt doch auch als admin User auf!

Post by *ghisler(Author) » 2009-08-26, 15:01 UTC

Nein, eigentlich nicht - welche Version von TC?

dy/dx · Post by *dy/dx » 2009-08-26, 15:07 UTC

Hi,

Aha, gar nichts in diese Richtung bekannt? Komisch, denn ich hatte das Problem schon immer und jetzt hab ich neu aufgesetzt und sogar hier bekomme ich es.

Version ist: 7.04a.

Wie gesagt, das ganze ist reproduzierbar. Ich muss nur herausfinden unter welchen Vorraussetzungen genau. Ich kann gerne weitere Tests durchführen.

LG,
dy/dx

Matzix · Post by *Matzix » 2009-08-27, 12:27 UTC

Ich kenne diesen Bug ebenso, und zwar sowohl von verschiedenen Beta-Versionen von 7.5 (incl. RC1), als auch von Version 7.04a. Mein Verdacht war da aber bislang, dass der Virenscanner Dateien blockiert, denn es passiert bei mir auch mit Dateien, für die ich volle Rechte habe. Nach dem Killen über den Taskmanager und einem Neustart von TC geht es dann immer wieder...

Post by *ghisler(Author) » 2009-08-27, 12:55 UTC

Vielleicht lässt sich mit dem "process monitor" von www.sysinternals.com herausfinden, wo es hängt. Es könnte durchaus an einem Virenscanner liegen.

dy/dx · Post by *dy/dx » 2009-09-18, 14:52 UTC

Hallo!

Virenscanner & Co kann es nicht sein (hab ich nicht).

Ich habe heute einen Weg gefunden das Problem zu reproduzieren: Ich habe den Total Commander im Laufenden Betrieb auf die neue 7.5 upgedadet. Die totalcmd.exe konnte er natürlich nicht überschreiben da sie in Gebrauch ist. Statt aber eine Fehlermeldung zu geben schoss die CPU auf 100%. Egal ob als admin oder nicht.

Die gute Sache dabei: Ich wollte das jetzt mit 7.5. wiederholen. Ergebnis: Es scheint auf den ersten Blick nicht mehr aufzutreten, d.h. offenbar und hoffentlich ist der Bug in der 7.5. behoben

(Es kommt die Meldung "Zugriff verweigert" wie es eigentlich sein sollte).

Falls es mir noch irgendwann auffällt melde ich mich hier wieder.

lg,
Niki

dy/dx · Post by *dy/dx » 2010-07-22, 12:40 UTC

Hallo,

Nachdem seither schon mehrere Versionen herausgekommen sind und das Problem noch immer besteht glaube ich ziemlich sicher dass das ein Bug ist. Leider ein sehr störender denn als intensiver TC Nutzer muss ich so mehrmals pro Tag totalcmd.exe im Taskmanager killen und den TC dann erneut starten.

Ich habe mittlerweile einen Weg gefunden wie ich das Problem bei mir zu 100% reproduzieren kann:

1.) Man lege im TC ein Verzeichnis an, z.B. d:\test
2.) Parallel dazu: Start | Ausführen | cmd
3.) In dieses Verzeichnis wechseln: d: und cd test
4.) notepad test.txt ausführen
5.) Im Editor ein paar Zeilen reinschreiben, speichern, Datei offen lassen
6.) Im Total Commander das betreffende Verzeichnis löschen (cmd und notepad offen lassen!). CPU ist auf 100%, TC hängt.

6.b.) Falls es beim ersten Anlauf nicht klappt, mehrmals hintereinander das Verzeichnis mit SHIFT + ENTF löschen versuchen. Spätestens nach dem dritten Mal tritt dann der genannte Bug zu tage.

Weitere Infos: Windows XP Prof., angemeldet mit normalen Userrechten.

Das ganze passiert also offenbar wenn ein anderer Prozess noch ein Verzeichnis geöffnet hat das man mit dem Total Commander löschen möchte.

Nachdem das so reproduzierbar ist: Gibts ja nicht dass das nur bei mir auftritt oder?

LG,
dy/dx

Post by *ghisler(Author) » 2010-07-22, 14:06 UTC

Danke für die Anleitung, ich werde versuchen das zu reproduzieren. Bei meinen bisherigen Versuchen kommt nur die Meldung, das Verzeichnis könne nicht korrekt gelöscht werden. Getestet unter Windows XP SP3 (deutsche Version).

dy/dx · Post by *dy/dx » 2010-07-22, 16:48 UTC

Vielen Dank!

Aber komisch: Ich habe auch WinXP Prof. SP3, deutsch.

Haben Sie auch mit Userrechten probiert? Und wie gesagt auch öfters hintereinander? Bei mir kommt es manchmal vor dass beim ersten Mal auch die Meldung kommt dass das Verzeichnis nicht gelöscht werden kann und beim nächsten Versuch erst das beschriebene Phänomen.

Ich habe währenddessen auch den Process Monitor laufen lassen. Zum einen finde ich aber keine spannenden Informationen und zum anderen kommen keine Einträge mehr wenn das Phänomen (100% CPU) auftritt.

Gibt es von meiner Seite her irgendwas was ich tun kann? z.B. sowas wie ein strace. o.ä.?

LG,
dy/dx

Post by *ghisler(Author) » 2010-07-23, 19:42 UTC

Sie können es mal mit dem "process explorer" von der selben Seite versuchen, der kann (nach einem Doppelklick auf den Programmnamen) die einzelnen Threads eines Programms zeigen, und ob sie aktiv sind oder nicht. Anhand der Adressen könnte ich herausfinden, wo es hängt.

dy/dx · Post by *dy/dx » 2010-07-26, 14:32 UTC

Vielen Dank für das Angebot!

Wenn ich es richtig interpretiere hakt es an Adresse 0x2bf40c

Zur Klarheit ist hier mal ein Screenshot:

Image: http://img409.imageshack.us/img409/4636/tcmd1.png

(http://img409.imageshack.us/img409/4636/tcmd1.png)

Man sieht dass die CPU beim Thread mit ID 3512 ganz oben ist.

Das ist der Calling-Stack (also wenn man auf "Stack" klickt):

Code: Select all

ntdll.dll!KiFastSystemCallRet
user32.dll!PeekMessageW+0x167
TOTALCMD.EXE+0x19b84
TOTALCMD.EXE+0x19cca
TOTALCMD.EXE+0x6f820
TOTALCMD.EXE+0x6f010
TOTALCMD.EXE+0x14d3ea
TOTALCMD.EXE+0x44da0
TOTALCMD.EXE+0x14566
user32.dll!GetDC+0x6d
user32.dll!GetDC+0x14f
user32.dll!IsWindowUnicode+0xa1
user32.dll!CallWindowProcW+0x1b
TOTALCMD.EXE+0x44361
TOTALCMD.EXE+0x14566
user32.dll!GetDC+0x6d
user32.dll!GetDC+0x14f
user32.dll!DefWindowProcW+0x180
user32.dll!DefWindowProcW+0x1cc
ntdll.dll!KiUserCallbackDispatcher+0x13
user32.dll!PeekMessageW+0x167
ole32.dll!CoWaitForMultipleHandles+0x416b
ole32.dll!CoUnmarshalInterface+0x18fc
ole32.dll!CoUnmarshalInterface+0x1919
ole32.dll!CoUnmarshalInterface+0x1509
ole32.dll!StgGetIFillLockBytesOnFile+0x1081b
ole32.dll!StgGetIFillLockBytesOnFile+0x10223
ole32.dll!StgGetIFillLockBytesOnFile+0x10107
ole32.dll!CoUnmarshalInterface+0x15b6
ole32.dll!CoUnmarshalInterface+0x155f
ole32.dll!ReleaseStgMedium+0x127f
RPCRT4.dll!NdrProxySendReceive+0x40
RPCRT4.dll!NdrProxySendReceive+0x138
RPCRT4.dll!NdrProxySendReceive+0xcd
RPCRT4.dll!RpcBindingSetObject+0x4d
tiptsf.dll!ProcessCaretEvents+0x1c3d
tiptsf.dll+0x2680f
user32.dll!GetDC+0x6d
user32.dll!GetDC+0x14f
user32.dll!GetWindowLongW+0x127
user32.dll!DispatchMessageW+0xf
TOTALCMD.EXE+0x19c32
TOTALCMD.EXE+0x19cca
TOTALCMD.EXE+0x2bf7f3
kernel32.dll!RegisterWaitForInputIdle+0x49

LG,
dy/dx

Post by *ghisler(Author) » 2010-07-27, 14:35 UTC

Danke für den Stack! Mit welcher Version genau tritt das auf? 7.50? 7.50a? 7.55? 7.55a?

dy/dx · Post by *dy/dx » 2010-07-27, 19:36 UTC

Ui, und genau gestern hab ich von 7.55 auf 7.55a upgegraded!

Aber durch die tolle Loggingfunktion des TC

hab ich nun herausgefunden: Test durchgeführt: Ca. 16:25. Upgrade durchgeführt: Ca. 17:00

Also müsste der Test (incl. Stack) noch mit 7.55 stattgefunden haben ...

PS: Auftreten tut es natürlich mit allen (wie bereits geschrieben) nur der Stack stammt von 7.55...

Post by *ghisler(Author) » 2010-07-28, 15:07 UTC

OK, hier der analysierte Trace:

$19b84: forms.pas: 4465 TApplication.ProcessMessage
$19cca: forms.pas: 4503 TApplication.HandleMessage
$6f820: extmsgdl.pas: 313 extmsgboxW2
$6f010: extmsgdl.pas: 118 ExtMsgBoxCallback
$14d3ea: mainwin.pas: 6474 TTOTAL_CMD.OnMsgBoxCallBack
$44da0: controls.pas: 3517 TWinControl.MainWndProc
$14566: forms.pas: 1038 StdWndProc
$44361: controls.pas: 3170 TWinControlTrap.Win32Proc
$14566: forms.pas: 1038 StdWndProc
$19c32: forms.pas: 4480 TApplication.ProcessMessage
$19cca: forms.pas: 4503 TApplication.HandleMessage
$2bf7f3: totalcmd.pas: 335 TOTALCMD

TC versucht eine Dialog anzuzeigen (extmsgboxW2), um den Fehler zu melden. Weil Delphi-Dialoge nicht threadsicher sind, wird der Dialog im Hauptthread angezeigt (via OnMsgBoxCallBack). Entweder erscheint der Dialog bei Ihnen unter dem Programm, oder ausserhalb des Bildschirms. Schauen Sie mal, ob Sie mit Alt+Tab oder Alt+Enter zum Dialog kommen.

Vielleicht können Sie mir noch die Stacks der anderen Threads nennen, damit ich herausfinden kann, welche Funktion (welcher Hintergrundthread) den Dialog anzeigen wollte...

dy/dx · Post by *dy/dx » 2010-07-28, 17:07 UTC

Ok, mehrere Dinge:

1.) Dialog gibt es leider keinen, weder darunter, noch mit ALT+{TAB,ENTER}. Zumindest nicht so dass ich ihn sehen könnte

1.a.) Ich habe mit Spy++ versucht den Dialog zu finden allerdings kann man dort nicht nach Pid suchen weshalb mir die Suche zu aufwendig wurde.

2.) Allerdings könnte es natürlich sein dass der Fehler direkt im "Das Verzeichnis [...] konnte nicht korrekt gelöscht werden"-Dialog liegt. Vielleicht sagt ein Bild mehr als 1000 Worte:

Image: http://a.imageshack.us/img801/5104/tcmd2.png

Unten rechts ist gut zu erkennen dass die CPU auf 100% ist. Im Bild ist zu erkennen dass das Verzeichnis d:\temp gelöscht wurde (welches gleichzeitig in der cmd.exe in der Taskleiste geöffnet ist). Das Dialog ist allerdings normalerweise nur grau. Jetzt geschah es zum ersten Mal dass ich den Schriftzug "Das Verzeichnis D:\test konnte nicht gelöscht werden" drauf gesehen habe. Der Verdacht liegt also nahe dass Sie genau diesen Dialog meinen!

3.) Eine schlechte (allerdings logische Nachricht): Der Stack des Threads der die CPU verbratet ändert sich ständig. Allerdings ist das klar, denn die CPU arbeitet ja wie wild in diesem Thread. Womöglich eine Endlosschleife oder so?

4.) Ich habe jetzt von allen Threads die Stacks rauskopiert:

Code: Select all

TOTALCMD.EXE+0x2c0b4c
---------------------
TOTALCMD.EXE+0x310982
ntdll.dll!KiFastSystemCallRet
tiptsf.dll+0x14fe
user32.dll!MoveWindow+0xd4
user32.dll!MoveWindow+0x79
user32.dll!GetWindowTextLengthW+0x9a
ntdll.dll!KiUserCallbackDispatcher+0x13
user32.dll!PeekMessageW+0x167
TOTALCMD.EXE+0x19b80
TOTALCMD.EXE+0x19cc6
TOTALCMD.EXE+0x6fba8
TOTALCMD.EXE+0x6f398
TOTALCMD.EXE+0x14dbc6
TOTALCMD.EXE+0x45134
TOTALCMD.EXE+0x14562
user32.dll!GetDC+0x6d
user32.dll!GetDC+0x14f
user32.dll!IsWindowUnicode+0xa1
user32.dll!CallWindowProcW+0x1b
TOTALCMD.EXE+0x446f5
TOTALCMD.EXE+0x14562
user32.dll!GetDC+0x6d
user32.dll!GetDC+0x14f
user32.dll!DefWindowProcW+0x180
user32.dll!DefWindowProcW+0x1cc
ntdll.dll!KiUserCallbackDispatcher+0x13
user32.dll!PeekMessageW+0x167
ole32.dll!CoWaitForMultipleHandles+0x416b
ole32.dll!CoUnmarshalInterface+0x18fc
ole32.dll!CoUnmarshalInterface+0x1919
ole32.dll!CoUnmarshalInterface+0x1509
ole32.dll!StgGetIFillLockBytesOnFile+0x1081b
ole32.dll!StgGetIFillLockBytesOnFile+0x10223
ole32.dll!StgGetIFillLockBytesOnFile+0x10107
ole32.dll!CoUnmarshalInterface+0x15b6
ole32.dll!CoUnmarshalInterface+0x155f
ole32.dll!ReleaseStgMedium+0x127f
RPCRT4.dll!NdrProxySendReceive+0x40
RPCRT4.dll!NdrProxySendReceive+0x138
RPCRT4.dll!NdrProxySendReceive+0xcd
RPCRT4.dll!RpcBindingSetObject+0x4d
tiptsf.dll!ProcessCaretEvents+0x1c3d
tiptsf.dll+0x2680f
user32.dll!GetDC+0x6d
user32.dll!GetDC+0x14f
user32.dll!GetWindowLongW+0x127
user32.dll!DispatchMessageW+0xf
TOTALCMD.EXE+0x19c2e
TOTALCMD.EXE+0x19cc6
TOTALCMD.EXE+0x2c0f33
kernel32.dll!RegisterWaitForInputIdle+0x49

TOTALCMD.EXE+0x35f0
-------------------
ntdll.dll!KiFastSystemCallRet
user32.dll!GetLastInputInfo+0x105
user32.dll!MsgWaitForMultipleObjects+0x1f
TOTALCMD.EXE+0x21c4d8
TOTALCMD.EXE+0x227d2
TOTALCMD.EXE+0x361a
kernel32.dll!GetModuleFileNameA+0x1ba

advapi32.dll!WmiFreeBuffer+0xa7
-------------------------------
xpsp2res.dll+0x2409da
ntdll.dll!KiFastSystemCallRet
advapi32.dll!WmiFreeBuffer+0x24e
kernel32.dll!GetModuleFileNameA+0x1ba

TOTALCMD.EXE+0x35f0
-------------------
ntdll.dll!KiFastSystemCallRet
TOTALCMD.EXE+0x2291f
TOTALCMD.EXE+0x12c21d
TOTALCMD.EXE+0x227d2
TOTALCMD.EXE+0x361a
kernel32.dll!GetModuleFileNameA+0x1ba

TOTALCMD.EXE+0x35f0
-------------------
ntdll.dll!KiFastSystemCallRet
kernel32.dll!WaitForSingleObject+0x12
TOTALCMD.EXE+0x2997a1
TOTALCMD.EXE+0x227d2
TOTALCMD.EXE+0x361a
kernel32.dll!GetModuleFileNameA+0x1ba

ntdll.dll!RtlQueueWorkItem+0x283
--------------------------------
ntdll.dll!KiFastSystemCallRet
kernel32.dll!GetModuleFileNameA+0x1ba

ntdll.dll!wcsncpy+0x3b
----------------------
ntdll.dll!KiFastSystemCallRet
kernel32.dll!GetModuleFileNameA+0x1ba

TOTALCMD.EXE+0x35f0
-------------------
xpsp2res.dll+0x80a12
ntdll.dll!KiFastSystemCallRet
user32.dll!GetLastInputInfo+0x105
user32.dll!MsgWaitForMultipleObjects+0x1f
TOTALCMD.EXE+0x1ecc60
TOTALCMD.EXE+0x227d2
TOTALCMD.EXE+0x361a
kernel32.dll!GetModuleFileNameA+0x1ba

kernel32.dll!CreateThread+0x22
------------------------------
xpsp2res.dll+0xa0a12
ntdll.dll!KiFastSystemCallRet
RPCRT4.dll!I_RpcBCacheFree+0x61c
RPCRT4.dll!I_RpcBCacheFree+0x43e
RPCRT4.dll!I_RpcBCacheFree+0x604
kernel32.dll!GetModuleFileNameA+0x1ba

kernel32.dll!CreateThread+0x22
------------------------------
ntdll.dll!KiFastSystemCallRet
RPCRT4.dll!I_RpcBCacheFree+0x61c
RPCRT4.dll!I_RpcBCacheFree+0x43e
RPCRT4.dll!I_RpcBCacheFree+0x604
kernel32.dll!GetModuleFileNameA+0x1ba

TOTALCMD.EXE+0x35f0
-------------------
ntdll.dll!KiFastSystemCallRet
user32.dll!SendMessageA+0x49
TOTALCMD.EXE+0x6f33a
TOTALCMD.EXE+0x259281
TOTALCMD.EXE+0x2594b5
TOTALCMD.EXE+0x259d17
TOTALCMD.EXE+0x227d2
TOTALCMD.EXE+0x361a
kernel32.dll!GetModuleFileNameA+0x1ba

5.) Vielleicht ist es einfacher wenn ich Ihnen einen Speicherdump (erstellt mit dem Process Explorer) zukommen lasse? Können Sie damit was anfangen? Ich habe zum Zeitpunkt des Fehlers einen Dump (ca. 50MB) und einen Minidump (ca. 1MB) erstellt.

6.) Wie auf dem Screenshot zu erkennen ist die Version jetzt 7.55a

LG,
dy/dx