Zine.net online

Witaj na Zine.net online Zaloguj się | Rejestracja | Pomoc
w Szukaj

mgrzeg.net - Admin on Rails :)

Procmon call stack, czyli symbole a narzędzia Sysinternals

Kilka lat temu (będzie już niedługo 5!) napisałem dla WSS tekst 'Admin czy nie admin' o narzędziach Sysinternals, dzięki którym można dosyć sprawnie poradzić sobie ze standardowymi problemami związanymi z ograniczonym dostępem do systemu. Linka nie podaję, ponieważ lada moment wss.pl przenosi się i zapewne stare sznurki pourywają się, więc ‘google is your friend’ :). Już wówczas były to potężne narzędzia diagnostyczne dające bardzo wiele informacji o tym co się aktualnie dzieje w systemie.
Od tamtej chwili upłynęło już trochę wody, a miejsce Filemona i Regmona zajął Procmon rozbudowany w stosunku do swoich poprzedników o wiele nowych funkcjonalności. Jedną z nich jest podgląd stosu wywołań (call stack), wraz ze wsparciem dla plików symboli. Poza procmonem taką funkcjonalność mają jeszcze Process Explorer oraz VMMap, co do reszty programów z SysinternalsSuite nie wypowiadam się, bo albo nie używam i nie wiem, albo nie zauważyłem, żeby była taka możliwość.
Na kilku przykładach spróbuję przybliżyć tę funkcjonalność, mam nadzieję, że ktoś z tego skorzysta.

Call Stack

W najprostszym ujęciu stos wywołania przedstawia przepływ wykonania dla danego programu. Podglądając go widzimy kolejno jakie funkcje były wywoływane z jakich modułów i wiemy gdzie aktualnie znajduje się wykonanie. Zgodnie z architekturą podczas wywołania funkcji odkładany jest na stos adres powrotu, który zdejmowany jest z niego w momencie powrotu z funkcji. Na samym dole stosu znajduje się pierwsza funkcja, z której wywołana została kolejna, a na górze stosu znajduje się adres powrotu do ostatniej funkcji, z której nastąpiło wywołanie.

Gdzie to mogę znaleźć w procmonie?

Dla każdego zdarzenia zarejestrowanego przez Procmon mamy możliwość podejrzenia stosu wywołań, który doprowadził nas do tego miejsca. Wystarczy dwa razy kliknąć interesujące nas zdarzenie (ewentualnie ctrl + p - properties) i wybrać zakładkę 'Stack'. W pierwszej kolumnie mamy informację o numerze ramki stosu oraz tryb użytkownika 'U', lub jądra 'K', w którym znajduje się wykonanie. Jako że Procmon zbiera głównie informacje I/O, nie dziwi nas to, że w większości przypadków na górze stosu mamy kilka ramek z trybu jądra, a niżej całe stado z trybu użytkownika.

Przykład 1 - odczyt pliku

Włączmy procmon i wykonajmy w wierszu polecenia:

>type c:\test.txt
ala nie ma kota

Zawężamy filtrami poszukiwania do 'Path is c:\test.txt' i szybko odnajdujemy coś podobnego do tego, co mam na Rys. 1:

13:47:05,9162779 cmd.exe 4444 QueryDirectory C:\test.txt SUCCESS Filter: test.txt, 1: test.txt
13:47:05,9165640 cmd.exe 4444 CreateFile C:\test.txt SUCCESS Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened
13:47:05,9166087 cmd.exe 4444 QueryBasicInformationFile C:\test.txt SUCCESS CreationTime: 2011-09-12 17:25:06, LastAccessTime: 2011-09-12 17:25:06, LastWriteTime: 2011-09-12 17:25:12, ChangeTime: 2011-09-12 17:25:12, FileAttributes: A
13:47:05,9166303 cmd.exe 4444 CloseFile C:\test.txt SUCCESS
13:47:05,9167975 cmd.exe 4444 CreateFile C:\test.txt SUCCESS Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened
13:47:05,9168605 cmd.exe 4444 QueryStandardInformationFile C:\test.txt SUCCESS AllocationSize: 16, EndOfFile: 15, NumberOfLinks: 1, DeletePending: False, Directory: False
13:47:05,9168837 cmd.exe 4444 ReadFile C:\test.txt SUCCESS Offset: 0, Length: 15, Priority: Normal
13:47:05,9170998 cmd.exe 4444 CloseFile C:\test.txt SUCCESS

Rys. 1. Type a procmon

Przy okazji filtrowania zachęcam do korzystania z 'Exclude Events Before' oraz 'Exclude Events After' - jak dla mnie rewelacja!
Wybierzmy przedostatnie zdarzenie (Operation = ReadFile) i zajrzyjmy do zakładki 'Stack' (Rys. 2):

