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
;
140 EFI_STRING StringPtrUnknown
;
142 StringPtrUnknown
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_ALIT_UNKNOWN
), NULL
);
143 IncFlag
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_ALL
), NULL
);
144 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
145 (IncFlag
== NULL
) ? StringPtrUnknown
: IncFlag
);
146 FreePool (StringPtrUnknown
);
148 // Get Handle information
151 HandleBuffer
= &TempHandle
;
152 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, &TempHandle
);
153 if (Status
== EFI_BUFFER_TOO_SMALL
) {
154 HandleBuffer
= AllocatePool (Size
);
155 ASSERT (HandleBuffer
!= NULL
);
156 if (HandleBuffer
== NULL
) {
159 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, HandleBuffer
);
161 if (EFI_ERROR (Status
)) {
162 PrintToken (STRING_TOKEN (STR_DP_HANDLES_ERROR
), Status
);
165 // We have successfully populated the HandleBuffer
166 // Display ALL Measurement Records
167 // Up to Limit lines displayed
168 // Display only records with Elapsed times >= mInterestThreshold
169 // Display driver names in Module field for records with Handles.
171 PrintToken (STRING_TOKEN (STR_DP_ALL_HEADR
) );
172 PrintToken (STRING_TOKEN (STR_DP_DASHES
) );
177 while ( WITHIN_LIMIT(Count
, Limit
) &&
178 ((LogEntryKey
= GetPerformanceMeasurement (
183 &Measurement
.StartTimeStamp
,
184 &Measurement
.EndTimeStamp
)) != 0)
187 ++Index
; // Count every record. First record is 1.
189 if (IncFlag
!= NULL
) {
190 FreePool ((void *)IncFlag
);
192 if (Measurement
.EndTimeStamp
!= 0) {
193 Duration
= GetDuration (&Measurement
);
194 ElapsedTime
= DurationInMicroSeconds ( Duration
);
195 IncFlag
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_COMPLETE
), NULL
);
198 IncFlag
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_INCOMPLETE
), NULL
); // Mark incomplete records
200 if ((ElapsedTime
< mInterestThreshold
) ||
201 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
202 ) { // Ignore "uninteresting" or excluded records
205 if (Measurement
.EndTimeStamp
== 0) {
206 ElapsedTime
= Measurement
.StartTimeStamp
;
208 ++Count
; // Count the number of records printed
210 // If Handle is non-zero, see if we can determine a name for the driver
211 AsciiStrToUnicodeStr (Measurement
.Module
, mGaugeString
); // Use Module by default
212 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
213 if (Measurement
.Handle
!= NULL
) {
214 // See if the Handle is in the HandleBuffer
215 for (TIndex
= 0; TIndex
< (Size
/ sizeof(HandleBuffer
[0])); TIndex
++) {
216 if (Measurement
.Handle
== HandleBuffer
[TIndex
]) {
217 GetNameFromHandle (HandleBuffer
[TIndex
]);
222 // Ensure that the argument strings are not too long.
223 mGaugeString
[31] = 0;
224 mUnicodeToken
[18] = 0;
226 PrintToken( STRING_TOKEN (STR_DP_ALL_STATS
),
227 Index
, // 1 based, Which measurement record is being printed
236 if (HandleBuffer
!= &TempHandle
) {
237 FreePool (HandleBuffer
);
239 FreePool ((void *)IncFlag
);
243 Gather and print Raw Trace Records.
245 All Trace measurements with a duration greater than or equal to
246 mInterestThreshold are printed without interpretation.
248 The number of records displayed is controlled by:
249 - records with a duration less than mInterestThreshold microseconds are not displayed.
250 - No more than Limit records are displayed. A Limit of zero will not limit the output.
251 - If the ExcludeFlag is TRUE, records matching entries in the CumData array are not
254 @pre The mInterestThreshold global variable is set to the shortest duration to be printed.
256 @param[in] Limit The number of records to print. Zero is ALL.
257 @param[in] ExcludeFlag TRUE to exclude individual Cumulative items from display.
263 IN BOOLEAN ExcludeFlag
266 MEASUREMENT_RECORD Measurement
;
273 EFI_STRING StringPtr
;
274 EFI_STRING StringPtrUnknown
;
276 StringPtrUnknown
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_ALIT_UNKNOWN
), NULL
);
277 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_RAWTRACE
), NULL
);
278 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
279 (StringPtr
== NULL
) ? StringPtrUnknown
: StringPtr
);
280 FreePool (StringPtr
);
281 FreePool (StringPtrUnknown
);
283 PrintToken (STRING_TOKEN (STR_DP_RAW_HEADR
) );
284 PrintToken (STRING_TOKEN (STR_DP_RAW_DASHES
) );
289 while ( WITHIN_LIMIT(Count
, Limit
) &&
290 ((LogEntryKey
= GetPerformanceMeasurement (
295 &Measurement
.StartTimeStamp
,
296 &Measurement
.EndTimeStamp
)) != 0)
299 ++Index
; // Count every record. First record is 1.
301 if (Measurement
.EndTimeStamp
!= 0) {
302 Duration
= GetDuration (&Measurement
);
303 ElapsedTime
= DurationInMicroSeconds ( Duration
);
305 if ((ElapsedTime
< mInterestThreshold
) ||
306 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
307 ) { // Ignore "uninteresting" or Excluded records
310 ++Count
; // Count the number of records printed
311 PrintToken (STRING_TOKEN (STR_DP_RAW_VARS
),
312 Index
, // 1 based, Which measurement record is being printed
314 Measurement
.StartTimeStamp
,
315 Measurement
.EndTimeStamp
,
323 Gather and print Major Phase metrics.
325 @param[in] Ticker The timer value for the END of Shell phase
333 MEASUREMENT_RECORD Measurement
;
334 UINT64 BdsTimeoutValue
;
343 EFI_STRING StringPtr
;
345 EFI_STRING StringPtrUnknown
;
354 // Get Execution Phase Statistics
356 StringPtrUnknown
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_ALIT_UNKNOWN
), NULL
);
357 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_PHASES
), NULL
);
358 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
359 (StringPtr
== NULL
) ? StringPtrUnknown
: StringPtr
);
360 FreePool (StringPtr
);
361 FreePool (StringPtrUnknown
);
364 while ((LogEntryKey
= GetPerformanceMeasurement (
369 &Measurement
.StartTimeStamp
,
370 &Measurement
.EndTimeStamp
)) != 0)
372 if (AsciiStrnCmp (Measurement
.Token
, ALit_SHELL
, PERF_TOKEN_LENGTH
) == 0) {
373 Measurement
.EndTimeStamp
= Ticker
;
375 if (Measurement
.EndTimeStamp
== 0) { // Skip "incomplete" records
378 Duration
= GetDuration (&Measurement
);
379 if ( Measurement
.Handle
!= NULL
380 && (AsciiStrnCmp (Measurement
.Token
, ALit_BdsTO
, PERF_TOKEN_LENGTH
) == 0)
383 BdsTimeoutValue
= Duration
;
384 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_SEC
, PERF_TOKEN_LENGTH
) == 0) {
386 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_PEI
, PERF_TOKEN_LENGTH
) == 0) {
388 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_DXE
, PERF_TOKEN_LENGTH
) == 0) {
390 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_BDS
, PERF_TOKEN_LENGTH
) == 0) {
392 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_SHELL
, PERF_TOKEN_LENGTH
) == 0) {
393 ShellTime
= Duration
;
399 // print SEC phase duration time
402 ElapsedTime
= DurationInMicroSeconds ( SecTime
); // Calculate elapsed time in microseconds
403 Total
+= DivU64x32 (ElapsedTime
, 1000); // Accumulate time in milliseconds
404 PrintToken (STRING_TOKEN (STR_DP_SEC_PHASE
), ElapsedTime
);
407 // print PEI phase duration time
410 ElapsedTime
= DivU64x32 (
412 (UINT32
)TimerInfo
.Frequency
414 Total
+= ElapsedTime
;
415 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_PEI
, ElapsedTime
);
418 // print DXE phase duration time
421 ElapsedTime
= DivU64x32 (
423 (UINT32
)TimerInfo
.Frequency
425 Total
+= ElapsedTime
;
426 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_DXE
, ElapsedTime
);
429 // print BDS phase duration time
432 ElapsedTime
= DivU64x32 (
434 (UINT32
)TimerInfo
.Frequency
436 Total
+= ElapsedTime
;
437 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_BDS
, ElapsedTime
);
440 if (BdsTimeoutValue
> 0) {
441 ElapsedTime
= DivU64x32 (
443 (UINT32
)TimerInfo
.Frequency
445 PrintToken (STRING_TOKEN (STR_DP_PHASE_BDSTO
), ALit_BdsTO
, ElapsedTime
);
448 // print SHELL phase duration time
451 ElapsedTime
= DivU64x32 (
453 (UINT32
)TimerInfo
.Frequency
455 Total
+= ElapsedTime
;
456 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_SHELL
, ElapsedTime
);
459 PrintToken (STRING_TOKEN (STR_DP_TOTAL_DURATION
), Total
);
463 Gather and print Handle data.
465 @param[in] ExcludeFlag TRUE to exclude individual Cumulative items from display.
467 @return Status from a call to gBS->LocateHandle().
471 IN BOOLEAN ExcludeFlag
474 MEASUREMENT_RECORD Measurement
;
477 EFI_HANDLE
*HandleBuffer
;
478 EFI_STRING StringPtr
;
483 EFI_HANDLE TempHandle
;
485 EFI_STRING StringPtrUnknown
;
487 StringPtrUnknown
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_ALIT_UNKNOWN
), NULL
);
488 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_DRIVERS
), NULL
);
489 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
490 (StringPtr
== NULL
) ? StringPtrUnknown
: StringPtr
);
491 FreePool (StringPtr
);
492 FreePool (StringPtrUnknown
);
495 HandleBuffer
= &TempHandle
;
496 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, &TempHandle
);
497 if (Status
== EFI_BUFFER_TOO_SMALL
) {
498 HandleBuffer
= AllocatePool (Size
);
499 ASSERT (HandleBuffer
!= NULL
);
500 if (HandleBuffer
== NULL
) {
503 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, HandleBuffer
);
505 if (EFI_ERROR (Status
)) {
506 PrintToken (STRING_TOKEN (STR_DP_HANDLES_ERROR
), Status
);
510 Print (L
"There are %,d Handles defined.\n", (Size
/ sizeof(HandleBuffer
[0])));
513 PrintToken (STRING_TOKEN (STR_DP_HANDLE_GUID
) );
514 PrintToken (STRING_TOKEN (STR_DP_DASHES
) );
518 while ((LogEntryKey
= GetPerformanceMeasurement (
523 &Measurement
.StartTimeStamp
,
524 &Measurement
.EndTimeStamp
)) != 0)
527 Duration
= GetDuration (&Measurement
);
528 ElapsedTime
= DurationInMicroSeconds ( Duration
);
529 if ((ElapsedTime
< mInterestThreshold
) ||
530 (Measurement
.EndTimeStamp
== 0) ||
531 (Measurement
.Handle
== NULL
) ||
532 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
533 ) { // Ignore "uninteresting" or excluded records
536 mGaugeString
[0] = 0; // Empty driver name by default
537 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
538 // See if the Handle is in the HandleBuffer
539 for (Index
= 0; Index
< (Size
/ sizeof(HandleBuffer
[0])); Index
++) {
540 if (Measurement
.Handle
== HandleBuffer
[Index
]) {
541 GetNameFromHandle (HandleBuffer
[Index
]); // Name is put into mGaugeString
545 // Ensure that the argument strings are not too long.
546 mGaugeString
[31] = 0;
547 mUnicodeToken
[18] = 0;
548 if (mGaugeString
[0] != 0) {
549 // Display the record if it has a valid handle.
551 STRING_TOKEN (STR_DP_HANDLE_VARS
),
552 Count
, // 1 based, Which measurement record is being printed
553 Index
+ 1, // 1 based, Which handle is being printed
561 if (HandleBuffer
!= &TempHandle
) {
562 FreePool (HandleBuffer
);
568 Gather and print PEIM data.
570 Only prints complete PEIM records
578 MEASUREMENT_RECORD Measurement
;
581 EFI_STRING StringPtr
;
584 EFI_STRING StringPtrUnknown
;
586 StringPtrUnknown
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_ALIT_UNKNOWN
), NULL
);
587 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_PEIMS
), NULL
);
588 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
589 (StringPtr
== NULL
) ? StringPtrUnknown
: StringPtr
);
590 FreePool (StringPtr
);
591 FreePool (StringPtrUnknown
);
593 PrintToken (STRING_TOKEN (STR_DP_PEIM_SECTION
));
594 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
597 while ((LogEntryKey
= GetPerformanceMeasurement (
602 &Measurement
.StartTimeStamp
,
603 &Measurement
.EndTimeStamp
)) != 0)
606 if ((Measurement
.EndTimeStamp
== 0) ||
607 (AsciiStrnCmp (Measurement
.Token
, ALit_PEIM
, PERF_TOKEN_LENGTH
) != 0)
612 Duration
= GetDuration (&Measurement
);
613 ElapsedTime
= DurationInMicroSeconds ( Duration
); // Calculate elapsed time in microseconds
614 if (ElapsedTime
>= mInterestThreshold
) {
615 // PEIM FILE Handle is the start address of its FFS file that contains its file guid.
616 PrintToken (STRING_TOKEN (STR_DP_PEIM_STAT2
),
617 TIndex
, // 1 based, Which measurement record is being printed
618 Measurement
.Handle
, // base address
619 Measurement
.Handle
, // file guid
627 Gather and print global data.
629 Strips out incomplete or "Execution Phase" records
630 Only prints records where Handle is NULL
631 Increment TIndex for every record, even skipped ones, so that we have an
632 indication of every measurement record taken.
640 MEASUREMENT_RECORD Measurement
;
643 EFI_STRING StringPtr
;
645 UINTN Index
; // Index, or number, of the measurement record being processed
646 EFI_STRING StringPtrUnknown
;
648 StringPtrUnknown
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_ALIT_UNKNOWN
), NULL
);
649 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_GENERAL
), NULL
);
650 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
651 (StringPtr
== NULL
) ? StringPtrUnknown
: StringPtr
);
652 FreePool (StringPtr
);
653 FreePool (StringPtrUnknown
);
655 PrintToken (STRING_TOKEN (STR_DP_GLOBAL_SECTION
));
656 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
661 while ((LogEntryKey
= GetPerformanceMeasurement (
666 &Measurement
.StartTimeStamp
,
667 &Measurement
.EndTimeStamp
)) != 0)
669 AsciiStrToUnicodeStr (Measurement
.Module
, mGaugeString
);
670 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
671 if ( ! ( IsPhase( &Measurement
) ||
672 (Measurement
.Handle
!= NULL
) ||
673 (Measurement
.EndTimeStamp
== 0)
676 Duration
= GetDuration (&Measurement
);
677 ElapsedTime
= DurationInMicroSeconds ( Duration
);
678 if (ElapsedTime
>= mInterestThreshold
) {
680 STRING_TOKEN (STR_DP_FOUR_VARS_2
),
693 Gather and print cumulative data.
695 Traverse the measurement records and:<BR>
696 For each record with a Token listed in the CumData array:<BR>
697 - Update the instance count and the total, minimum, and maximum durations.
698 Finally, print the gathered cumulative statistics.
706 UINT64 AvgDur
; // the computed average duration
710 EFI_STRING StringPtr
;
712 EFI_STRING StringPtrUnknown
;
714 StringPtrUnknown
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_ALIT_UNKNOWN
), NULL
);
715 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_CUMULATIVE
), NULL
);
716 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
717 (StringPtr
== NULL
) ? StringPtrUnknown
: StringPtr
);
718 FreePool (StringPtr
);
719 FreePool (StringPtrUnknown
);
721 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_SECT_1
));
722 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_SECT_2
));
723 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
725 for ( TIndex
= 0; TIndex
< NumCum
; ++TIndex
) {
726 if (CumData
[TIndex
].Count
!= 0) {
727 AvgDur
= DivU64x32 (CumData
[TIndex
].Duration
, CumData
[TIndex
].Count
);
728 AvgDur
= DurationInMicroSeconds(AvgDur
);
729 Dur
= DurationInMicroSeconds(CumData
[TIndex
].Duration
);
730 MaxDur
= DurationInMicroSeconds(CumData
[TIndex
].MaxDur
);
731 MinDur
= DurationInMicroSeconds(CumData
[TIndex
].MinDur
);
733 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_STATS
),
734 CumData
[TIndex
].Name
,
735 CumData
[TIndex
].Count
,