2 Trace reporting for the Dp utility.
4 Copyright (c) 2009 - 2011, 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 (((Measurement
.EndTimeStamp
!= 0) && (ElapsedTime
< mInterestThreshold
)) ||
201 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
202 ) { // Ignore "uninteresting" or excluded records
205 ++Count
; // Count the number of records printed
207 // If Handle is non-zero, see if we can determine a name for the driver
208 AsciiStrToUnicodeStr (Measurement
.Module
, mGaugeString
); // Use Module by default
209 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
210 if (Measurement
.Handle
!= NULL
) {
211 // See if the Handle is in the HandleBuffer
212 for (TIndex
= 0; TIndex
< (Size
/ sizeof(HandleBuffer
[0])); TIndex
++) {
213 if (Measurement
.Handle
== HandleBuffer
[TIndex
]) {
214 GetNameFromHandle (HandleBuffer
[TIndex
]);
220 if (AsciiStrnCmp (Measurement
.Token
, ALit_PEIM
, PERF_TOKEN_LENGTH
) == 0) {
221 UnicodeSPrint (mGaugeString
, sizeof (mGaugeString
), L
"%g", Measurement
.Handle
);
224 // Ensure that the argument strings are not too long.
225 mGaugeString
[DP_GAUGE_STRING_LENGTH
] = 0;
226 mUnicodeToken
[13] = 0;
228 PrintToken( STRING_TOKEN (STR_DP_ALL_VARS
),
229 Index
, // 1 based, Which measurement record is being printed
238 if (HandleBuffer
!= &TempHandle
) {
239 FreePool (HandleBuffer
);
241 FreePool ((void *)IncFlag
);
245 Gather and print Raw Trace Records.
247 All Trace measurements with a duration greater than or equal to
248 mInterestThreshold are printed without interpretation.
250 The number of records displayed is controlled by:
251 - records with a duration less than mInterestThreshold microseconds are not displayed.
252 - No more than Limit records are displayed. A Limit of zero will not limit the output.
253 - If the ExcludeFlag is TRUE, records matching entries in the CumData array are not
256 @pre The mInterestThreshold global variable is set to the shortest duration to be printed.
258 @param[in] Limit The number of records to print. Zero is ALL.
259 @param[in] ExcludeFlag TRUE to exclude individual Cumulative items from display.
265 IN BOOLEAN ExcludeFlag
268 MEASUREMENT_RECORD Measurement
;
275 EFI_STRING StringPtr
;
276 EFI_STRING StringPtrUnknown
;
278 StringPtrUnknown
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_ALIT_UNKNOWN
), NULL
);
279 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_RAWTRACE
), NULL
);
280 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
281 (StringPtr
== NULL
) ? StringPtrUnknown
: StringPtr
);
282 FreePool (StringPtr
);
283 FreePool (StringPtrUnknown
);
285 PrintToken (STRING_TOKEN (STR_DP_RAW_HEADR
) );
286 PrintToken (STRING_TOKEN (STR_DP_RAW_DASHES
) );
291 while ( WITHIN_LIMIT(Count
, Limit
) &&
292 ((LogEntryKey
= GetPerformanceMeasurement (
297 &Measurement
.StartTimeStamp
,
298 &Measurement
.EndTimeStamp
)) != 0)
301 ++Index
; // Count every record. First record is 1.
303 if (Measurement
.EndTimeStamp
!= 0) {
304 Duration
= GetDuration (&Measurement
);
305 ElapsedTime
= DurationInMicroSeconds ( Duration
);
307 if ((ElapsedTime
< mInterestThreshold
) ||
308 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
309 ) { // Ignore "uninteresting" or Excluded records
312 ++Count
; // Count the number of records printed
313 PrintToken (STRING_TOKEN (STR_DP_RAW_VARS
),
314 Index
, // 1 based, Which measurement record is being printed
316 Measurement
.StartTimeStamp
,
317 Measurement
.EndTimeStamp
,
325 Gather and print Major Phase metrics.
327 @param[in] Ticker The timer value for the END of Shell phase
335 MEASUREMENT_RECORD Measurement
;
336 UINT64 BdsTimeoutValue
;
345 EFI_STRING StringPtr
;
347 EFI_STRING StringPtrUnknown
;
356 // Get Execution Phase Statistics
358 StringPtrUnknown
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_ALIT_UNKNOWN
), NULL
);
359 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_PHASES
), NULL
);
360 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
361 (StringPtr
== NULL
) ? StringPtrUnknown
: StringPtr
);
362 FreePool (StringPtr
);
363 FreePool (StringPtrUnknown
);
366 while ((LogEntryKey
= GetPerformanceMeasurement (
371 &Measurement
.StartTimeStamp
,
372 &Measurement
.EndTimeStamp
)) != 0)
374 if (AsciiStrnCmp (Measurement
.Token
, ALit_SHELL
, PERF_TOKEN_LENGTH
) == 0) {
375 Measurement
.EndTimeStamp
= Ticker
;
377 if (Measurement
.EndTimeStamp
== 0) { // Skip "incomplete" records
380 Duration
= GetDuration (&Measurement
);
381 if ( Measurement
.Handle
!= NULL
382 && (AsciiStrnCmp (Measurement
.Token
, ALit_BdsTO
, PERF_TOKEN_LENGTH
) == 0)
385 BdsTimeoutValue
= Duration
;
386 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_SEC
, PERF_TOKEN_LENGTH
) == 0) {
388 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_PEI
, PERF_TOKEN_LENGTH
) == 0) {
390 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_DXE
, PERF_TOKEN_LENGTH
) == 0) {
392 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_BDS
, PERF_TOKEN_LENGTH
) == 0) {
394 } else if (AsciiStrnCmp (Measurement
.Token
, ALit_SHELL
, PERF_TOKEN_LENGTH
) == 0) {
395 ShellTime
= Duration
;
401 // print SEC phase duration time
404 ElapsedTime
= DurationInMicroSeconds ( SecTime
); // Calculate elapsed time in microseconds
405 Total
+= DivU64x32 (ElapsedTime
, 1000); // Accumulate time in milliseconds
406 PrintToken (STRING_TOKEN (STR_DP_SEC_PHASE
), ElapsedTime
);
409 // print PEI phase duration time
412 ElapsedTime
= DivU64x32 (
414 (UINT32
)TimerInfo
.Frequency
416 Total
+= ElapsedTime
;
417 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_PEI
, ElapsedTime
);
420 // print DXE phase duration time
423 ElapsedTime
= DivU64x32 (
425 (UINT32
)TimerInfo
.Frequency
427 Total
+= ElapsedTime
;
428 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_DXE
, ElapsedTime
);
431 // print BDS phase duration time
434 ElapsedTime
= DivU64x32 (
436 (UINT32
)TimerInfo
.Frequency
438 Total
+= ElapsedTime
;
439 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_BDS
, ElapsedTime
);
442 if (BdsTimeoutValue
> 0) {
443 ElapsedTime
= DivU64x32 (
445 (UINT32
)TimerInfo
.Frequency
447 PrintToken (STRING_TOKEN (STR_DP_PHASE_BDSTO
), ALit_BdsTO
, ElapsedTime
);
450 // print SHELL phase duration time
453 ElapsedTime
= DivU64x32 (
455 (UINT32
)TimerInfo
.Frequency
457 Total
+= ElapsedTime
;
458 PrintToken (STRING_TOKEN (STR_DP_PHASE_DURATION
), ALit_SHELL
, ElapsedTime
);
461 PrintToken (STRING_TOKEN (STR_DP_TOTAL_DURATION
), Total
);
465 Gather and print Handle data.
467 @param[in] ExcludeFlag TRUE to exclude individual Cumulative items from display.
469 @return Status from a call to gBS->LocateHandle().
473 IN BOOLEAN ExcludeFlag
476 MEASUREMENT_RECORD Measurement
;
479 EFI_HANDLE
*HandleBuffer
;
480 EFI_STRING StringPtr
;
485 EFI_HANDLE TempHandle
;
487 EFI_STRING StringPtrUnknown
;
489 StringPtrUnknown
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_ALIT_UNKNOWN
), NULL
);
490 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_DRIVERS
), NULL
);
491 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
492 (StringPtr
== NULL
) ? StringPtrUnknown
: StringPtr
);
493 FreePool (StringPtr
);
494 FreePool (StringPtrUnknown
);
497 HandleBuffer
= &TempHandle
;
498 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, &TempHandle
);
499 if (Status
== EFI_BUFFER_TOO_SMALL
) {
500 HandleBuffer
= AllocatePool (Size
);
501 ASSERT (HandleBuffer
!= NULL
);
502 if (HandleBuffer
== NULL
) {
505 Status
= gBS
->LocateHandle (AllHandles
, NULL
, NULL
, &Size
, HandleBuffer
);
507 if (EFI_ERROR (Status
)) {
508 PrintToken (STRING_TOKEN (STR_DP_HANDLES_ERROR
), Status
);
512 Print (L
"There are %,d Handles defined.\n", (Size
/ sizeof(HandleBuffer
[0])));
515 PrintToken (STRING_TOKEN (STR_DP_HANDLE_SECTION
) );
516 PrintToken (STRING_TOKEN (STR_DP_DASHES
) );
520 while ((LogEntryKey
= GetPerformanceMeasurement (
525 &Measurement
.StartTimeStamp
,
526 &Measurement
.EndTimeStamp
)) != 0)
529 Duration
= GetDuration (&Measurement
);
530 ElapsedTime
= DurationInMicroSeconds ( Duration
);
531 if ((ElapsedTime
< mInterestThreshold
) ||
532 (Measurement
.EndTimeStamp
== 0) ||
533 (Measurement
.Handle
== NULL
) ||
534 ((ExcludeFlag
) && (GetCumulativeItem(&Measurement
) >= 0))
535 ) { // Ignore "uninteresting" or excluded records
538 mGaugeString
[0] = 0; // Empty driver name by default
539 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
540 // See if the Handle is in the HandleBuffer
541 for (Index
= 0; Index
< (Size
/ sizeof(HandleBuffer
[0])); Index
++) {
542 if (Measurement
.Handle
== HandleBuffer
[Index
]) {
543 GetNameFromHandle (HandleBuffer
[Index
]); // Name is put into mGaugeString
547 // Ensure that the argument strings are not too long.
548 mGaugeString
[DP_GAUGE_STRING_LENGTH
] = 0;
549 mUnicodeToken
[11] = 0;
550 if (mGaugeString
[0] != 0) {
551 // Display the record if it has a valid handle.
553 STRING_TOKEN (STR_DP_HANDLE_VARS
),
554 Count
, // 1 based, Which measurement record is being printed
555 Index
+ 1, // 1 based, Which handle is being printed
563 if (HandleBuffer
!= &TempHandle
) {
564 FreePool (HandleBuffer
);
570 Gather and print PEIM data.
572 Only prints complete PEIM records
580 MEASUREMENT_RECORD Measurement
;
583 EFI_STRING StringPtr
;
586 EFI_STRING StringPtrUnknown
;
588 StringPtrUnknown
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_ALIT_UNKNOWN
), NULL
);
589 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_PEIMS
), NULL
);
590 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
591 (StringPtr
== NULL
) ? StringPtrUnknown
: StringPtr
);
592 FreePool (StringPtr
);
593 FreePool (StringPtrUnknown
);
595 PrintToken (STRING_TOKEN (STR_DP_PEIM_SECTION
));
596 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
599 while ((LogEntryKey
= GetPerformanceMeasurement (
604 &Measurement
.StartTimeStamp
,
605 &Measurement
.EndTimeStamp
)) != 0)
608 if ((Measurement
.EndTimeStamp
== 0) ||
609 (AsciiStrnCmp (Measurement
.Token
, ALit_PEIM
, PERF_TOKEN_LENGTH
) != 0)
614 Duration
= GetDuration (&Measurement
);
615 ElapsedTime
= DurationInMicroSeconds ( Duration
); // Calculate elapsed time in microseconds
616 if (ElapsedTime
>= mInterestThreshold
) {
617 // PEIM FILE Handle is the start address of its FFS file that contains its file guid.
618 PrintToken (STRING_TOKEN (STR_DP_PEIM_VARS
),
619 TIndex
, // 1 based, Which measurement record is being printed
620 Measurement
.Handle
, // base address
621 Measurement
.Handle
, // file guid
629 Gather and print global data.
631 Strips out incomplete or "Execution Phase" records
632 Only prints records where Handle is NULL
633 Increment TIndex for every record, even skipped ones, so that we have an
634 indication of every measurement record taken.
642 MEASUREMENT_RECORD Measurement
;
645 EFI_STRING StringPtr
;
647 UINTN Index
; // Index, or number, of the measurement record being processed
648 EFI_STRING StringPtrUnknown
;
650 StringPtrUnknown
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_ALIT_UNKNOWN
), NULL
);
651 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_GENERAL
), NULL
);
652 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
653 (StringPtr
== NULL
) ? StringPtrUnknown
: StringPtr
);
654 FreePool (StringPtr
);
655 FreePool (StringPtrUnknown
);
657 PrintToken (STRING_TOKEN (STR_DP_GLOBAL_SECTION
));
658 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
663 while ((LogEntryKey
= GetPerformanceMeasurement (
668 &Measurement
.StartTimeStamp
,
669 &Measurement
.EndTimeStamp
)) != 0)
671 AsciiStrToUnicodeStr (Measurement
.Module
, mGaugeString
);
672 AsciiStrToUnicodeStr (Measurement
.Token
, mUnicodeToken
);
673 mGaugeString
[26] = 0;
674 mUnicodeToken
[31] = 0;
675 if ( ! ( IsPhase( &Measurement
) ||
676 (Measurement
.Handle
!= NULL
) ||
677 (Measurement
.EndTimeStamp
== 0)
680 Duration
= GetDuration (&Measurement
);
681 ElapsedTime
= DurationInMicroSeconds ( Duration
);
682 if (ElapsedTime
>= mInterestThreshold
) {
684 STRING_TOKEN (STR_DP_GLOBAL_VARS
),
697 Gather and print cumulative data.
699 Traverse the measurement records and:<BR>
700 For each record with a Token listed in the CumData array:<BR>
701 - Update the instance count and the total, minimum, and maximum durations.
702 Finally, print the gathered cumulative statistics.
710 UINT64 AvgDur
; // the computed average duration
714 EFI_STRING StringPtr
;
716 EFI_STRING StringPtrUnknown
;
718 StringPtrUnknown
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_ALIT_UNKNOWN
), NULL
);
719 StringPtr
= HiiGetString (gHiiHandle
, STRING_TOKEN (STR_DP_SECTION_CUMULATIVE
), NULL
);
720 PrintToken( STRING_TOKEN (STR_DP_SECTION_HEADER
),
721 (StringPtr
== NULL
) ? StringPtrUnknown
: StringPtr
);
722 FreePool (StringPtr
);
723 FreePool (StringPtrUnknown
);
725 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_SECT_1
));
726 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_SECT_2
));
727 PrintToken (STRING_TOKEN (STR_DP_DASHES
));
729 for ( TIndex
= 0; TIndex
< NumCum
; ++TIndex
) {
730 if (CumData
[TIndex
].Count
!= 0) {
731 AvgDur
= DivU64x32 (CumData
[TIndex
].Duration
, CumData
[TIndex
].Count
);
732 AvgDur
= DurationInMicroSeconds(AvgDur
);
733 Dur
= DurationInMicroSeconds(CumData
[TIndex
].Duration
);
734 MaxDur
= DurationInMicroSeconds(CumData
[TIndex
].MaxDur
);
735 MinDur
= DurationInMicroSeconds(CumData
[TIndex
].MinDur
);
737 PrintToken (STRING_TOKEN (STR_DP_CUMULATIVE_STATS
),
738 CumData
[TIndex
].Name
,
739 CumData
[TIndex
].Count
,