Frame,Module,Location,Address,Path
0,fltmgr.sys,FltAcquirePushLockShared + 0x907,0xfffff88001316067,C:\Windows\system32\drivers\fltmgr.sys
1,fltmgr.sys,FltIsCallbackDataDirty + 0xa39,0xfffff88001317329,C:\Windows\system32\drivers\fltmgr.sys
2,fltmgr.sys,fltmgr.sys + 0x16c7,0xfffff880013156c7,C:\Windows\system32\drivers\fltmgr.sys
3,ntoskrnl.exe,NtCreateFile + 0x31b,0xfffff800031998ab,C:\Windows\system32\ntoskrnl.exe
4,ntoskrnl.exe,NtReadFile + 0x633,0xfffff8000317b223,C:\Windows\system32\ntoskrnl.exe
5,ntoskrnl.exe,KeSynchronizeExecution + 0x3a43,0xfffff80002e90f93,C:\Windows\system32\ntoskrnl.exe
6,ntdll.dll,NtReadFile + 0xa,0x7750137a,C:\Windows\SYSTEM32\ntdll.dll
7,KERNELBASE.dll,ReadFile + 0x7a,0x7fefd9c1aca,C:\Windows\system32\KERNELBASE.dll
8,kernel32.dll,ReadFile + 0x59,0x77191559,C:\Windows\system32\kernel32.dll
9,cmd.exe,cmd.exe + 0x1506e,0x4a84506e,C:\Windows\System32\cmd.exe
10,cmd.exe,cmd.exe + 0x14ee9,0x4a844ee9,C:\Windows\System32\cmd.exe
11,cmd.exe,cmd.exe + 0x14f5a,0x4a844f5a,C:\Windows\System32\cmd.exe
12,cmd.exe,cmd.exe + 0x3b04,0x4a833b04,C:\Windows\System32\cmd.exe
13,cmd.exe,cmd.exe + 0x1a52,0x4a831a52,C:\Windows\System32\cmd.exe
14,cmd.exe,cmd.exe + 0x88e8,0x4a8388e8,C:\Windows\System32\cmd.exe
15,cmd.exe,cmd.exe + 0x9962,0x4a839962,C:\Windows\System32\cmd.exe
16,kernel32.dll,BaseThreadInitThunk + 0xd,0x7719652d,C:\Windows\system32\kernel32.dll
17,ntdll.dll,RtlUserThreadStart + 0x21,0x774dc521,C:\Windows\SYSTEM32\ntdll.dll

Rys. 2. Call stack dla polecenia type i odczytu pliku

Robimy teraz małą sztuczkę, ponownie zaglądamy do właściwości tego samego zdarzenia, a wynik będzie następujący (Rys. 3):

Frame,Module,Location,Address,Path
0,fltmgr.sys,FltpPerformPreCallbacks + 0x2f7,0xfffff88001316067,C:\Windows\system32\drivers\fltmgr.sys
1,fltmgr.sys,FltpPassThrough + 0x2d9,0xfffff88001317329,C:\Windows\system32\drivers\fltmgr.sys
2,fltmgr.sys,FltpDispatch + 0xb7,0xfffff880013156c7,C:\Windows\system32\drivers\fltmgr.sys
3,ntoskrnl.exe,IopSynchronousServiceTail + 0xfb,0xfffff800031998ab,C:\Windows\system32\ntoskrnl.exe
4,ntoskrnl.exe,NtReadFile + 0x631,0xfffff8000317b223,C:\Windows\system32\ntoskrnl.exe
5,ntoskrnl.exe,KiSystemServiceCopyEnd + 0x13,0xfffff80002e90f93,C:\Windows\system32\ntoskrnl.exe
6,ntdll.dll,NtReadFile + 0xa,0x7750137a,C:\Windows\SYSTEM32\ntdll.dll
7,KERNELBASE.dll,ReadFile + 0x76,0x7fefd9c1aca,C:\Windows\system32\KERNELBASE.dll
8,kernel32.dll,ReadFileImplementation + 0x55,0x77191559,C:\Windows\system32\kernel32.dll
9,cmd.exe,TyWork + 0x170,0x4a84506e,C:\Windows\System32\cmd.exe
10,cmd.exe,LoopThroughArgs + 0x275,0x4a844ee9,C:\Windows\System32\cmd.exe
11,cmd.exe,eType + 0x1a,0x4a844f5a,C:\Windows\System32\cmd.exe
12,cmd.exe,FindFixAndRun + 0x2ad,0x4a833b04,C:\Windows\System32\cmd.exe
13,cmd.exe,Dispatch + 0x192,0x4a831a52,C:\Windows\System32\cmd.exe
14,cmd.exe,main + 0x454,0x4a8388e8,C:\Windows\System32\cmd.exe
15,cmd.exe,LUAGetUserType + 0x315,0x4a839962,C:\Windows\System32\cmd.exe
16,kernel32.dll,BaseThreadInitThunk + 0xd,0x7719652d,C:\Windows\system32\kernel32.dll
17,ntdll.dll,RtlUserThreadStart + 0x1d,0x774dc521,C:\Windows\SYSTEM32\ntdll.dll

