Analiza uruchamiania systemu Windows 7 z użyciem Xperfa

Z uwagi na coraz bardziej powszechne wykorzystywanie systemu Windows 7, użytkownicy instalują na nim coraz to nowsze i bardziej wymagające oprogramowanie, którego natłok obniża stopniowo jego wydajność. Spora część usług i aplikacji startuje automatycznie wraz z systemem, znacznie, a niekiedy zupełnie nieoczekiwanie wydłużając czas jego uruchamiania. W niniejszym artykule przyjrzymy się więc narzędziom pozwalającym na dokonanie dogłębnej analizy podejrzanie wydłużonego startu systemu Windows 7. Znając tego przyczynę, będziemy mogli odpowiednio zareagować i skrócić czas oczekiwania na osiągnięcie przez system stanu bezczynności, a co za tym idzie jego gotowości do pracy.

Przygotowanie

Aby uzyskać dostęp do opisywanych w tym artykule narzędzi, musimy zainstalować na komputerze pakiet Windows Performance Toolkit, wchodzący w skład Windows SDK for Windows 7 and .NET Framework 4.

Niezwykle przydatny okaże się także program Sysinternals Autologon. Umożliwi nam on automatyczne zalogowanie się do systemu w czasie przeprowadzanej diagnostyki, dzięki czemu będziemy mogli zmierzyć rzeczywisty czas uruchamiania systemu.

Pozyskiwanie śladów z rozruchu

Zanim przystąpimy do optymalizacji uruchamiania systemu Windows 7, musimy wykonać kilka zabiegów, które pozwolą nam na dokładne zlokalizowanie związanych z tym procesem problemów.

Z uwagi na wykonywane operacje, musimy zalogować się w systemie z użyciem konta użytkownika z prawami administratora. Wówczas uruchamiamy program Autologon i wprowadzamy do niego dane dotyczące naszego konta. Dzięki automatycznemu logowaniu nie będziemy musieli ręcznie wpisywać poświadczeń użytkownika, a co za tym idzie, nasze pomiary dotyczące czasu uruchamiania systemu nie będą zafałszowane. Następnie tworzymy nowy, osobny folder - na przykład C:\PerfTrace - w którym będzie przechowywany plik z pozyskanymi śladami rozruchu. Kiedy mamy już wszystko przygotowane, uruchamiamy wiersz poleceń z podniesionymi uprawnieniami, przechodzimy do utworzonego wcześniej katalogu C:\PerfTrace i wpisujemy poniższe polecenie:

xbootmgr –trace boot

Wykonanie tego polecenia spowoduje ponowny rozruch komputera, podczas którego zostaną przechwycone wszystkie informacje o uruchamianych wraz z systemem procesach, w tym także zdarzenia zachodzące już po (w tym wypadku automatycznym) zalogowaniu użytkownika. Na zebranie tych ostatnich zdarzeń program poświęci 120 sekund, dając nam w tym czasie możliwość wcześniejszego zakończenia procesu przechwytywania.

Analizowanie śladów rozruchu

Analizy śladów możemy dokonać na dwa sposoby. Pierwszy z nich polega na analizie wyeksportowanego pliku XML, w którym zawarte są odpowiednie punkty czasowe poszczególnych zdarzeń. Aby tego dokonać, w wierszu poleceń wykonujemy poniższe polecenie:

xperf –i boot_BASE+CSWITCH_1.etl –o summary.xml –a boot

Cały raport jest dość obszerny, zaś nam chodzi jedynie o informacje dotyczące uruchamiania systemu, dlatego też zawęziliśmy obszar poszukiwań, tak jak to przedstawia powyższy zrzut ekranu. Interesują nas jedynie dwa punkty czasowe, których wartości podano w milisekundach:

• bootDoneViaExplorer – czas po jakim uruchomiony zostaje proces Explorer.exe
• bootDoneViaPostBoot – całkowity czas potrzebny na uruchomienie systemu.

Z powyższego przykładu możemy odczytać, że do całkowitego uruchomienia Windows 7 potrzeba było 76 sekund. Jednak użyte przez nas narzędzie odczekuje dodatkowe 10 sekund (postBootRequiredIdleTime), by system mógł osiągnąć pełną bezczynność. Tak więc, aby otrzymać rzeczywisty czas rozruchu, należy odliczyć te 10 sekund - daje nam to w rezultacie 66 sekund na pełne uruchomienie systemu Windows 7.

Jak już wcześniej wspomnieliśmy, analizy śladów rozruchu możemy dokonać na dwa sposoby. Pierwszy - przeglądanie interesujących nas danych w dzienniku w formacie XML - już omówiliśmy, pora więc przejść do drugiego, wykorzystującego graficzną nakładkę XperfView. Aby tego dokonać wystarczy w wierszu poleceń wpisać poniższą komendę:

xperfview boot_BASE_CSWITCH_1.etl

Cały raport zawiera pokaźną ilość informacji, a że my zajmujemy się rozruchem systemu i procesem logowania, dlatego też skupimy się na sekcji Winlogon:

