ReactOS  0.4.15-dev-3446-g30010a5
tracing.cpp
Go to the documentation of this file.
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 
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  //
74 
75  return STATUS_SUCCESS;
76 }
77 
78 VOID
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  //
100 }
101 
103 NTSTATUS
105  __in TRACEHANDLE LoggerHandle,
106  __in ULONG MessageFlags,
107  __in LPGUID MessageGuid,
109  __in ...
110  )
111 {
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,
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
135  __in PFX_DRIVER_GLOBALS FxDriverGlobals,
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;
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 
173  NULL,
174  NULL);
175 
176  status = ZwOpenKey(&service.m_Key, KEY_READ, &oa);
177  if (!NT_SUCCESS(status)) {
178  goto defaultValues;
179  }
180 
182  (PUNICODE_STRING)&parametersPath,
184  service.m_Key,
185  NULL);
186 
187  status = ZwOpenKey(&parameters.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
221  __in PFX_DRIVER_GLOBALS FxDriverGlobals,
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 {
239  ULONG size;
240 
242 
244 
245  //
246  // Return early if IFR is disabled.
247  //
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 
260  size,
261  WDF_IFR_LOG_TAG );
262  if (pHeader == NULL) {
263  return;
264  }
265 
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 
285  "FxIFR logging started" );
286 
287  if (size > FxIFRMinLogSize) {
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
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  //
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 
331 NTSTATUS
333  __in PFX_DRIVER_GLOBALS FxDriverGlobals,
334  __in UCHAR MessageLevel,
335  __in ULONG MessageFlags,
336  __in LPGUID MessageGuid,
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;
368 
369  UNREFERENCED_PARAMETER( MessageLevel );
370  UNREFERENCED_PARAMETER( MessageFlags );
371 
372  //
373  // Return early if IFR is disabled.
374  //
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 
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 
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 }
NTSTATUS NTAPI WmiTraceMessageVa(IN TRACEHANDLE LoggerHandle, IN ULONG MessageFlags, IN LPGUID MessageGuid, IN USHORT MessageNumber, IN va_list MessageArgList)
Definition: wmi.c:368
ULONG64 TRACEHANDLE
Definition: evntrace.h:40
LONG AsLONG
Definition: fxifr.h:83
#define OBJ_CASE_INSENSITIVE
Definition: winternl.h:228
#define KEY_READ
Definition: nt_native.h:1023
#define UNREFERENCED_PARAMETER(P)
Definition: ntbasedef.h:317
WDFCASSERT(sizeof(WDF_DRIVER_CONFIG_V1_0)==sizeof(WDF_DRIVER_CONFIG_V1_1))
unsigned char * PUCHAR
Definition: retypes.h:3
LONG NTSTATUS
Definition: precomp.h:26
_Must_inspect_result_ _In_ PDRIVER_OBJECT _In_ PCUNICODE_STRING RegistryPath
Definition: wdfdriver.h:213
#define InterlockedCompareExchange
Definition: interlocked.h:104
#define TRACINGDRIVER
Definition: dbgtrace.h:68
#define TRACE_LEVEL_INFORMATION
Definition: storswtr.h:29
struct _WDF_IFR_OFFSET::@4520::@4521 s
#define OBJ_KERNEL_HANDLE
Definition: winternl.h:231
struct _WDF_IFR_HEADER WDF_IFR_HEADER
__inline VOID FxVerifyLogHeader(__in PFX_DRIVER_GLOBALS FxDriverGlobals, __in PWDF_IFR_HEADER Header)
Definition: fxifrkm.h:49
_Must_inspect_result_ NTSTATUS FxIFR(__in PFX_DRIVER_GLOBALS FxDriverGlobals, __in UCHAR MessageLevel, __in ULONG MessageFlags, __in LPGUID MessageGuid, __in USHORT MessageNumber, __in ...)
Definition: tracing.cpp:332
union _WDF_IFR_OFFSET::@4520 u
#define L(x)
Definition: ntvdm.h:50
#define va_end(ap)
Definition: acmsvcex.h:90
FxContextHeader * pHeader
Definition: handleapi.cpp:604
char * va_list
Definition: acmsvcex.h:78
_Must_inspect_result_ _In_ PDRIVER_OBJECT DriverObject
Definition: wdfdriver.h:213
struct _WDF_IFR_HEADER * PWDF_IFR_HEADER
#define WPP_CLEANUP(a)
Definition: kdebugprint.h:57
GLsizeiptr size
Definition: glext.h:5919
VOID FxIFRStart(__in PFX_DRIVER_GLOBALS FxDriverGlobals, __in PCUNICODE_STRING RegistryPath, __in MdDriverObject DriverObject)
Definition: tracing.cpp:220
#define ASSERT(a)
Definition: mode.c:44
#define WPP_INIT_TRACING(a, b)
Definition: kdebugprint.h:56
#define NT_SUCCESS(StatCode)
Definition: apphelp.c:32
#define DECLARE_CONST_UNICODE_STRING(_variablename, _string)
Definition: wdfcore.h:161
ULONG FxIFRGetSize(__in PFX_DRIVER_GLOBALS FxDriverGlobals, __in PCUNICODE_STRING RegistryPath)
Definition: tracing.cpp:134
va_start(ap, x)
#define WDF_IFR_LOG_TAG
Definition: fxifr.h:88
#define STATUS_UNSUCCESSFUL
Definition: udferr_usr.h:132
#define ExAllocatePoolWithTag(hernya, size, tag)
Definition: env_spec_w32.h:350
unsigned char UCHAR
Definition: xmlstorage.h:181
_Must_inspect_result_ NTSTATUS FxTraceInitialize(VOID)
Definition: tracing.cpp:47
struct _WDF_IFR_RECORD * PWDF_IFR_RECORD
#define PAGE_SIZE
Definition: env_spec_w32.h:49
VOID FxIFRStop(__in PFX_DRIVER_GLOBALS FxDriverGlobals)
Definition: tracing.cpp:297
#define _Must_inspect_result_
Definition: ms_sal.h:558
FxLibraryGlobalsType FxLibraryGlobals
Definition: globals.cpp:95
#define WDF_IFR_HEADER_NAME_LEN
Definition: fxifr.h:42
#define WDF_IFR_RECORD_SIGNATURE
Definition: fxifr.h:109
struct _WDF_IFR_RECORD WDF_IFR_RECORD
#define va_arg(ap, T)
Definition: acmsvcex.h:89
#define InterlockedIncrement
Definition: armddk.h:53
unsigned short USHORT
Definition: pedump.c:61
GLsizei GLsizei GLchar * source
Definition: glext.h:6048
_Must_inspect_result_ typedef _In_ ULONG _In_ ULONG MessageNumber
Definition: iotypes.h:4303
DoTraceLevelMessage(pFxDriverGlobals, TRACE_LEVEL_VERBOSE, TRACINGPNP, "Enter, WDFDEVICE %p", Device)
#define NULL
Definition: types.h:112
void int int ULONGLONG int va_list * ap
Definition: winesup.h:32
unsigned int ULONG
Definition: retypes.h:1
#define RtlZeroMemory(Destination, Length)
Definition: typedefs.h:262
VOID TraceUninitialize(VOID)
Definition: tracing.cpp:79
_Must_inspect_result_ NTSTATUS FxWmiTraceMessage(__in TRACEHANDLE LoggerHandle, __in ULONG MessageFlags, __in LPGUID MessageGuid, __in USHORT MessageNumber, __in ...)
Definition: tracing.cpp:104
#define InitializeObjectAttributes(p, n, a, r, s)
Definition: reg.c:106
#define RtlCopyMemory(Destination, Source, Length)
Definition: typedefs.h:263
NTSTRSAFEAPI RtlStringCchCopyA(_Out_writes_(cchDest) _Always_(_Post_z_) NTSTRSAFE_PSTR pszDest, _In_ size_t cchDest, _In_ NTSTRSAFE_PCSTR pszSrc)
Definition: ntstrsafe.h:110
#define STATUS_SUCCESS
Definition: shellext.h:65
#define __in
Definition: dbghelp.h:35
#define ExFreePoolWithTag(_P, _T)
Definition: module.h:1099
static SERVICE_STATUS status
Definition: service.c:31
struct CFHEADER header
Definition: fdi.c:101
Definition: ps.c:97