Rys. 3. To samo, co wyżej, ale z symbolami

Procmon & Symbole

Skąd taka różnica?
Standardowo Procmon korzysta z biblioteki c:\windows\system32\dbghelp.dll, dostarczanej z systemem, która daje dostęp wyłącznie do eksportów i nie obsługuje serwera symboli (Rys 4).

Rys. 4. Standardowa konfiguracja symboli w Procmonie

Zrzućmy tablicę eksportów dla cmd.exe

>link /dump /exports c:\Windows\System32\cmd.exe
Microsoft (R) COFF/PE Dumper Version 10.00.30319.01
Copyright (C) Microsoft Corporation.  All rights reserved.
Dump of file c:\Windows\System32\cmd.exe
File Type: EXECUTABLE IMAGE
  Summary
       1E000 .data
        3000 .pdata
        5000 .rdata
        1000 .reloc
        9000 .rsrc
       28000 .text

i gołym okiem widzimy, że cmd.exe nic nam nie oferuje w ramach eksportów. (Alternatywnie możemy użyć Dependency Walkera i również stwierdzić pustą listę eksportów)

Aby skorzystać z dobrodziejstwa serwera publicznych symboli Microsoftu, ustawiamy ścieżkę do biblioteki dbghelp.dll z Debugging Tools for Windows, do tego ścieżkę do serwera symboli, np.:
srv*C:\websymbols*http://msdl.microsoft.com/downloads/symbols
i gotowe :)

Rys. 5. Ustawienie serwera symboli w Procmonie

Tu drobna uwaga: na systemach 64-bitowych procmon umożliwia przechwytywanie zdarzeń wyłącznie w wersji 64-bit, więc biblioteka dbghelp.dll musi również być 64-bitowa.

Procmon nie mając informacji o funkcjach, przedstawia ramki w postaci

9,cmd.exe,cmd.exe + 0x1506e,0x4a84506e,C:\Windows\System32\cmd.exe

natomiast po ściągnięciu i załadowaniu odpowiednich symboli ta sama ramka przedstawia się następująco:

9,cmd.exe,TyWork + 0x170,0x4a84506e,C:\Windows\System32\cmd.exe

Jak widać, w pierwszym przypadku przesunięcie w stosunku do początku funkcji (offset = 0x1506e) jest bardzo duże, co jest wyraźną oznaką braku symboli. Procmon w takiej sytuacji robi, co może i pokazuje przesunięcie względem najbliższej znanej mu funkcji, lub początku programu (jak ma to miejsce w przypadku cmd.exe).
W przypadku, gdy procmon ma dostępne wszystkie symbole sprawa jest prosta - offset jest mały (offset = 0x170) i dobrze wiemy z jakiej funkcji (TyWork) nastąpiło wywołanie.

Procmon a źródła

Drugi przykład pójdzie nieco dalej.
A co w sytuacji, gdy mamy prywatne symbole i źródła? Procmon chętnie z tego skorzysta i pokaże nam plik źródłowy i zaznaczy miejsce, z którego nastąpiło wywołanie! Niech ilustracją będzie poniższy zrzut (Rys. 6):

Rys. 6. Podgląd źródła dla konkretnej ramki ze stosu wywołań (po kliknięciu 'Source' dla ramki 13)

Przyglądamy się ramce nr 13 i widzimy, że z funkcji ProcMonDebugOutput zdefiniowanej w pliku procmondebugoutput.cpp (dokładniej: z linii 58), znajdującej się w bibliotece ProcMonDebugOutputx86.dll nastąpiło wywołanie funkcji DeviceIoControl z biblioteki kernel32.dll. Nie mamy co prawda wartości przekazywanych parametrów, ani żadnych innych informacji, ale Procmon jest stale rozwijany, więc kto wie, kto wie... może w którejś z następnych wersji... :)

Procmon a analiza systemu