Na powyższym zrzucie ekranu widnieją różne punkty kontrolne. W naszym przypadku interesują nas tylko:

• GP Client – punkt ten pojawia się wielokrotnie: przed zalogowaniem użytkownika (Computer Group Policy) i po zalogowaniu (User Group Policy).
• CreateSession Notification – ten punkt kontrolny wskazuje moment, w którym użytkownik wprowadził swoje dane i rozpoczął się proces logowania.
• Profiles – moment, w którym został załadowany profil użytkownika.
• StartShell Notification – punkt kontrolny wskazujący moment, w którym powłoka systemu jest gotowa do załadowania i uruchomienia procesu explorer.exe.

Dzięki danym pozyskanym poprzez Xperf nie tylko dowiemy się ile czasu wymagane jest do wykonania pełnego rozruchu systemu, ale uzyskamy także informacje nt. próbkowania procesora, wykorzystania procesora i dysku przez procesy i wątki, procedur przerwania usług i opóźnionych wywołań procedur, błędów sprzętowych, a także szczegółowe dane dotyczące operacji wejścia/wyjścia dysków twardych.

Przeglądanie wyników śledzenia

Istnieją dwa sposoby wyświetlania plików dziennika:

• w wierszu poleceń z podniesionymi uprawnieniami wykonujemy xperf <nazwa pliku>.etl
• lub uruchamiamy graficzne narzędzie XperfView (Windows Performance Analyzer), a następnie z jego poziomu ręcznie otwieramy plik .etl.

Po otwarciu pliku dziennika, powinniśmy zobaczyć ekran zbliżony do poniższego:

UWAGA - O ile do uruchomienia programu Xperf wymaga się wiersza poleceń z podniesionymi uprawnieniami, to do analizy danych uprawnienia te nie są już wymagane.

Korzystając z zakładki Chart Selector (Wybór wykresu) możemy wybrać, które z wykresów chcielibyśmy obejrzeć. By szczegółowo przejrzeć dany wykres korzystamy z opcji Summary table (Tabela zbiorcza), znajdującej się w menu kontekstowym. Na przykład, na wykresie próbkowania procesora w oparciu o procesy (CPU Sampling by Process), wspomniana tabela podsumowuje uruchamiane podczas startu systemu procesy, wraz z takimi informacjami jak ilość czasu procesora, jego procent wykorzystania czy też stosy poszczególnych procesów. Przykładowo, patrząc na taką tabelę dla wykresu Disk I/O (Operacje wejścia/wyjścia dysku) można zobaczyć, które procesy zapisywały pliki (podane są także nazwy tych plików) na dysk, a także ile czasu im to zajęło.

Istnieje również możliwość nakładania na siebie wielu wykresów, co pozwala na szybkie porównywanie i zestawianie ze sobą różnych danych. Ponadto na każdym wykresie możemy wybrać liczniki, które chcemy zobaczyć - w prawym górnym rogu każdego z nich znajduje się rozwijana lista, z której wybieramy licznik instancji. Na przykład na wykresie Disk I/O, możemy wybrać dysk 0, dysk 1 lub oba dyski jednocześnie.

Rozpoczynanie śledzenia

Procesu śledzenia możemy także dokonać w czasie działania systemu operacyjnego, by uzyskać informacje na temat wykonywanych w nim zadań. Dla większości z nich, wszystko czego potrzeba do skutecznej analizy to śledzenie zdarzeń jądra. W przykładzie tym użyjemy parametru DiagEasy, aby umożliwić zbieranie wybranych zdarzeń jądra, w tym:

• ładowania obrazu
• operacji wejścia/wyjścia dysku
• zdarzeń procesu i wątku
• odwołań do pliku wymiany
• opóźnionych wywołań procedur i przerwań
• przełączania kontekstowego
• oraz liczników wydajności

xperf -on DiagEasy.

Spowoduje to wystartowanie rejestratora zdarzeń jądra w trybie sekwencyjnym, z zapisem do domyślnego pliku kernel.etl (w bieżącym katalogu), używając domyślnej wielkość bufora 64K, przy minimalnie 64 i maksymalnie 320 buforach.

Zatrzymywanie śledzenia

Aby zatrzymać śledzenie, wpisujemy w wierszu poleceń:

xperf -d <nazwa pliku>.etl 

Spowoduje to zatrzymanie kolekcjonowania danych i zapisanie ich do pliku dziennika o podanej nazwie. Plik ten możemy przeglądać i analizować korzystając z jednej ze wspomnianych wcześniej możliwości.

Podsumowanie

Mając tak szczegółowe dane dotyczące uruchamianych wraz z Windows 7 procesów i zachodzących w tym czasie zdarzeń, możemy bardzo szybko uzyskać informacje o zdarzeniach, które bezpośrednio wpływają na długi czas uruchamiania tego systemu. Nic nie stoi wówczas na przeszkodzie, by podjąć odpowiednie kroki usuwające namierzony w ten sposób problem. Może nim być wadliwy sterownik czy też aplikacja bądź usługa, która niepotrzebnie startuje wraz z systemem, w znacznym stopniu wydłużając czas jego uruchamiania.