Esempio 15: Misurazione del tempo DPC/ISR
È possibile misurare la quantità di tempo trascorso da un driver nelle chiamate di routine posticipate (DPC) e nelle routine del servizio di interruzione tracciando questi eventi nel kernel di Windows. Queste informazioni consentono di ridurre al minimo il tempo trascorso dal driver a irQLs più elevati, rendendo più efficiente il driver e il sistema.
Microsoft consiglia che i CONTROLLER di rete non debbano essere eseguiti più di 100 microsecondi e gli ISR non debbano essere eseguiti più di 25 microsecondi. Per i requisiti più recenti, vedere Hardware Lab Kit.
La procedura descritta in questa sezione include i passaggi seguenti:
Avviare la traccia del kernel degli eventi DPC/ISR.
Monitorare la sessione di traccia per individuare gli eventi persi e, se necessario, aumentare le dimensioni dei buffer di traccia.
Esercizio del driver di test.
Arrestare la sessione di traccia.
Usare Tracerpt per generare un report che riepiloga l'attività DPC/ISR.
Analizzare i report
Passaggio 1: Avviare una sessione di traccia.
Il comando seguente avvia una sessione di traccia del logger del kernel NT:
tracelog -start -f test01.etl -dpcisr -UsePerfCounter -b 64
Il comando tracelog -start avvia la sessione di traccia. Poiché "NT Kernel Logger" è il nome di sessione predefinito, non è necessario specificarlo e non è possibile usare il parametro -guid per specificare un file del provider. Il comando usa il parametro -f per indicare una sessione di log e indirizzare i messaggi di traccia al file di log di traccia degli eventi test01.etl .
Il comando include il parametro -dpcisr per abilitare la traccia dei DPC, degli ISR, dei commutatori di contesto e del caricamento delle immagini.
Quando si tracciano controller di rete e isr, aggiungere sempre il parametro -UsePerfCounter al comando. La risoluzione del timer di sistema è troppo bassa per misurare il tempo impiegato in queste attività. Inoltre, Tracerpt, lo strumento che formatta gli eventi DPC/ISR, richiede i valori di clock del contatore delle prestazioni per i relativi report. Tracerpt è incluso in Windows XP e versioni successive di Windows.
Infine, il comando usa il parametro -b per aumentare le dimensioni dei buffer di traccia a 64 KB. Poiché la traccia DPC/ISR genera un volume elevato di messaggi di traccia a una velocità rapida, è importante aumentare le dimensioni dei buffer di traccia in modo da non perdere eventi.
In risposta a questo comando, Tracelog avvia la sessione NT Kernel Logger e ne visualizza le proprietà.
Logger Started...
Operation Status: 0L The operation completed successfully.
Logger Name: NT Kernel Logger
Logger Id: ffff
Logger Thread Id: 00000C18
Buffer Size: 64 Kb
Maximum Buffers: 25
Minimum Buffers: 3
Number of Buffers: 5
Free Buffers: 4
Buffers Written: 14
Events Lost: 0
Log Buffers Lost: 0
Real Time Buffers Lost: 0
AgeLimit: 15
Log File Mode: Sequential
Enabled tracing: Process Thread Disk File ImageLoad
Log Filename: c:\Tracelog\test01.etl
Si noti che gli eventi DPC, ISR e cambio di contesto non vengono visualizzati nel campo Di traccia abilitato della visualizzazione. Poiché questi eventi vengono monitorati dalla strumentazione interna, non vengono visualizzati in questo elenco anche quando sono abilitati. Tuttavia, vengono visualizzati gli eventi di caricamento delle immagini, che sono abilitati anche dal parametro -dpcisr .
Passaggio 2: Verificare la presenza di eventi persi.
Usare periodicamente un comando tracelog -q (query) per verificare la presenza di eventi persi. Se vengono trovate, usare un comando tracelog -update per aggiungere altri buffer alla sessione di traccia.
tracelog -q
Il comando tracelog -q accetta un nome di sessione, ma non è necessario specificarne uno in questo caso perché "NT Kernel Logger" è l'impostazione predefinita.
In risposta a questo comando, Tracelog visualizza le proprietà della sessione.
Operation Status: 0L The operation completed successfully.
Logger Name: NT Kernel Logger
Logger Id: ffff
Logger Thread Id: 00000BC4
Buffer Size: 64 Kb
Maximum Buffers: 25
Minimum Buffers: 3
Number of Buffers: 25
Free Buffers: 23
Buffers Written: 571
Events Lost: 544
Log Buffers Lost: 0
Real Time Buffers Lost: 0
AgeLimit: 15
Log File Mode: Sequential
Enabled tracing: Process Thread Disk File ImageLoad
Log Filename: c:\Tracelog\test.etl
In questo caso, 544 eventi generati non sono stati salvati in un buffer. Per evitare che ciò si ripeta, usare un comando tracelog -update per aumentare le dimensioni di ogni buffer (-b) o aumentare il numero massimo di buffer (-max), ad esempio:
tracelog -update -b 128 -max 40
Passaggio 3: Esercizio del driver.
Usare le routine di test per fare in modo che il driver esegua le funzioni. Prendere in considerazione l'esecuzione di due test, uno per le funzioni di base e uno per le funzioni più avanzate.
Passaggio 4: Arrestare la sessione di traccia.
Usare il comando seguente per arrestare la sessione di traccia:
tracelog -stop
Un comando tracelog -stop richiede in genere un nome di sessione, ma poiché "NT Kernel Logger" è l'impostazione predefinita, il nome della sessione non è obbligatorio.
Passaggio 5: Creare un report DPC/ISR.
Per riepilogare i messaggi DPC/ISR nel registro di traccia eventi, usare la versione di Tracerpt inclusa in Windows XP con SP2 e versioni successive di Windows.
Il comando Tracerpt seguente formatta i messaggi nel file Test01.etl e crea un report formattato in testo dell'attività in Windows XP con SP2.
tracerpt test01.etl -report dpcisr.txt -df
In questo comando, il parametro -report specifica il metodo di analisi e il nome del file di output. Il parametro -df è necessario per formattare correttamente i messaggi solo in Windows XP con SP2.
Quando si crea questo report in Windows Server 2003 con SP1 e versioni successive di Windows, è possibile creare un report in formato HTML usando il comando seguente.
tracerpt test01.etl -report dpcisr.html -f HTML
In questo comando, il parametro -report specifica il nome del file di output e il parametro -f specifica il formato del report.
Passaggio 6: Analizzare il report.
Il "Report sessione di traccia eventi di Windows" include le sezioni seguenti:
Statistiche immagine. Visualizza i dati sui processi in esecuzione nel computer durante la traccia.
Totali disco. Visualizza i dati sull'I/O del disco per ogni processo in esecuzione durante la traccia.
Utilizzo del processore DPC per l'intera traccia: visualizza la percentuale di tempo del processore impiegato per la manutenzione delle routine DPC per ogni driver.
Distribuzione di tutti i tempi di esecuzione DPC per l'intera traccia. Tabella degli intervalli di tempo in unità di microsecondo. Nella tabella viene visualizzata la percentuale di routine DPC che rientrano in ogni intervallo di tempo.
Distribuzione dei tempi di esecuzione DPCRoutineAddress ( DPCRoutineAddress ) per l'intera traccia. Tabella degli intervalli di tempo in unità di microsecondo. Nella tabella viene visualizzata la percentuale di istanze di questa routine DPC che rientrano in ogni intervallo di tempo. Viene visualizzata una sezione simile a questa per ogni routine DPC nella traccia.
Utilizzo del processore ISR per l'intera traccia. Visualizza la percentuale di tempo del processore impiegato per la manutenzione delle routine del servizio di interruzione per ogni driver nella traccia.
Distribuzione di tutti i tempi di esecuzione ISR per l'intera traccia. Tabella degli intervalli di tempo in unità di microsecondo. Nella tabella viene visualizzata la percentuale di routine ISR che rientrano in ogni intervallo di tempo.
Distribuzione di DriverName ( ISRAddress ) tempi di esecuzione ISR per l'intera traccia. Tabella degli intervalli di tempo in unità di microsecondo. Nella tabella viene visualizzata la percentuale di istanze dell'ISR che rientrano in ogni intervallo di tempo. Viene visualizzata una sezione come questa per ogni ISR nella traccia.
Distribuzione dell'utilizzo del processore DPC e ISR per TracingPeriodInMs con due finestre temporali di microsecondo. Visualizza l'utilizzo combinato del processore da parte di DPC e ISR durante la traccia.
Distribuzione di DriverName ( ISRAddress ) ISR a DriverName ( DPCRoutineAddress ) latenze DPC per l'intera traccia. Visualizza la distribuzione degli intervalli di ritardo tra la fine di un ISR e l'inizio del DPC associato.
Nell'estratto seguente di un report di esempio viene illustrata la distribuzione dei tempi di esecuzione DPC per Ipsec.sys. In generale, le routine DPC che durano più di 100 microsecondi sono sconsigliate. Il report mostra che più della metà delle routine DPC per questo driver supera la soglia.
+------------------------------------------------------------------------------+
| Distribution of ipsec.sys (F7AA7449) DPC execution times for the whole trace |
+------------------------------------------------------------------------------+
| Lower Bound Upper Bound Count Percent |
+------------------------------------------------------------------------------+
| 0 1 0 0.00% |
| 1 2 0 0.00% |
| 2 3 8 42.11% |
| 3 4 1 5.26% |
| 4 5 0 0.00% |
| 5 10 0 0.00% |
| 10 25 0 0.00% |
| 25 50 0 0.00% |
| 50 100 0 0.00% |
| 100 250 10 52.63% |
+------------------------------------------------------------------------------+
| 19 100.00% |
+------------------------------------------------------------------------------+