Jeśli dwa pierwsze przykłady nie przekonały Cię jeszcze do zaglądania do zakładki 'Stack', to może tym razem? :)
W jednym z ostatnich tekstów pisałem o haśle komputera zapisywanym w sekretach LSASS. Wspominałem wówczas o narzędziu nltest, dzięki któremu możemy zmienić hasło komputera. Zobaczmy zatem, jakie informacje możemy uzyskać o systemie korzystając z procmona i stosu wywołań z symbolami.
Uruchamiamy zatem procmon, ustawiamy filtr na klucz rejestru zawierający ciąg $MACHINE.ACC i uruchamiamy nltest.exe:

>nltest /sc_change_pwd:mordor
Flagi: 0
Połączenie Status = 0 0x0 NERR_Success
Polecenie zostało wykonane pomyślnie.

Zaglądamy do procmona, a tam 37 zdarzeń związanych z procesem lsass.exe (nie nltest.exe!) oraz wspomnianym kluczem rejestru. Nasze zainteresowanie skupiamy na zdarzeniu, w którym następował zapis nowej wartości (Default typu REG_NONE) w kluczu $MACHINE.ACC\CurrVal (poza nim zapisywane są jeszcze: stara wartość w kluczu OldVal, czas aktualizacji w CupdTime oraz stary czas w OupdTime, ale nas to nie interesuje).

Rys. 7. Zapisywanie nowego hasła w sekrecie LSA wyłapane w procmonie

Zaglądamy do zakładki 'Stack' (Rys. 8) i przeglądamy stos wywołań.

Rys. 8. Stos wywołań związany z zapisem nowego hasła komputera w sekrecie LSA

Gołym okiem widać, że nltest zlecił do LSA poprzez RPC zmianę hasła, która została wykonana w ramach lsass.exe w module netlogon.dll (ramki 12 do 10, ze szczególnym uwzględnieniem ramki 11 i funkcji NlChangePassword). Dalej lsasrv wykonuje już tylko mrówczą pracę, czyli zapisanie sekretu w rejestrze.

Do dokładniejszej analizy można w tym momencie użyć narzędzia typu PEBrowse Professional (wersja 64-bit do obsługi bibliotek 64-bit, jak np. netlogon.dll, czy lsasrv.dll), które również ma pełne wsparcie dla serwera symboli i potrafi pobrać odpowiednie symbole z Microsoftu, po czym wgłębić się w sekcję Debug->Debug Symbols. Przeglądając kod trzeba pamiętać o offsecie względem początku funkcji, a także o tym, że adresy w pamięci mogą się różnić względem adresów zadeklarowanych jako base w module i odpowiednio je poprzeliczać. Zostawiam to jednak jako ćwiczenie dla chętnych.

Własne komunikaty w Procmonie

Procmon stale się rozwija, a Mark Russinovich dodaje nowe funkcjonalności które zgłaszają mu użytkownicy. Jedną z takich funkcjonalności jest możliwość przesyłania własnych komunikatów diagnostycznych do procmona. Aby coś takiego zrobić, wystarczy w czasie pracy procmona zapisać do urządzenia \\.\Global\ProcmonDebugLogger komunikat tekstowy (max 2047 znaków), a ten zostanie odebrany przez sterownik obsługujący Procmona i umieszczony na liście zdarzeń.

John Robbins umieścił na swoim blogu przykładowe rozwiązanie obejmujące natywne biblioteki (32+64-bit) przesyłające komunikat do procmona, a także bibliotekę zarządzaną opakowującą obie natywne w postaci TraceListenera do wykorzystania przy logowaniu z użyciem Trace.Write z System.Diagnostics (przykładowy projekt korzystający z nich w wersji natywnej oraz zarządzanej również są).  Korzystając z tego projektu przygotowałem wyżej opisany drugi przykład (funkcja ProcMonDebugOutput).

Nlog Target dla Process Monitora

Jako że korzystam od czasu do czasu z NLoga Jarka Kowalskiego, to pozwoliłem sobie w oparciu o kod Johna Robbinsa napisać odpowiedni Target do wykorzystania wraz z NLogiem, jednak całkowicie w kodzie zarządzanym. Wówczas mając przykładowy kod logujący z użyciem NLoga:

using System;
using NLog;
namespace ZineNlogTester
{
  class Program
  {
    private static Logger logger = LogManager.GetCurrentClassLogger();
    static void Main(string[] args)
    {
      logger.Warn("Warning");
      logger.Debug("Debug");
      logger.Info("Info");
      logger.Error("Error");
    }
  }
}

oraz plik konfiguracyjny NLog.config:

<?xml version="1.0" encoding="utf-8" ?>
<
nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
 xmlns:xsi=http://www.w3.org/2001/XMLSchema-instance>
