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"
33 Collect verbose statistics about the logged performance measurements.
35 General Summary information for all Trace measurements is gathered and
36 stored within the SummaryData structure. This information is both
37 used internally by subsequent reporting functions, and displayed
38 at the end of verbose reports.
40 @pre The SummaryData and CumData structures must be initialized
41 prior to calling this function.
43 @post The SummaryData and CumData structures contain statistics for the
44 current performance logs.
51 MEASUREMENT_RECORD Measurement
;
57 while ((LogEntryKey
= GetPerformanceMeasurement (
62 &Measurement
.StartTimeStamp
,
63 &Measurement
.EndTimeStamp
)) != 0)
65 ++SummaryData
.NumTrace
; // Count the number of TRACE Measurement records
66 if (Measurement
.EndTimeStamp
== 0) {
67 ++SummaryData
.NumIncomplete
; // Count the incomplete records
71 if (Measurement
.Handle
!= NULL
) {
72 ++SummaryData
.NumHandles
; // Count the number of measurements with non-NULL handles
75 if (IsPhase( &Measurement
)) {
76 ++SummaryData
.NumSummary
; // Count the number of major phases
78 else { // !IsPhase(...
79 if(Measurement
.Handle
== NULL
) {
80 ++SummaryData
.NumGlobal
;
84 if (AsciiStrnCmp (Measurement
.Token
, ALit_PEIM
, PERF_TOKEN_LENGTH
) == 0) {
85 ++SummaryData
.NumPEIMs
; // Count PEIM measurements
88 Duration
= GetDuration (&Measurement
);
89 TIndex
= GetCumulativeItem (&Measurement
);
91 CumData
[TIndex
].Duration
+= Duration
;
92 CumData
[TIndex
].Count
++;
93 if ( Duration
< CumData
[TIndex
].MinDur
) {
94 CumData
[TIndex
].MinDur
= Duration
;
96 if ( Duration
> CumData
[TIndex
].MaxDur
) {
97 CumData
[TIndex
].MaxDur
= Duration
;
104 Gather and print ALL Trace Records.
106 Displays all "interesting" Trace measurements in order.<BR>
107 The number of records displayed is controlled by:
108 - records with a duration less than mInterestThreshold microseconds are not displayed.
109 - No more than Limit records are displayed. A Limit of zero will not limit the output.
110 - If the ExcludeFlag is TRUE, records matching entries in the CumData array are not
113 @pre The mInterestThreshold global variable is set to the shortest duration to be printed.
114 The mGaugeString and mUnicodeToken global arrays are used for temporary string storage.
115 They must not be in use by a calling function.
117 @param[in] Limit The number of records to print. Zero is ALL.
118 @param[in] ExcludeFlag TRUE to exclude individual Cumulative items from display.
124 IN BOOLEAN ExcludeFlag
127 MEASUREMENT_RECORD Measurement
;
130 const CHAR16
*IncFlag
;
136 EFI_HANDLE
*HandleBuffer
;
138 EFI_HANDLE TempHandle
;
141 IncFlag
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_ALL
), NULL
);
142 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
143 (IncFlag
== NULL
) ? ALit_UNKNOWN
: IncFlag
);
145 // Get Handle information
148 HandleBuffer
= &TempHandle
;
149 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, &TempHandle
);
150 if (Status
== EFI_BUFFER_TOO_SMALL
) {
151 HandleBuffer
= AllocatePool (Size
);
152 ASSERT (HandleBuffer
!= NULL
);
153 if (HandleBuffer
== NULL
) {
156 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, HandleBuffer
);
158 if (EFI_ERROR (Status
)) {
159 PrintToken (STRING_TOKEN (STR_DP_HANDLES_ERROR
), Status
);
162 // We have successfully populated the HandleBuffer
163 // Display ALL Measurement Records
164 // Up to Limit lines displayed
165 // Display only records with Elapsed times >= mInterestThreshold
166 // Display driver names in Module field for records with Handles.
168 PrintToken (STRING_TOKEN (STR_DP_ALL_HEADR
) );
169 PrintToken (STRING_TOKEN (STR_DP_DASHES
) );
174 while ( WITHIN_LIMIT(Count
, Limit
) &&
175 ((LogEntryKey
= GetPerformanceMeasurement (
180 &Measurement
.StartTimeStamp
,
181 &Measurement
.EndTimeStamp
)) != 0)
184 ++Index
; // Count every record. First record is 1.
186 if (Measurement
.EndTimeStamp
!= 0) {
187 Duration
= GetDuration (&Measurement
);
188 ElapsedTime
= DurationInMicroSeconds ( Duration
);
189 IncFlag
= STR_DP_COMPLETE
;
192 IncFlag
= STR_DP_INCOMPLETE
; // Mark incomplete records
194 if ((ElapsedTime
< mInterestThreshold
) ||
195 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
196 ) { // Ignore "uninteresting" or excluded records
199 if (Measurement
.EndTimeStamp
== 0) {
200 ElapsedTime
= Measurement
.StartTimeStamp
;
202 ++Count
; // Count the number of records printed
204 // If Handle is non-zero, see if we can determine a name for the driver
205 AsciiStrToUnicodeStr (Measurement
.Module
, mGaugeString
); // Use Module by default
206 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
207 if (Measurement
.Handle
!= NULL
) {
208 // See if the Handle is in the HandleBuffer
209 for (TIndex
= 0; TIndex
< (Size
/ sizeof(HandleBuffer
[0])); TIndex
++) {
210 if (Measurement
.Handle
== HandleBuffer
[TIndex
]) {
211 GetNameFromHandle (HandleBuffer
[TIndex
]);
216 // Ensure that the argument strings are not too long.
217 mGaugeString
[31] = 0;
218 mUnicodeToken
[18] = 0;
220 PrintToken( STRING_TOKEN (STR_DP_ALL_STATS
),
221 Index
, // 1 based, Which measurement record is being printed
230 if (HandleBuffer
!= &TempHandle
) {
231 FreePool (HandleBuffer
);
236 Gather and print Raw Trace Records.
238 All Trace measurements with a duration greater than or equal to
239 mInterestThreshold are printed without interpretation.
241 The number of records displayed is controlled by:
242 - records with a duration less than mInterestThreshold microseconds are not displayed.
243 - No more than Limit records are displayed. A Limit of zero will not limit the output.
244 - If the ExcludeFlag is TRUE, records matching entries in the CumData array are not
247 @pre The mInterestThreshold global variable is set to the shortest duration to be printed.
249 @param[in] Limit The number of records to print. Zero is ALL.
250 @param[in] ExcludeFlag TRUE to exclude individual Cumulative items from display.
256 IN BOOLEAN ExcludeFlag
259 MEASUREMENT_RECORD Measurement
;
266 EFI_STRING StringPtr
;
268 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_RAWTRACE
), NULL
);
269 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
270 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
272 PrintToken (STRING_TOKEN (STR_DP_RAW_HEADR
) );
273 PrintToken (STRING_TOKEN (STR_DP_RAW_DASHES
) );
278 while ( WITHIN_LIMIT(Count
, Limit
) &&
279 ((LogEntryKey
= GetPerformanceMeasurement (
284 &Measurement
.StartTimeStamp
,
285 &Measurement
.EndTimeStamp
)) != 0)
288 ++Index
; // Count every record. First record is 1.
290 if (Measurement
.EndTimeStamp
!= 0) {
291 Duration
= GetDuration (&Measurement
);
292 ElapsedTime
= DurationInMicroSeconds ( Duration
);
294 if ((ElapsedTime
< mInterestThreshold
) ||
295 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
296 ) { // Ignore "uninteresting" or Excluded records
299 ++Count
; // Count the number of records printed
300 PrintToken (STRING_TOKEN (STR_DP_RAW_VARS
),
301 Index
, // 1 based, Which measurement record is being printed
303 Measurement
.StartTimeStamp
,
304 Measurement
.EndTimeStamp
,
312 Gather and print Major Phase metrics.
314 @param[in] Ticker The timer value for the END of Shell phase
322 MEASUREMENT_RECORD Measurement
;
323 UINT64 BdsTimeoutValue
;
332 EFI_STRING StringPtr
;
342 // Get Execution Phase Statistics
344 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_PHASES
), NULL
);
345 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
346 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
349 while ((LogEntryKey
= GetPerformanceMeasurement (
354 &Measurement
.StartTimeStamp
,
355 &Measurement
.EndTimeStamp
)) != 0)
357 if (AsciiStrnCmp (Measurement
.Token
, ALit_SHELL
, PERF_TOKEN_LENGTH
) == 0) {
358 Measurement
.EndTimeStamp
= Ticker
;
360 if (Measurement
.EndTimeStamp
== 0) { // Skip "incomplete" records
363 Duration
= GetDuration (&Measurement
);
364 if ( Measurement
.Handle
!= NULL
365 && (AsciiStrnCmp (Measurement
.Token
, ALit_BdsTO
, PERF_TOKEN_LENGTH
) == 0)
368 BdsTimeoutValue
= Duration
;
369 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_SEC
, PERF_TOKEN_LENGTH
) == 0) {
371 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_PEI
, PERF_TOKEN_LENGTH
) == 0) {
373 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_DXE
, PERF_TOKEN_LENGTH
) == 0) {
375 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_BDS
, PERF_TOKEN_LENGTH
) == 0) {
377 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_SHELL
, PERF_TOKEN_LENGTH
) == 0) {
378 ShellTime
= Duration
;
384 // print SEC phase duration time
387 ElapsedTime
= DurationInMicroSeconds ( SecTime
); // Calculate elapsed time in microseconds
388 Total
+= DivU64x32 (ElapsedTime
, 1000); // Accumulate time in milliseconds
389 PrintToken (STRING_TOKEN (STR_DP_SEC_PHASE
), ElapsedTime
);
392 // print PEI phase duration time
395 ElapsedTime
= DivU64x32 (
397 (UINT32
)TimerInfo
.Frequency
399 Total
+= ElapsedTime
;
400 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_PEI
, ElapsedTime
);
403 // print DXE phase duration time
406 ElapsedTime
= DivU64x32 (
408 (UINT32
)TimerInfo
.Frequency
410 Total
+= ElapsedTime
;
411 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_DXE
, ElapsedTime
);
414 // print BDS phase duration time
417 ElapsedTime
= DivU64x32 (
419 (UINT32
)TimerInfo
.Frequency
421 Total
+= ElapsedTime
;
422 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_BDS
, ElapsedTime
);
425 if (BdsTimeoutValue
> 0) {
426 ElapsedTime
= DivU64x32 (
428 (UINT32
)TimerInfo
.Frequency
430 PrintToken (STRING_TOKEN (STR_DP_PHASE_BDSTO
), ALit_BdsTO
, ElapsedTime
);
433 // print SHELL phase duration time
436 ElapsedTime
= DivU64x32 (
438 (UINT32
)TimerInfo
.Frequency
440 Total
+= ElapsedTime
;
441 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_SHELL
, ElapsedTime
);
444 PrintToken (STRING_TOKEN (STR_DP_TOTAL_DURATION
), Total
);
448 Gather and print Handle data.
450 @param[in] ExcludeFlag TRUE to exclude individual Cumulative items from display.
452 @return Status from a call to gBS->LocateHandle().
456 IN BOOLEAN ExcludeFlag
459 MEASUREMENT_RECORD Measurement
;
462 EFI_HANDLE
*HandleBuffer
;
463 EFI_STRING StringPtr
;
468 EFI_HANDLE TempHandle
;
471 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_DRIVERS
), NULL
);
472 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
473 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
476 HandleBuffer
= &TempHandle
;
477 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, &TempHandle
);
478 if (Status
== EFI_BUFFER_TOO_SMALL
) {
479 HandleBuffer
= AllocatePool (Size
);
480 ASSERT (HandleBuffer
!= NULL
);
481 if (HandleBuffer
== NULL
) {
484 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, HandleBuffer
);
486 if (EFI_ERROR (Status
)) {
487 PrintToken (STRING_TOKEN (STR_DP_HANDLES_ERROR
), Status
);
491 Print (L
"There are %,d Handles defined.\n", (Size
/ sizeof(HandleBuffer
[0])));
494 PrintToken (STRING_TOKEN (STR_DP_HANDLE_GUID
) );
495 PrintToken (STRING_TOKEN (STR_DP_DASHES
) );
499 while ((LogEntryKey
= GetPerformanceMeasurement (
504 &Measurement
.StartTimeStamp
,
505 &Measurement
.EndTimeStamp
)) != 0)
508 Duration
= GetDuration (&Measurement
);
509 ElapsedTime
= DurationInMicroSeconds ( Duration
);
510 if ((ElapsedTime
< mInterestThreshold
) ||
511 (Measurement
.EndTimeStamp
== 0) ||
512 (Measurement
.Handle
== NULL
) ||
513 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
514 ) { // Ignore "uninteresting" or excluded records
517 mGaugeString
[0] = 0; // Empty driver name by default
518 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
519 // See if the Handle is in the HandleBuffer
520 for (Index
= 0; Index
< (Size
/ sizeof(HandleBuffer
[0])); Index
++) {
521 if (Measurement
.Handle
== HandleBuffer
[Index
]) {
522 GetNameFromHandle (HandleBuffer
[Index
]); // Name is put into mGaugeString
526 // Ensure that the argument strings are not too long.
527 mGaugeString
[31] = 0;
528 mUnicodeToken
[18] = 0;
529 if (mGaugeString
[0] != 0) {
530 // Display the record if it has a valid handle.
532 STRING_TOKEN (STR_DP_HANDLE_VARS
),
533 Count
, // 1 based, Which measurement record is being printed
534 Index
+ 1, // 1 based, Which handle is being printed
542 if (HandleBuffer
!= &TempHandle
) {
543 FreePool (HandleBuffer
);
549 Gather and print PEIM data.
551 Only prints complete PEIM records
559 MEASUREMENT_RECORD Measurement
;
562 EFI_STRING StringPtr
;
567 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_PEIMS
), NULL
);
568 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
569 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
571 PrintToken (STRING_TOKEN (STR_DP_PEIM_SECTION
));
572 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
575 while ((LogEntryKey
= GetPerformanceMeasurement (
580 &Measurement
.StartTimeStamp
,
581 &Measurement
.EndTimeStamp
)) != 0)
584 if ((Measurement
.EndTimeStamp
== 0) ||
585 (AsciiStrnCmp (Measurement
.Token
, ALit_PEIM
, PERF_TOKEN_LENGTH
) != 0)
590 Duration
= GetDuration (&Measurement
);
591 ElapsedTime
= DurationInMicroSeconds ( Duration
); // Calculate elapsed time in microseconds
592 if (ElapsedTime
>= mInterestThreshold
) {
593 GetNameFromHandle ((EFI_HANDLE
) Measurement
.Handle
); // Name placed in mGaugeString
594 PrintToken (STRING_TOKEN (STR_DP_PEIM_STAT2
),
595 TIndex
, // 1 based, Which measurement record is being printed
605 Gather and print global data.
607 Strips out incomplete or "Execution Phase" records
608 Only prints records where Handle is NULL
609 Increment TIndex for every record, even skipped ones, so that we have an
610 indication of every measurement record taken.
618 MEASUREMENT_RECORD Measurement
;
621 EFI_STRING StringPtr
;
623 UINTN Index
; // Index, or number, of the measurement record being processed
625 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_GENERAL
), NULL
);
626 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
627 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
629 PrintToken (STRING_TOKEN (STR_DP_GLOBAL_SECTION
));
630 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
635 while ((LogEntryKey
= GetPerformanceMeasurement (
640 &Measurement
.StartTimeStamp
,
641 &Measurement
.EndTimeStamp
)) != 0)
643 AsciiStrToUnicodeStr (Measurement
.Module
, mGaugeString
);
644 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
645 if ( ! ( IsPhase( &Measurement
) ||
646 (Measurement
.Handle
!= NULL
) ||
647 (Measurement
.EndTimeStamp
== 0)
650 Duration
= GetDuration (&Measurement
);
651 ElapsedTime
= DurationInMicroSeconds ( Duration
);
652 if (ElapsedTime
>= mInterestThreshold
) {
654 STRING_TOKEN (STR_DP_FOUR_VARS_2
),
667 Gather and print cumulative data.
669 Traverse the measurement records and:<BR>
670 For each record with a Token listed in the CumData array:<BR>
671 - Update the instance count and the total, minimum, and maximum durations.
672 Finally, print the gathered cumulative statistics.
680 UINT64 Avgval
; // the computed average duration
681 EFI_STRING StringPtr
;
685 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_CUMULATIVE
), NULL
);
686 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
687 (StringPtr
== NULL
) ? ALit_UNKNOWN
: StringPtr
);
689 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_SECT_1
));
690 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_SECT_2
));
691 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
693 for ( TIndex
= 0; TIndex
< NumCum
; ++TIndex
) {
694 Avgval
= DivU64x32 (CumData
[TIndex
].Duration
, CumData
[TIndex
].Count
);
695 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_STATS
),
696 CumData
[TIndex
].Name
,
697 CumData
[TIndex
].Count
,
698 DurationInMicroSeconds(CumData
[TIndex
].Duration
),
699 DurationInMicroSeconds(Avgval
),
700 DurationInMicroSeconds(CumData
[TIndex
].MinDur
),
701 DurationInMicroSeconds(CumData
[TIndex
].MaxDur
)