1 /*++
2
3 Copyright (c) Microsoft Corporation
4
5 Module Name:
6
7 Tracing.cpp
8
9 Abstract:
10
11 This module implements tracing for the driver frameworks
12
13 Author:
14
15
16
17 Environment:
18
19 Kernel mode only
20
21 Revision History:
22
23
24
25
26
27 --*/
28
29 #include "fxcorepch.hpp"
30
31 // We use DoTraceMessage
32 extern "C" {
33 // #include "tracing.tmh"
34 }
35
36 #include <initguid.h>
37 #include "fxifr.h" // shared struct between IFR and debug ext.
38 #include "fxifrkm.h" // kernel mode only IFR definitions
39
40
41 //=============================================================================
42 //
43 //=============================================================================
44
45 _Must_inspect_result_
46 NTSTATUS
FxTraceInitialize(VOID)47 FxTraceInitialize(
48 VOID
49 )
50
51 /*++
52
53 Routine Description:
54
55 This routine initializes the frameworks tracing.
56
57 It must be called early on in the frameworks DriverEntry
58 initialization.
59
60 Arguments:
61
62 None
63
64 Returns:
65
66 NTSTATUS code
67
68 --*/
69 {
70 //
71 // Initialize the tracing package: Vista or later
72 //
73 WPP_INIT_TRACING(NULL, NULL);
74
75 return STATUS_SUCCESS;
76 }
77
78 VOID
TraceUninitialize(VOID)79 TraceUninitialize(
80 VOID
81 )
82 /*++
83
84 Routine Description:
85 This routine uninitializes the frameworks tracing. It must be called just
86 before DriverUnload
87
88 Arguments:
89 None
90
91 Returns:
92 None
93
94 --*/
95 {
96 //
97 // Vista and later
98 //
99 WPP_CLEANUP(NULL);
100 }
101
102 _Must_inspect_result_
103 NTSTATUS
FxWmiTraceMessage(__in TRACEHANDLE LoggerHandle,__in ULONG MessageFlags,__in LPGUID MessageGuid,__in USHORT MessageNumber,__in...)104 FxWmiTraceMessage(
105 __in TRACEHANDLE LoggerHandle,
106 __in ULONG MessageFlags,
107 __in LPGUID MessageGuid,
108 __in USHORT MessageNumber,
109 __in ...
110 )
111 {
112 NTSTATUS status;
113 va_list va;
114
115 va_start(va, MessageNumber);
116
117 #pragma prefast(suppress:__WARNING_BUFFER_OVERFLOW, "Recommneded by EndClean");
118 status = WmiTraceMessageVa(LoggerHandle,
119 MessageFlags,
120 MessageGuid,
121 MessageNumber,
122 va);
123 va_end(va);
124
125 return status;
126 }
127
128
129 //-----------------------------------------------------------------------------
130 // Subcomponents for the In-Flight Recorder follow.
131 //-----------------------------------------------------------------------------
132
133 ULONG
FxIFRGetSize(__in PFX_DRIVER_GLOBALS FxDriverGlobals,__in PCUNICODE_STRING RegistryPath)134 FxIFRGetSize(
135 __in PFX_DRIVER_GLOBALS FxDriverGlobals,
136 __in PCUNICODE_STRING RegistryPath
137 )
138 /*++
139
140 Routine Description:
141 Checks to see if the service has overriden the default number of pages that
142 are in the IFR.
143
144 Arguments:
145 RegistryPath - path to the service
146
147 Return Value:
148 The size of the IFR to create in bytes (not pages!)
149
150 --*/
151 {
152 FxAutoRegKey service, parameters;
153 NTSTATUS status;
154 OBJECT_ATTRIBUTES oa;
155 ULONG numPages;
156
157 //
158 // This is the value used in case of any error while retrieving 'LogPages'
159 // from the registry.
160 //
161 numPages = FxIFRMinLogPages;
162
163 //
164 // External representation of the IFR is the "LogPages", so use that term when
165 // overriding the size via the registry.
166 //
167 DECLARE_CONST_UNICODE_STRING(parametersPath, L"Parameters\\Wdf");
168 DECLARE_CONST_UNICODE_STRING(valueName, L"LogPages");
169
170 InitializeObjectAttributes(&oa,
171 (PUNICODE_STRING)RegistryPath,
172 OBJ_KERNEL_HANDLE | OBJ_CASE_INSENSITIVE,
173 NULL,
174 NULL);
175
176 status = ZwOpenKey(&service.m_Key, KEY_READ, &oa);
177 if (!NT_SUCCESS(status)) {
178 goto defaultValues;
179 }
180
181 InitializeObjectAttributes(&oa,
182 (PUNICODE_STRING)¶metersPath,
183 OBJ_KERNEL_HANDLE | OBJ_CASE_INSENSITIVE,
184 service.m_Key,
185 NULL);
186
187 status = ZwOpenKey(¶meters.m_Key, KEY_READ, &oa);
188
189 if (!NT_SUCCESS(status)) {
190 goto defaultValues;
191 }
192
193 status = FxRegKey::_QueryULong(parameters.m_Key, &valueName, &numPages);
194 if (!NT_SUCCESS(status)) {
195 goto defaultValues;
196 }
197
198 if (numPages == 0) {
199 numPages = FxIFRMinLogPages;
200 }
201
202 defaultValues:
203 //
204 // Use FxIFRAvgLogPages if user specifies greater than FxIFRMaxLogPages and if
205 // Verifier flag is on and so is Verbose flag.
206 //
207 if (numPages > FxIFRMaxLogPages) {
208 if (FxDriverGlobals->FxVerifierOn && FxDriverGlobals->FxVerboseOn) {
209 numPages = FxIFRAvgLogPages;
210 }
211 else {
212 numPages = FxIFRMinLogPages;
213 }
214 }
215
216 return numPages * PAGE_SIZE;
217 }
218
219 VOID
FxIFRStart(__in PFX_DRIVER_GLOBALS FxDriverGlobals,__in PCUNICODE_STRING RegistryPath,__in MdDriverObject DriverObject)220 FxIFRStart(
221 __in PFX_DRIVER_GLOBALS FxDriverGlobals,
222 __in PCUNICODE_STRING RegistryPath,
223 __in MdDriverObject DriverObject
224 )
225 /*++
226
227 Routine Description:
228
229 This routine initialize the In-Flight Recorder (IFR).
230
231 The default log size is set by WDF_IFR_LOG_SIZE and currently
232 is 4096 (one x86 page).
233 This routine should be called very early in driver initialization
234 to allow the capture of all significant events.
235
236 --*/
237 {
238 PWDF_IFR_HEADER pHeader;
239 ULONG size;
240
241 UNREFERENCED_PARAMETER( DriverObject );
242
243 WDFCASSERT(FxIFRRecordSignature == WDF_IFR_RECORD_SIGNATURE);
244
245 //
246 // Return early if IFR is disabled.
247 //
248 if (FxLibraryGlobals.IfrDisabled) {
249 ASSERT(FxDriverGlobals->WdfLogHeader == NULL);
250 return;
251 }
252
253 if (FxDriverGlobals == NULL || FxDriverGlobals->WdfLogHeader != NULL) {
254 return;
255 }
256
257 size = FxIFRGetSize(FxDriverGlobals, RegistryPath);
258
259 pHeader = (PWDF_IFR_HEADER) ExAllocatePoolWithTag(NonPagedPool,
260 size,
261 WDF_IFR_LOG_TAG );
262 if (pHeader == NULL) {
263 return;
264 }
265
266 RtlZeroMemory(pHeader, size);
267
268 //
269 // Initialize the header.
270 // Base will be where the IFR records are placed.
271 // WPP_ThisDir_CTLGUID_FrameworksTraceGuid
272 //
273 RtlCopyMemory(&pHeader->Guid, (PVOID) &WdfTraceGuid, sizeof(GUID));
274
275 pHeader->Base = (PUCHAR) &pHeader[1];
276 pHeader->Size = size - sizeof(WDF_IFR_HEADER);
277
278 pHeader->Offset.u.s.Current = 0;
279 pHeader->Offset.u.s.Previous = 0;
280 RtlStringCchCopyA(pHeader->DriverName, WDF_IFR_HEADER_NAME_LEN, FxDriverGlobals->Public.DriverName);
281
282 FxDriverGlobals->WdfLogHeader = pHeader;
283
284 DoTraceLevelMessage(FxDriverGlobals, TRACE_LEVEL_INFORMATION, TRACINGDRIVER,
285 "FxIFR logging started" );
286
287 if (size > FxIFRMinLogSize) {
288 DoTraceLevelMessage(
289 FxDriverGlobals, TRACE_LEVEL_INFORMATION, TRACINGDRIVER,
290 "FxIFR has been started with a size override: size 0x%x bytes, "
291 "# Pages %d. An extended IFR size may not be written to a minidump!",
292 size, size/PAGE_SIZE);
293 }
294 }
295
296 VOID
FxIFRStop(__in PFX_DRIVER_GLOBALS FxDriverGlobals)297 FxIFRStop(
298 __in PFX_DRIVER_GLOBALS FxDriverGlobals
299 )
300 /*++
301
302 Routine Description:
303
304 This routine stops the In-Flight Recorder (IFR).
305
306 It should be called as late in the driver teardown as possible
307 to allow for the capture of all significant events.
308
309 --*/
310 {
311 //
312 // Return early if IFR is disabled.
313 //
314 if (FxLibraryGlobals.IfrDisabled) {
315 ASSERT(FxDriverGlobals->WdfLogHeader == NULL);
316 return;
317 }
318
319 if (FxDriverGlobals == NULL || FxDriverGlobals->WdfLogHeader == NULL) {
320 return;
321 }
322
323 //
324 // Free the Log buffer.
325 //
326 ExFreePoolWithTag( FxDriverGlobals->WdfLogHeader, WDF_IFR_LOG_TAG );
327 FxDriverGlobals->WdfLogHeader = NULL;
328 }
329
330 _Must_inspect_result_
331 NTSTATUS
FxIFR(__in PFX_DRIVER_GLOBALS FxDriverGlobals,__in UCHAR MessageLevel,__in ULONG MessageFlags,__in LPGUID MessageGuid,__in USHORT MessageNumber,__in...)332 FxIFR(
333 __in PFX_DRIVER_GLOBALS FxDriverGlobals,
334 __in UCHAR MessageLevel,
335 __in ULONG MessageFlags,
336 __in LPGUID MessageGuid,
337 __in USHORT MessageNumber,
338 __in ...
339 )
340 /*++
341
342 Routine Description:
343
344 This routine is the main In-Flight Recorder (IFR) routine.
345
346 It captures a WPP message to the IFR log.
347 The IFR is always running, e.g. not WPP logger is necessary
348 to start logging.
349
350 Arguments:
351
352 MessageLevel - The WPP message level for this event
353 MessageFlags - The WPP message flags for this event (see trace GUID)
354 MessageGuid - The tracewpp generated guid for module emitting this event.
355 MessageNumber - The tracewpp generated message number within
356 the emitting module.
357 ... - Variable arguments associates with the emitted message.
358
359 Returns:
360
361 NTSTATUS
362
363 --*/
364 {
365 size_t size;
366 PWDF_IFR_RECORD record;
367 PWDF_IFR_HEADER header;
368
369 UNREFERENCED_PARAMETER( MessageLevel );
370 UNREFERENCED_PARAMETER( MessageFlags );
371
372 //
373 // Return early if IFR is disabled.
374 //
375 if (FxLibraryGlobals.IfrDisabled) {
376 ASSERT(FxDriverGlobals->WdfLogHeader == NULL);
377 return STATUS_SUCCESS;
378 }
379
380 if ( FxDriverGlobals->WdfLogHeader == NULL) {
381 return STATUS_UNSUCCESSFUL;
382 }
383
384 //
385 // Determine the number bytes to follow header
386 //
387 size = 0; // For Count of Bytes
388
389 //
390 // Determine how much log space is needed for this
391 // trace record's data.
392 //
393 {
394 va_list ap;
395 size_t argLen;
396
397 va_start(ap, MessageNumber);
398 #pragma prefast(suppress: __WARNING_BUFFER_OVERFLOW, "Recommneded by EndClean");
399 while ((va_arg(ap, PVOID)) != NULL) {
400
401 argLen = va_arg(ap, size_t);
402
403 if (argLen > 0) {
404
405 if (argLen > FxIFRMaxMessageSize) {
406 goto drop_message;
407 }
408 size += (USHORT) argLen;
409 }
410 }
411
412 va_end(ap);
413
414 //
415 // NOTE: The final size must be 32-bit (ULONG) aligned.
416 // This is necessary for IA64 to prevent Alignment Faults.
417 //
418 size += (size % sizeof(ULONG)) ? sizeof(ULONG) - (size % sizeof(ULONG)) : 0;
419
420 if (size > FxIFRMaxMessageSize) {
421 goto drop_message;
422 }
423 }
424
425 size += sizeof(WDF_IFR_RECORD);
426
427 //
428 // Allocate log space of the calculated size
429 //
430 {
431 WDF_IFR_OFFSET offsetRet;
432 WDF_IFR_OFFSET offsetCur;
433 WDF_IFR_OFFSET offsetNew;
434 USHORT usSize = (USHORT) size; // for a prefast artifact.
435
436 header = (PWDF_IFR_HEADER) FxDriverGlobals->WdfLogHeader;
437
438 FxVerifyLogHeader(FxDriverGlobals, header);
439
440 offsetRet.u.AsLONG = header->Offset.u.AsLONG;
441 offsetNew.u.AsLONG = offsetRet.u.s.Current;
442
443 do {
444 offsetCur.u.AsLONG = offsetRet.u.AsLONG;
445
446 if (&header->Base[header->Size] < &header->Base[offsetCur.u.s.Current+size]) {
447
448 offsetNew.u.s.Current = 0;
449 offsetNew.u.s.Previous = offsetRet.u.s.Previous;
450
451 offsetRet.u.AsLONG =
452 InterlockedCompareExchange( &header->Offset.u.AsLONG,
453 offsetNew.u.AsLONG,
454 offsetCur.u.AsLONG );
455
456 if (offsetCur.u.AsLONG != offsetRet.u.AsLONG) {
457 continue;
458 } else {
459 offsetNew.u.s.Current = offsetCur.u.s.Current + usSize;
460 offsetNew.u.s.Previous = offsetRet.u.s.Current;
461 }
462 } else {
463
464 offsetNew.u.s.Current = offsetCur.u.s.Current + usSize;
465 offsetNew.u.s.Previous = offsetCur.u.s.Current;
466 }
467
468 offsetRet.u.AsLONG =
469 InterlockedCompareExchange( &header->Offset.u.AsLONG,
470 offsetNew.u.AsLONG,
471 offsetCur.u.AsLONG );
472
473 } while (offsetCur.u.AsLONG != offsetRet.u.AsLONG);
474
475 record = (PWDF_IFR_RECORD) &header->Base[offsetRet.u.s.Current];
476
477 // RtlZeroMemory( record, sizeof(WDF_IFR_RECORD) );
478
479 //
480 // Build record (fill all fields!)
481 //
482 record->Signature = FxIFRRecordSignature;
483 record->Length = (USHORT) size;
484 record->PrevOffset = (USHORT) offsetRet.u.s.Previous;
485 record->MessageNumber = MessageNumber;
486 record->Sequence = InterlockedIncrement( &header->Sequence );
487 record->MessageGuid = *MessageGuid;
488 }
489
490 //
491 // Move variable part of data into log.
492 //
493 {
494 va_list ap;
495 size_t argLen;
496 PVOID source;
497 PUCHAR argsData;
498
499 argsData = (UCHAR*) &record[1];
500
501 va_start(ap, MessageNumber);
502
503 while ((source = va_arg(ap, PVOID)) != NULL) {
504
505 argLen = va_arg(ap, size_t);
506
507 if (argLen > 0) {
508
509 RtlCopyMemory( argsData, source, argLen );
510 argsData += argLen;
511 }
512 }
513
514 va_end(ap);
515 }
516
517 FxVerifyLogHeader(FxDriverGlobals, header);
518
519 return STATUS_SUCCESS;
520
521 {
522 //
523 // Increment sequence number to indicate dropped message
524 //
525 drop_message:
526 header = (PWDF_IFR_HEADER) FxDriverGlobals->WdfLogHeader;
527 InterlockedIncrement( &header->Sequence );
528 return STATUS_UNSUCCESSFUL;
529 }
530 }
531