<extensions>
 <
add assembly="Zine.ProcmonNlogTarget"/>
</
extensions>
<
targets>
 <
target name="procmon" type="Procmon" layout="NLOG: ${message}" />
</
targets>
<
rules>
 <
logger name="*" minLevel="Debug" writeTo="procmon"/>
</
rules>
</
nlog>

otrzymamy w oknie procmona odpowiednie zdarzenia naszej aplikacji (należy włączyć 'Show profiling events' -  ostatnia ikona na pasku narzędziowym) (Rys. 9)

Rys. 9. Nlog Target dla Procmona w akcji

Biblioteka z targetem oraz przykładowa aplikacja jest do ściągnięcia w załączniku do tego tekstu.

Uwagi końcowe

1. Procmon potrafi skorzystac ze zmiennej środowiskowej _NT_SYMBOL_PATH, więc ja dla przykładu mam ustawioną ścieżkę na
_NT_SYMBOL_PATH=srv*C:\websymbols*http://msdl.microsoft.com/downloads/symbols
dla całego systemu, dzięki czemu w różnych przedziwnych sytuacjach każdy proces ma dostęp do symboli i nie muszę się martwić o nic (a naprawdę sporo programów potrafi z tego skorzystać!)

2. Procmon nie potrafi pokazać prawidłowo stosu wywołań dla aplikacji zarządzanych. Zamiast nazw modułów pokazuje <unknown>, a zamiast nazw funkcji - adresy. Oczywiście, zaglądając do zakładki 'process' i porównując adres, w którym załadowana jest biblioteka z adresem z zakładki 'Stack' możemy się domyśleć o który moduł chodzi, ale nikomu tego nie polecam. Niewątpliwie jest to jeszcze praca do wykonania dla twórców Process Monitora i pewnie wystarczyłoby skorzystać z odpowiedniego sos.dll, żeby tę informację szybko wydłubać, ale na razie musimy na tę funkcjonalność jeszcze poczekać.

3. Jeśli zastanawiacie się skąd Procmon ma taką furę informacji, to odpowiadam: ETW. Myślę nad tekstem o Event Tracing for Windows i pewnie niebawem coś napiszę, ponieważ technologia warta jest krótkiego choćby opisu.

Opublikowane 16 września 2011 19:28 przez mgrzeg
Attachment(s): http://zine.net.pl/Misc/Zine.NlogProcmon.zip

Powiadamianie o komentarzach

Jeżeli chciałbyś otrzymywać email gdy ta wypowiedź zostanie zaktualizowana, to zarejestruj się tutaj

Subskrybuj komentarze za pomocą RSS

Komentarze:

 

omeg said:

Procmon to bardzo fajne narzędzie, ale jego główną wadą jest obsługa tylko wąskiego zakresu funkcji API. Ostatnio na przykład potrzebowałem zbadać, co jest przyczyną "magicznego" unloadowania mojej DLLki obsługującej windows hooki ze wszystkich procesów. Zadanie aż się prosiło o monitorowanie FreeLibrary i podobnych - niestety, Process Monitor tego nie potrafi (próbowałem podawać nazwę funkcji w polu "Operation" filtra). Rozwiązaniem okazał się Api Monitor (http://www.rohitab.com/apimonitor) - nowa wersja świetnego narzędzia, to cacko potrafi nawet pokazywać parametry wywołań funkcji. :)

Ostatecznie moim problemem okazało się to, że hooki założone wewnątrz wątku są ubijane, kiedy tenże wątek umiera - co nie jest udokumentowane w oficjalnej dokumentacji MSDN. :)

września 17, 2011 11:07
 

mgrzeg said:

@omeg: Zgadza się, Procmon nie ma takiej funkcjonalności. Odnośnie APIMona to w marcu pisałem to i owo o nim:

http://zine.net.pl/blogs/mgrzeg/archive/2011/03/01/securestring-a-kod-natywny.aspx

http://zine.net.pl/blogs/mgrzeg/archive/2011/03/07/tajemnica-systemfunction040-czyli-jeszcze-o-api-monitorze.aspx

i oczywiście baaardzo gorąco go polecam :)

września 17, 2011 14:32
 

dotnetomaniak.pl said:

Dziękujemy za publikację - Trackback z dotnetomaniak.pl

września 18, 2011 08:58
 

When procmon trace is not enough – Low Level Design said:

lutego 20, 2017 08:53

Co o tym myślisz?

(wymagane) 
(opcjonalne)
(wymagane) 

  
Wprowadź kod: (wymagane)
Wyślij

Subskrypcje

W oparciu o Community Server (Personal Edition), Telligent Systems