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
146 HandleBuffer
= &TempHandle
;
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 if (HandleBuffer
== NULL
) {
154 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, HandleBuffer
);
156 if (EFI_ERROR (Status
)) {
157 PrintToken (STRING_TOKEN (STR_DP_HANDLES_ERROR
), Status
);
160 // We have successfully populated the HandleBuffer
161 // Display ALL Measurement Records
162 // Up to Limit lines displayed
163 // Display only records with Elapsed times >= mInterestThreshold
164 // Display driver names in Module field for records with Handles.
166 PrintToken (STRING_TOKEN (STR_DP_ALL_HEADR
) );
167 PrintToken (STRING_TOKEN (STR_DP_DASHES
) );
172 while ( WITHIN_LIMIT(Count
, Limit
) &&
173 ((LogEntryKey
= GetPerformanceMeasurement (
178 &Measurement
.StartTimeStamp
,
179 &Measurement
.EndTimeStamp
)) != 0)
182 ++Index
; // Count every record. First record is 1.
184 if (Measurement
.EndTimeStamp
!= 0) {
185 Duration
= GetDuration (&Measurement
);
186 ElapsedTime
= DurationInMicroSeconds ( Duration
);
187 IncFlag
= STR_DP_COMPLETE
;
190 IncFlag
= STR_DP_INCOMPLETE
; // Mark incomplete records
192 if ((ElapsedTime
< mInterestThreshold
) ||
193 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
194 ) { // Ignore "uninteresting" or excluded records
197 if (Measurement
.EndTimeStamp
== 0) {
198 ElapsedTime
= Measurement
.StartTimeStamp
;
200 ++Count
; // Count the number of records printed
202 // If Handle is non-zero, see if we can determine a name for the driver
203 AsciiStrToUnicodeStr (Measurement
.Module
, mGaugeString
); // Use Module by default
204 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
205 if (Measurement
.Handle
!= NULL
) {
206 // See if the Handle is in the HandleBuffer
207 for (TIndex
= 0; TIndex
< (Size
/ sizeof(HandleBuffer
[0])); TIndex
++) {
208 if (Measurement
.Handle
== HandleBuffer
[TIndex
]) {
209 GetNameFromHandle (HandleBuffer
[TIndex
]);
214 // Ensure that the argument strings are not too long.
215 mGaugeString
[31] = 0;
216 mUnicodeToken
[18] = 0;
218 PrintToken( STRING_TOKEN (STR_DP_ALL_STATS
),
219 Index
, // 1 based, Which measurement record is being printed
228 if (HandleBuffer
!= &TempHandle
) {
229 FreePool (HandleBuffer
);
233 /** Gather and print Raw Trace Records.
235 * All Trace measurements with a duration greater than or equal to
236 * mInterestThreshold are printed without interpretation.
238 * The number of records displayed is controlled by:
239 * - records with a duration less than mInterestThreshold microseconds are not displayed.
240 * - No more than Limit records are displayed. A Limit of zero will not limit the output.
241 * - If the ExcludeFlag is TRUE, records matching entries in the CumData array are not
244 * @pre The mInterestThreshold global variable is set to the shortest duration to be printed.
246 * @param[in] Limit The number of records to print. Zero is ALL.
247 * @param[in] ExcludeFlag TRUE to exclude individual Cumulative items from display.
253 IN BOOLEAN ExcludeFlag
256 MEASUREMENT_RECORD Measurement
;
263 EFI_STRING StringPtr
;
265 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_RAWTRACE
), NULL
);
266 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
267 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
269 PrintToken (STRING_TOKEN (STR_DP_RAW_HEADR
) );
270 PrintToken (STRING_TOKEN (STR_DP_RAW_DASHES
) );
275 while ( WITHIN_LIMIT(Count
, Limit
) &&
276 ((LogEntryKey
= GetPerformanceMeasurement (
281 &Measurement
.StartTimeStamp
,
282 &Measurement
.EndTimeStamp
)) != 0)
285 ++Index
; // Count every record. First record is 1.
287 if (Measurement
.EndTimeStamp
!= 0) {
288 Duration
= GetDuration (&Measurement
);
289 ElapsedTime
= DurationInMicroSeconds ( Duration
);
291 if ((ElapsedTime
< mInterestThreshold
) ||
292 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
293 ) { // Ignore "uninteresting" or Excluded records
296 ++Count
; // Count the number of records printed
297 PrintToken (STRING_TOKEN (STR_DP_RAW_VARS
),
298 Index
, // 1 based, Which measurement record is being printed
300 Measurement
.StartTimeStamp
,
301 Measurement
.EndTimeStamp
,
308 /** Gather and print Major Phase metrics.
310 * @param[in] Ticker The timer value for the END of Shell phase
318 MEASUREMENT_RECORD Measurement
;
319 UINT64 BdsTimeoutValue
= 0;
324 UINT64 ShellTime
= 0;
328 EFI_STRING StringPtr
;
332 // Get Execution Phase Statistics
334 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_PHASES
), NULL
);
335 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
336 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
339 while ((LogEntryKey
= GetPerformanceMeasurement (
344 &Measurement
.StartTimeStamp
,
345 &Measurement
.EndTimeStamp
)) != 0)
347 if (AsciiStrnCmp (Measurement
.Token
, ALit_SHELL
, PERF_TOKEN_LENGTH
) == 0) {
348 Measurement
.EndTimeStamp
= Ticker
;
350 if (Measurement
.EndTimeStamp
== 0) { // Skip "incomplete" records
353 Duration
= GetDuration (&Measurement
);
354 if ( Measurement
.Handle
!= NULL
355 && (AsciiStrnCmp (Measurement
.Token
, ALit_BdsTO
, PERF_TOKEN_LENGTH
) == 0)
358 BdsTimeoutValue
= Duration
;
359 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_SEC
, PERF_TOKEN_LENGTH
) == 0) {
361 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_PEI
, PERF_TOKEN_LENGTH
) == 0) {
363 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_DXE
, PERF_TOKEN_LENGTH
) == 0) {
365 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_BDS
, PERF_TOKEN_LENGTH
) == 0) {
367 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_SHELL
, PERF_TOKEN_LENGTH
) == 0) {
368 ShellTime
= Duration
;
374 // print SEC phase duration time
377 ElapsedTime
= DurationInMicroSeconds ( SecTime
); // Calculate elapsed time in microseconds
378 Total
+= DivU64x32 (ElapsedTime
, 1000); // Accumulate time in milliseconds
379 PrintToken (STRING_TOKEN (STR_DP_SEC_PHASE
), ElapsedTime
);
382 // print PEI phase duration time
385 ElapsedTime
= DivU64x32 (
387 (UINT32
)TimerInfo
.Frequency
389 Total
+= ElapsedTime
;
390 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_PEI
, ElapsedTime
);
393 // print DXE phase duration time
396 ElapsedTime
= DivU64x32 (
398 (UINT32
)TimerInfo
.Frequency
400 Total
+= ElapsedTime
;
401 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_DXE
, ElapsedTime
);
404 // print BDS phase duration time
407 ElapsedTime
= DivU64x32 (
409 (UINT32
)TimerInfo
.Frequency
411 Total
+= ElapsedTime
;
412 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_BDS
, ElapsedTime
);
415 if (BdsTimeoutValue
> 0) {
416 ElapsedTime
= DivU64x32 (
418 (UINT32
)TimerInfo
.Frequency
420 PrintToken (STRING_TOKEN (STR_DP_PHASE_BDSTO
), ALit_BdsTO
, ElapsedTime
);
423 // print SHELL phase duration time
426 ElapsedTime
= DivU64x32 (
428 (UINT32
)TimerInfo
.Frequency
430 Total
+= ElapsedTime
;
431 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_SHELL
, ElapsedTime
);
434 PrintToken (STRING_TOKEN (STR_DP_TOTAL_DURATION
), Total
);
437 /** Gather and print Handle data.
439 * @param[in] ExcludeFlag TRUE to exclude individual Cumulative items from display.
441 * @return Status from a call to gBS->LocateHandle().
445 IN BOOLEAN ExcludeFlag
448 MEASUREMENT_RECORD Measurement
;
451 EFI_HANDLE
*HandleBuffer
;
452 EFI_STRING StringPtr
;
457 EFI_HANDLE TempHandle
;
460 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_DRIVERS
), NULL
);
461 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
462 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
465 HandleBuffer
= &TempHandle
;
466 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, &TempHandle
);
467 if (Status
== EFI_BUFFER_TOO_SMALL
) {
468 HandleBuffer
= AllocatePool (Size
);
469 ASSERT (HandleBuffer
!= NULL
);
470 if (HandleBuffer
== NULL
) {
473 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, HandleBuffer
);
475 if (EFI_ERROR (Status
)) {
476 PrintToken (STRING_TOKEN (STR_DP_HANDLES_ERROR
), Status
);
480 Print (L
"There are %,d Handles defined.\n", (Size
/ sizeof(HandleBuffer
[0])));
483 PrintToken (STRING_TOKEN (STR_DP_HANDLE_GUID
) );
484 PrintToken (STRING_TOKEN (STR_DP_DASHES
) );
488 while ((LogEntryKey
= GetPerformanceMeasurement (
493 &Measurement
.StartTimeStamp
,
494 &Measurement
.EndTimeStamp
)) != 0)
497 Duration
= GetDuration (&Measurement
);
498 ElapsedTime
= DurationInMicroSeconds ( Duration
);
499 if ((ElapsedTime
< mInterestThreshold
) ||
500 (Measurement
.EndTimeStamp
== 0) ||
501 (Measurement
.Handle
== NULL
) ||
502 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
503 ) { // Ignore "uninteresting" or excluded records
506 mGaugeString
[0] = 0; // Empty driver name by default
507 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
508 // See if the Handle is in the HandleBuffer
509 for (Index
= 0; Index
< (Size
/ sizeof(HandleBuffer
[0])); Index
++) {
510 if (Measurement
.Handle
== HandleBuffer
[Index
]) {
511 GetNameFromHandle (HandleBuffer
[Index
]); // Name is put into mGaugeString
515 // Ensure that the argument strings are not too long.
516 mGaugeString
[31] = 0;
517 mUnicodeToken
[18] = 0;
518 if (mGaugeString
[0] != 0) {
519 // Display the record if it has a valid handle.
521 STRING_TOKEN (STR_DP_HANDLE_VARS
),
522 Count
, // 1 based, Which measurement record is being printed
523 Index
+ 1, // 1 based, Which handle is being printed
531 if (HandleBuffer
!= &TempHandle
) {
532 FreePool (HandleBuffer
);
537 /** Gather and print PEIM data.
539 * Only prints complete PEIM records
547 MEASUREMENT_RECORD Measurement
;
550 EFI_STRING StringPtr
;
555 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_PEIMS
), NULL
);
556 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
557 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
559 PrintToken (STRING_TOKEN (STR_DP_PEIM_SECTION
));
560 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
563 while ((LogEntryKey
= GetPerformanceMeasurement (
568 &Measurement
.StartTimeStamp
,
569 &Measurement
.EndTimeStamp
)) != 0)
572 if ((Measurement
.EndTimeStamp
== 0) ||
573 (AsciiStrnCmp (Measurement
.Token
, ALit_PEIM
, PERF_TOKEN_LENGTH
) != 0)
578 Duration
= GetDuration (&Measurement
);
579 ElapsedTime
= DurationInMicroSeconds ( Duration
); // Calculate elapsed time in microseconds
580 if (ElapsedTime
>= mInterestThreshold
) {
581 GetNameFromHandle ((EFI_HANDLE
) Measurement
.Handle
); // Name placed in mGaugeString
582 PrintToken (STRING_TOKEN (STR_DP_PEIM_STAT2
),
583 TIndex
, // 1 based, Which measurement record is being printed
592 /** Gather and print global data.
594 * Strips out incomplete or "Execution Phase" records
595 * Only prints records where Handle is NULL
596 * Increment TIndex for every record, even skipped ones, so that we have an
597 * indication of every measurement record taken.
606 MEASUREMENT_RECORD Measurement
;
609 EFI_STRING StringPtr
;
611 UINTN Index
; // Index, or number, of the measurement record being processed
613 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_GENERAL
), NULL
);
614 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
615 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
617 PrintToken (STRING_TOKEN (STR_DP_GLOBAL_SECTION
));
618 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
623 while ((LogEntryKey
= GetPerformanceMeasurement (
628 &Measurement
.StartTimeStamp
,
629 &Measurement
.EndTimeStamp
)) != 0)
631 AsciiStrToUnicodeStr (Measurement
.Module
, mGaugeString
);
632 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
633 if ( ! ( IsPhase( &Measurement
) ||
634 (Measurement
.Handle
!= NULL
) ||
635 (Measurement
.EndTimeStamp
== 0)
638 Duration
= GetDuration (&Measurement
);
639 ElapsedTime
= DurationInMicroSeconds ( Duration
);
640 if (ElapsedTime
>= mInterestThreshold
) {
642 STRING_TOKEN (STR_DP_FOUR_VARS_2
),
654 /** Gather and print cumulative data.
656 * Traverse the measurement records and:<BR>
657 * For each record with a Token listed in the CumData array:<BR>
658 * - Update the instance count and the total, minimum, and maximum durations.
659 * Finally, print the gathered cumulative statistics.
667 UINT64 avgval
; // the computed average duration
668 EFI_STRING StringPtr
;
672 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_CUMULATIVE
), NULL
);
673 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
674 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
676 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_SECT_1
));
677 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_SECT_2
));
678 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
680 for ( TIndex
= 0; TIndex
< NumCum
; ++TIndex
) {
681 avgval
= DivU64x32 (CumData
[TIndex
].Duration
, CumData
[TIndex
].Count
);
682 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_STATS
),
683 CumData
[TIndex
].Name
,
684 CumData
[TIndex
].Count
,
685 DurationInMicroSeconds(CumData
[TIndex
].Duration
),
686 DurationInMicroSeconds(avgval
),
687 DurationInMicroSeconds(CumData
[TIndex
].MinDur
),
688 DurationInMicroSeconds(CumData
[TIndex
].MaxDur
)