예제 15: DPC/ISR 시간 측정
Windows 커널에서 이러한 이벤트를 추적하여 드라이버가 DPC(지연 프로시저 호출) 및 ISR(인터럽트 서비스 루틴)에 소요되는 시간을 측정할 수 있습니다. 이 정보는 드라이버가 더 높은 IRQL에서 소비하는 시간을 최소화하여 드라이버와 시스템을 보다 효율적으로 만드는 데 도움이 됩니다.
Microsoft는 DDP가 100 마이크로초보다 오래 실행되지 않아야 하며 ISR은 25 마이크로초보다 오래 실행되지 않는 것이 좋습니다. 최신 요구 사항은 하드웨어 랩 키트를 참조하세요.
이 섹션에서 설명하는 절차는 다음 단계를 포함합니다.
DPC/ISR 이벤트의 커널 추적을 시작합니다.
손실된 이벤트에 대한 추적 세션을 모니터링하고 필요한 경우 추적 버퍼의 크기를 늘입니다.
테스트 드라이버를 실행합니다.
추적 세션을 중지합니다.
Tracerpt를 사용하여 DPC/ISR 활동을 요약하는 보고서를 생성합니다.
보고서 분석
1단계: 추적 세션을 시작합니다.
다음 명령은 NT 커널 로거 추적 세션을 시작합니다.
tracelog -start -f test01.etl -dpcisr -UsePerfCounter -b 64
tracelog -start 명령은 추적 세션을 시작합니다. "NT 커널 로거"는 기본 세션 이름이기 때문에 지정할 필요가 없으며 -guid 매개 변수를 사용하여 공급자 파일을 지정할 수 없습니다. 이 명령은 -f 매개 변수를 사용하여 로그 세션을 나타내고 추적 메시지를 test01.etl 이벤트 추적 로그 파일로 보냅니다.
이 명령에는 DPC, ISR, 컨텍스트 스위치 및 이미지 로드를 추적할 수 있도록 하는 -dpcisr 매개 변수가 포함됩니다.
DDP 및 ISR을 추적할 때는 항상 -UsePerfCounter 매개 변수를 명령에 추가합니다. 시스템 타이머 해상도가 너무 낮아 이러한 활동에 소요된 시간을 측정할 수 없습니다. 또한 DPC/ISR 이벤트의 형식을 지정하는 도구인 Tracerpt에는 보고서에 대한 성능 카운터 클록 값이 필요합니다. Tracerpt는 Windows XP 이상 버전의 Windows에 포함되어 있습니다.
마지막으로 이 명령은 -b 매개 변수를 사용하여 추적 버퍼의 크기를 64KB로 늘입니다. DPC/ISR 추적은 빠른 속도로 대량의 추적 메시지를 생성하므로 이벤트를 잃지 않도록 추적 버퍼의 크기를 늘리는 것이 중요합니다.
이 명령에 대한 응답으로 Tracelog는 NT 커널 로거 세션을 시작하고 해당 속성을 표시합니다.
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
DPC, ISR 및 컨텍스트 전환 이벤트는 디스플레이의 사용 추적 필드에 표시되지 않습니다. 이러한 이벤트는 내부 계측에 의해 모니터링되므로 사용하도록 설정된 경우에도 이 목록에 표시되지 않습니다. 그러나 -dpcisr 매개 변수에서도 사용하도록 설정된 이미지 로드 이벤트가 나타납니다.
2단계: 손실된 이벤트를 확인합니다.
추적 로그 -q(쿼리) 명령을 주기적으로 사용하여 손실된 이벤트를 검사. 찾을 경우 tracelog -update 명령을 사용하여 추적 세션에 버퍼를 더 추가합니다.
tracelog -q
tracelog -q 명령은 세션 이름을 사용하지만 이 경우 "NT 커널 로거"가 기본값이므로 이를 제공할 필요가 없습니다.
이 명령에 대한 응답으로 Tracelog는 세션의 속성을 표시합니다.
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
이 경우 생성된 544개의 이벤트가 버퍼에 저장되지 않았습니다. 이 문제가 되풀이되지 않도록 하려면 tracelog -update 명령을 사용하여 각 버퍼(-b)의 크기를 늘리거나 최대 버퍼 수(-max)를 늘입니다. 예를 들면 다음과 같습니다.
tracelog -update -b 128 -max 40
3단계: 드라이버를 연습합니다.
테스트 루틴을 사용하여 드라이버가 해당 기능을 수행하도록 합니다. 두 가지 테스트를 실행하는 것이 좋습니다. 하나는 기본 함수용이고 다른 하나는 고급 함수용입니다.
4단계: 추적 세션을 중지합니다.
다음 명령을 사용하여 추적 세션을 중지합니다.
tracelog -stop
tracelog -stop 명령은 일반적으로 세션 이름이 필요하지만 "NT 커널 로거"가 기본값이므로 세션 이름이 필요하지 않습니다.
5단계: DPC/ISR 보고서를 만듭니다.
이벤트 추적 로그에서 DPC/ISR 메시지를 요약하려면 Windows XP에 포함된 Tracerpt 버전을 SP2 이상 버전의 Windows와 함께 사용합니다.
다음 Tracerpt 명령은 Test01.etl 파일의 메시지 형식을 지정하고 WINDOWS XP에서 SP2를 사용하여 작업의 텍스트 형식 보고서를 만듭니다.
tracerpt test01.etl -report dpcisr.txt -df
이 명령 에서 -report 매개 변수는 분석 방법 및 출력 파일의 이름을 지정합니다. -df 매개 변수는 WINDOWS XP SP2에서만 메시지의 형식을 올바르게 지정하는 데 필요합니다.
WINDOWS Server 2003 SP1 이상 버전의 Windows에서 이 보고서를 만들 때 다음 명령을 사용하여 HTML 형식 보고서를 만들 수 있습니다.
tracerpt test01.etl -report dpcisr.html -f HTML
이 명령 에서 -report 매개 변수는 출력 파일의 이름을 지정하고 -f 매개 변수는 보고서 형식을 지정합니다.
6단계: 보고서를 분석합니다.
"Windows 이벤트 추적 세션 보고서"에는 다음 섹션이 있습니다.
이미지 통계. 추적 중에 컴퓨터에서 실행되는 프로세스에 대한 데이터를 표시합니다.
디스크 합계입니다. 추적 중에 실행되는 각 프로세스의 디스크 I/O에 대한 데이터를 표시합니다.
전체 추적에 대한 DPC 프로세서 사용률: 각 드라이버에 대한 DPC 루틴을 서비스하는 데 소요된 프로세서 시간의 비율을 표시합니다.
전체 추적에 대한 모든 DPC 실행 시간의 분포입니다. 시간 범위(마이크로초 단위)입니다. 표에는 각 시간 범위에 속하는 DPC 루틴의 백분율이 표시됩니다.
전체 추적에 대한 DriverName(DPCRoutineAddress) DPC 실행 시간의 분포입니다. 시간 범위(마이크로초 단위)입니다. 표에는 각 시간 범위에 속하는 이 DPC 루틴의 인스턴스 백분율이 표시됩니다. 추적의 모든 DPC 루틴에 대해 이와 같은 섹션이 나타납니다.
전체 추적에 대한 ISR 프로세서 사용률입니다. 추적의 각 드라이버에 대한 인터럽트 서비스 루틴을 서비스하는 데 소요된 프로세서 시간의 비율을 표시합니다.
전체 추적에 대한 모든 ISR 실행 시간의 분포입니다. 시간 범위(마이크로초 단위)입니다. 테이블에는 각 시간 범위에 속하는 ISR 루틴의 백분율이 표시됩니다.
전체 추적에 대한 DriverName(ISRAddress) ISR 실행 시간의 분포입니다. 시간 범위(마이크로초 단위)입니다. 테이블에는 각 시간 범위에 속하는 ISR 인스턴스의 백분율이 표시됩니다. 추적의 모든 ISR에 대해 다음과 같은 섹션이 나타납니다.
TracingPeriodInMs에 대한 DPC 및 ISR 프로세서 사용률 배포 2 마이크로초 시간 창. 추적 중에 DPC 및 ISR의 결합된 프로세서 사용률을 표시합니다.
전체 추적에 대한 DriverName(ISRAddress) ISR을 DriverName(DPCRoutineAddress) DPC 대기 시간으로 배포합니다. ISR의 끝과 연결된 DPC의 시작 사이의 지연 간격 분포를 표시합니다.
샘플 보고서에서 발췌한 다음 내용은 Ipsec.sys DPC 실행 시간의 분포를 보여 줍니다. 일반적으로 100 마이크로초 이상 지속되는 DPC 루틴은 권장되지 않습니다. 보고서에 따르면 이 드라이버에 대한 DPC 루틴의 절반 이상이 임계값을 초과하는 것으로 표시됩니다.
+------------------------------------------------------------------------------+
| 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% |
+------------------------------------------------------------------------------+