2 * Trace reporting for the Dp utility.
4 * Copyright (c) 2009-2010, Intel Corporation. All rights reserved.<BR>
5 * This program and the accompanying materials
6 * are licensed and made available under the terms and conditions of the BSD License
7 * which accompanies this distribution. The full text of the license may be found at
8 * http://opensource.org/licenses/bsd-license.php
10 * THE PROGRAM IS DISTRIBUTED UNDER THE BSD LICENSE ON AN "AS IS" BASIS,
11 * WITHOUT WARRANTIES OR REPRESENTATIONS OF ANY KIND, EITHER EXPRESS OR IMPLIED.
14 #include <Library/BaseLib.h>
15 #include <Library/BaseMemoryLib.h>
16 #include <Library/MemoryAllocationLib.h>
17 #include <Library/DebugLib.h>
18 #include <Library/UefiBootServicesTableLib.h>
19 #include <Library/TimerLib.h>
20 #include <Library/PeCoffGetEntryPointLib.h>
21 #include <Library/PerformanceLib.h>
22 #include <Library/PrintLib.h>
23 #include <Library/HiiLib.h>
24 #include <Library/PcdLib.h>
26 #include <Guid/Performance.h>
30 #include "DpInternal.h"
32 /** Collect verbose statistics about the logged performance measurements.
34 * General Summary information for all Trace measurements is gathered and
35 * stored within the SummaryData structure. This information is both
36 * used internally by subsequent reporting functions, and displayed
37 * at the end of verbose reports.
39 * @pre The SummaryData and CumData structures must be initialized
40 * prior to calling this function.
42 * @post The SummaryData and CumData structures contain statistics for the
43 * current performance logs.
50 MEASUREMENT_RECORD Measurement
;
56 while ((LogEntryKey
= GetPerformanceMeasurement (
61 &Measurement
.StartTimeStamp
,
62 &Measurement
.EndTimeStamp
)) != 0)
64 ++SummaryData
.NumTrace
; // Count the number of TRACE Measurement records
65 if (Measurement
.EndTimeStamp
== 0) {
66 ++SummaryData
.NumIncomplete
; // Count the incomplete records
70 if (Measurement
.Handle
!= NULL
) {
71 ++SummaryData
.NumHandles
; // Count the number of measurements with non-NULL handles
74 if (IsPhase( &Measurement
)) {
75 ++SummaryData
.NumSummary
; // Count the number of major phases
77 else { // !IsPhase(...
78 if(Measurement
.Handle
== NULL
) {
79 ++SummaryData
.NumGlobal
;
83 if (AsciiStrnCmp (Measurement
.Token
, ALit_PEIM
, PERF_TOKEN_LENGTH
) == 0) {
84 ++SummaryData
.NumPEIMs
; // Count PEIM measurements
87 Duration
= GetDuration (&Measurement
);
88 TIndex
= GetCumulativeItem (&Measurement
);
90 CumData
[TIndex
].Duration
+= Duration
;
91 CumData
[TIndex
].Count
++;
92 if ( Duration
< CumData
[TIndex
].MinDur
) {
93 CumData
[TIndex
].MinDur
= Duration
;
95 if ( Duration
> CumData
[TIndex
].MaxDur
) {
96 CumData
[TIndex
].MaxDur
= Duration
;
102 /** Gather and print ALL Trace Records.
104 * Displays all "interesting" Trace measurements in order.<BR>
105 * The number of records displayed is controlled by:
106 * - records with a duration less than mInterestThreshold microseconds are not displayed.
107 * - No more than Limit records are displayed. A Limit of zero will not limit the output.
108 * - If the ExcludeFlag is TRUE, records matching entries in the CumData array are not
111 * @pre The mInterestThreshold global variable is set to the shortest duration to be printed.
112 * The mGaugeString and mUnicodeToken global arrays are used for temporary string storage.
113 * They must not be in use by a calling function.
115 * @param[in] Limit The number of records to print. Zero is ALL.
116 * @param[in] ExcludeFlag TRUE to exclude individual Cumulative items from display.
122 IN BOOLEAN ExcludeFlag
125 MEASUREMENT_RECORD Measurement
;
128 const CHAR16
*IncFlag
;
134 EFI_HANDLE
*HandleBuffer
;
136 EFI_HANDLE TempHandle
;
139 IncFlag
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_ALL
), NULL
);
140 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
141 (IncFlag
== NULL
) ? ALit_UNKNOWN
: IncFlag
);
143 // Get Handle information
147 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, &TempHandle
);
148 if (Status
== EFI_BUFFER_TOO_SMALL
) {
149 HandleBuffer
= AllocatePool (Size
);
150 ASSERT (HandleBuffer
!= NULL
);
151 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, HandleBuffer
);
153 if (EFI_ERROR (Status
)) {
154 PrintToken (STRING_TOKEN (STR_DP_HANDLES_ERROR
), Status
);
157 // We have successfully populated the HandleBuffer
158 // Display ALL Measurement Records
159 // Up to Limit lines displayed
160 // Display only records with Elapsed times >= mInterestThreshold
161 // Display driver names in Module field for records with Handles.
163 PrintToken (STRING_TOKEN (STR_DP_ALL_HEADR
) );
164 PrintToken (STRING_TOKEN (STR_DP_DASHES
) );
169 while ( WITHIN_LIMIT(Count
, Limit
) &&
170 ((LogEntryKey
= GetPerformanceMeasurement (
175 &Measurement
.StartTimeStamp
,
176 &Measurement
.EndTimeStamp
)) != 0)
179 ++Index
; // Count every record. First record is 1.
181 if (Measurement
.EndTimeStamp
!= 0) {
182 Duration
= GetDuration (&Measurement
);
183 ElapsedTime
= DurationInMicroSeconds ( Duration
);
184 IncFlag
= STR_DP_COMPLETE
;
187 IncFlag
= STR_DP_INCOMPLETE
; // Mark incomplete records
189 if ((ElapsedTime
< mInterestThreshold
) ||
190 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
191 ) { // Ignore "uninteresting" or excluded records
194 if (Measurement
.EndTimeStamp
== 0) {
195 ElapsedTime
= Measurement
.StartTimeStamp
;
197 ++Count
; // Count the number of records printed
199 // If Handle is non-zero, see if we can determine a name for the driver
200 AsciiStrToUnicodeStr (Measurement
.Module
, mGaugeString
); // Use Module by default
201 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
202 if (Measurement
.Handle
!= NULL
) {
203 // See if the Handle is in the HandleBuffer
204 for (TIndex
= 0; TIndex
< (Size
/ sizeof(HandleBuffer
[0])); TIndex
++) {
205 if (Measurement
.Handle
== HandleBuffer
[TIndex
]) {
206 GetNameFromHandle (HandleBuffer
[TIndex
]);
211 // Ensure that the argument strings are not too long.
212 mGaugeString
[31] = 0;
213 mUnicodeToken
[18] = 0;
215 PrintToken( STRING_TOKEN (STR_DP_ALL_STATS
),
216 Index
, // 1 based, Which measurement record is being printed
225 FreePool (HandleBuffer
);
228 /** Gather and print Raw Trace Records.
230 * All Trace measurements with a duration greater than or equal to
231 * mInterestThreshold are printed without interpretation.
233 * The number of records displayed is controlled by:
234 * - records with a duration less than mInterestThreshold microseconds are not displayed.
235 * - No more than Limit records are displayed. A Limit of zero will not limit the output.
236 * - If the ExcludeFlag is TRUE, records matching entries in the CumData array are not
239 * @pre The mInterestThreshold global variable is set to the shortest duration to be printed.
241 * @param[in] Limit The number of records to print. Zero is ALL.
242 * @param[in] ExcludeFlag TRUE to exclude individual Cumulative items from display.
248 IN BOOLEAN ExcludeFlag
251 MEASUREMENT_RECORD Measurement
;
258 EFI_STRING StringPtr
;
260 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_RAWTRACE
), NULL
);
261 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
262 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
264 PrintToken (STRING_TOKEN (STR_DP_RAW_HEADR
) );
265 PrintToken (STRING_TOKEN (STR_DP_RAW_DASHES
) );
270 while ( WITHIN_LIMIT(Count
, Limit
) &&
271 ((LogEntryKey
= GetPerformanceMeasurement (
276 &Measurement
.StartTimeStamp
,
277 &Measurement
.EndTimeStamp
)) != 0)
280 ++Index
; // Count every record. First record is 1.
282 if (Measurement
.EndTimeStamp
!= 0) {
283 Duration
= GetDuration (&Measurement
);
284 ElapsedTime
= DurationInMicroSeconds ( Duration
);
286 if ((ElapsedTime
< mInterestThreshold
) ||
287 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
288 ) { // Ignore "uninteresting" or Excluded records
291 ++Count
; // Count the number of records printed
292 PrintToken (STRING_TOKEN (STR_DP_RAW_VARS
),
293 Index
, // 1 based, Which measurement record is being printed
295 Measurement
.StartTimeStamp
,
296 Measurement
.EndTimeStamp
,
303 /** Gather and print Major Phase metrics.
305 * @param[in] Ticker The timer value for the END of Shell phase
313 MEASUREMENT_RECORD Measurement
;
314 UINT64 BdsTimeoutValue
= 0;
319 UINT64 ShellTime
= 0;
323 EFI_STRING StringPtr
;
327 // Get Execution Phase Statistics
329 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_PHASES
), NULL
);
330 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
331 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
334 while ((LogEntryKey
= GetPerformanceMeasurement (
339 &Measurement
.StartTimeStamp
,
340 &Measurement
.EndTimeStamp
)) != 0)
342 if (AsciiStrnCmp (Measurement
.Token
, ALit_SHELL
, PERF_TOKEN_LENGTH
) == 0) {
343 Measurement
.EndTimeStamp
= Ticker
;
345 if (Measurement
.EndTimeStamp
== 0) { // Skip "incomplete" records
348 Duration
= GetDuration (&Measurement
);
349 if ( Measurement
.Handle
!= NULL
350 && (AsciiStrnCmp (Measurement
.Token
, ALit_BdsTO
, PERF_TOKEN_LENGTH
) == 0)
353 BdsTimeoutValue
= Duration
;
354 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_SEC
, PERF_TOKEN_LENGTH
) == 0) {
356 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_PEI
, PERF_TOKEN_LENGTH
) == 0) {
358 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_DXE
, PERF_TOKEN_LENGTH
) == 0) {
360 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_BDS
, PERF_TOKEN_LENGTH
) == 0) {
362 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_SHELL
, PERF_TOKEN_LENGTH
) == 0) {
363 ShellTime
= Duration
;
369 // print SEC phase duration time
372 ElapsedTime
= DurationInMicroSeconds ( SecTime
); // Calculate elapsed time in microseconds
373 Total
+= DivU64x32 (ElapsedTime
, 1000); // Accumulate time in milliseconds
374 PrintToken (STRING_TOKEN (STR_DP_SEC_PHASE
), ElapsedTime
);
377 // print PEI phase duration time
380 ElapsedTime
= DivU64x32 (
382 (UINT32
)TimerInfo
.Frequency
384 Total
+= ElapsedTime
;
385 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_PEI
, ElapsedTime
);
388 // print DXE phase duration time
391 ElapsedTime
= DivU64x32 (
393 (UINT32
)TimerInfo
.Frequency
395 Total
+= ElapsedTime
;
396 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_DXE
, ElapsedTime
);
399 // print BDS phase duration time
402 ElapsedTime
= DivU64x32 (
404 (UINT32
)TimerInfo
.Frequency
406 Total
+= ElapsedTime
;
407 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_BDS
, ElapsedTime
);
410 if (BdsTimeoutValue
> 0) {
411 ElapsedTime
= DivU64x32 (
413 (UINT32
)TimerInfo
.Frequency
415 PrintToken (STRING_TOKEN (STR_DP_PHASE_BDSTO
), ALit_BdsTO
, ElapsedTime
);
418 // print SHELL phase duration time
421 ElapsedTime
= DivU64x32 (
423 (UINT32
)TimerInfo
.Frequency
425 Total
+= ElapsedTime
;
426 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_SHELL
, ElapsedTime
);
429 PrintToken (STRING_TOKEN (STR_DP_TOTAL_DURATION
), Total
);
432 /** Gather and print Handle data.
434 * @param[in] ExcludeFlag TRUE to exclude individual Cumulative items from display.
436 * @return Status from a call to gBS->LocateHandle().
440 IN BOOLEAN ExcludeFlag
443 MEASUREMENT_RECORD Measurement
;
446 EFI_HANDLE
*HandleBuffer
;
447 EFI_STRING StringPtr
;
452 EFI_HANDLE TempHandle
;
455 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_DRIVERS
), NULL
);
456 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
457 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
461 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, &TempHandle
);
462 if (Status
== EFI_BUFFER_TOO_SMALL
) {
463 HandleBuffer
= AllocatePool (Size
);
464 ASSERT (HandleBuffer
!= NULL
);
465 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, HandleBuffer
);
467 if (EFI_ERROR (Status
)) {
468 PrintToken (STRING_TOKEN (STR_DP_HANDLES_ERROR
), Status
);
472 Print (L
"There are %,d Handles defined.\n", (Size
/ sizeof(HandleBuffer
[0])));
475 PrintToken (STRING_TOKEN (STR_DP_HANDLE_GUID
) );
476 PrintToken (STRING_TOKEN (STR_DP_DASHES
) );
480 while ((LogEntryKey
= GetPerformanceMeasurement (
485 &Measurement
.StartTimeStamp
,
486 &Measurement
.EndTimeStamp
)) != 0)
489 Duration
= GetDuration (&Measurement
);
490 ElapsedTime
= DurationInMicroSeconds ( Duration
);
491 if ((ElapsedTime
< mInterestThreshold
) ||
492 (Measurement
.EndTimeStamp
== 0) ||
493 (Measurement
.Handle
== NULL
) ||
494 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
495 ) { // Ignore "uninteresting" or excluded records
498 mGaugeString
[0] = 0; // Empty driver name by default
499 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
500 // See if the Handle is in the HandleBuffer
501 for (Index
= 0; Index
< (Size
/ sizeof(HandleBuffer
[0])); Index
++) {
502 if (Measurement
.Handle
== HandleBuffer
[Index
]) {
503 GetNameFromHandle (HandleBuffer
[Index
]); // Name is put into mGaugeString
507 // Ensure that the argument strings are not too long.
508 mGaugeString
[31] = 0;
509 mUnicodeToken
[18] = 0;
510 if (mGaugeString
[0] != 0) {
511 // Display the record if it has a valid handle.
513 STRING_TOKEN (STR_DP_HANDLE_VARS
),
514 Count
, // 1 based, Which measurement record is being printed
515 Index
+ 1, // 1 based, Which handle is being printed
523 FreePool (HandleBuffer
);
527 /** Gather and print PEIM data.
529 * Only prints complete PEIM records
537 MEASUREMENT_RECORD Measurement
;
540 EFI_STRING StringPtr
;
545 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_PEIMS
), NULL
);
546 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
547 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
549 PrintToken (STRING_TOKEN (STR_DP_PEIM_SECTION
));
550 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
553 while ((LogEntryKey
= GetPerformanceMeasurement (
558 &Measurement
.StartTimeStamp
,
559 &Measurement
.EndTimeStamp
)) != 0)
562 if ((Measurement
.EndTimeStamp
== 0) ||
563 (AsciiStrnCmp (Measurement
.Token
, ALit_PEIM
, PERF_TOKEN_LENGTH
) != 0)
568 Duration
= GetDuration (&Measurement
);
569 ElapsedTime
= DurationInMicroSeconds ( Duration
); // Calculate elapsed time in microseconds
570 if (ElapsedTime
>= mInterestThreshold
) {
571 GetNameFromHandle (Measurement
.Handle
); // Name placed in mGaugeString
572 PrintToken (STRING_TOKEN (STR_DP_PEIM_STAT2
),
573 TIndex
, // 1 based, Which measurement record is being printed
582 /** Gather and print global data.
584 * Strips out incomplete or "Execution Phase" records
585 * Only prints records where Handle is NULL
586 * Increment TIndex for every record, even skipped ones, so that we have an
587 * indication of every measurement record taken.
596 MEASUREMENT_RECORD Measurement
;
599 EFI_STRING StringPtr
;
601 UINTN Index
; // Index, or number, of the measurement record being processed
603 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_GENERAL
), NULL
);
604 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
605 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
607 PrintToken (STRING_TOKEN (STR_DP_GLOBAL_SECTION
));
608 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
613 while ((LogEntryKey
= GetPerformanceMeasurement (
618 &Measurement
.StartTimeStamp
,
619 &Measurement
.EndTimeStamp
)) != 0)
621 AsciiStrToUnicodeStr (Measurement
.Module
, mGaugeString
);
622 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
623 if ( ! ( IsPhase( &Measurement
) ||
624 (Measurement
.Handle
!= NULL
) ||
625 (Measurement
.EndTimeStamp
== 0)
628 Duration
= GetDuration (&Measurement
);
629 ElapsedTime
= DurationInMicroSeconds ( Duration
);
630 if (ElapsedTime
>= mInterestThreshold
) {
632 STRING_TOKEN (STR_DP_FOUR_VARS_2
),
644 /** Gather and print cumulative data.
646 * Traverse the measurement records and:<BR>
647 * For each record with a Token listed in the CumData array:<BR>
648 * - Update the instance count and the total, minimum, and maximum durations.
649 * Finally, print the gathered cumulative statistics.
657 UINT64 avgval
; // the computed average duration
658 EFI_STRING StringPtr
;
662 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_CUMULATIVE
), NULL
);
663 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
664 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
666 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_SECT_1
));
667 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_SECT_2
));
668 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
670 for ( TIndex
= 0; TIndex
< NumCum
; ++TIndex
) {
671 avgval
= DivU64x32 (CumData
[TIndex
].Duration
, CumData
[TIndex
].Count
);
672 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_STATS
),
673 CumData
[TIndex
].Name
,
674 CumData
[TIndex
].Count
,
675 DurationInMicroSeconds(CumData
[TIndex
].Duration
),
676 DurationInMicroSeconds(avgval
),
677 DurationInMicroSeconds(CumData
[TIndex
].MinDur
),
678 DurationInMicroSeconds(CumData
[TIndex
].MaxDur
)