The first step when optimizing boot time is to accurately measure it. Both u-boot and EDK II provide tools to achive this.
Note: These steps were performed on an armstoneMX8MP running F&S u-boot 2020.04-fsimx8mp-Y2023.03, F&S UEFI based on NXPs i.MX Windows 10 IoT v1.5.0 release
Measuring boot time in U-Boot
A simple way to measure boot time in U-Boot is by using BOOTSTAGE mechanism.
To enable it, U-Boot needs to be built with BOOTSTAGE enabled.
When building enable these options:
Flash BOOSTAGE-enabled u-boot to the board and reboot/reset.
To see the BOOSTAGE-report enter u-boot command prompt. Type
bootstage report and hit enter.
You should be presented with a report like this one:
Code: bootstage report
- Mark Elapsed Stage
- 0 0 reset
- 7.688 7.688 SPL
- 1.592.498 1.584.810 end SPL
- 2.294.575 702.077 board_init_f
- 2.677.406 382.831 board_init_r
- 2.842.624 165.218 id=64
- 3.092.554 249.930 id=65
- 3.099.565 7.011 main_loop
- 3.129.841 30.276 bootm_start
- 3.129.843 2 id=1
- 3.134.211 4.368 id=100
- 3.134.224 13 id=101
- 3.134.224 0 id=102
- 3.137.011 2.787 id=110
- 3.193.106 56.095 id=105
- 3.193.111 5 id=106
- 3.193.119 8 id=107
- 3.193.129 10 id=108
- 3.193.137 8 id=109
- 3.202.762 9.625 id=7
- 3.202.775 13 id=15
- 3.202.776 1 start_kernel
Tip: utilise fakegocmd to automatically output the bootstage report
- In the u-boot prompt enter editenv fakegocmd
- add ; bootstage report to the end of the line
- hit enter to apply
- enter saveenv to save your changes
For further information refer to the U-Boot TRACE documentation.
Measuring boot time in EDK II/UEFI
EDK II provides some mechanisms to measure and read out boot time
To enable Performance Recording, add or change theses PCDs in the .dsc file of your platform:
Code: armstoneMX8MP.dsc
- gEfiMdePkgTokenSpaceGuid.PcdReportStatusCodePropertyMask|0x01
- gEfiMdePkgTokenSpaceGuid.PcdPerformanceLibraryPropertyMask|0x01
- #Enable DpApp to visualize UEFI Performance
- ShellPkg/DynamicCommand/DpDynamicCommand/DpApp.inf
- #Enable ReportStatusCodeRouterRuntimeDxe & FirmwarePerformanceDxe for UEFI Performance reporting
- MdeModulePkg/Universal/ReportStatusCodeRouter/RuntimeDxe/ReportStatusCodeRouterRuntimeDxe.inf
- MdeModulePkg/Universal/Acpi/FirmwarePerformanceDataTableDxe/FirmwarePerformanceDxe.inf
DpApp, ReportStatusCodeRouterRuntimeDxe and FirmwarePerformanceDxe also need to be included in your platforms .fdf file.
Code: armstoneMX8MP.fdf
- #Enable ReportStatusCodeRouterRuntimeDxe & FirmwarePerformanceDxe for UEFI Performance reporting
- INF MdeModulePkg/Universal/ReportStatusCodeRouter/RuntimeDxe/ReportStatusCodeRouterRuntimeDxe.inf
- INF MdeModulePkg/Universal/Acpi/FirmwarePerformanceDataTableDxe/FirmwarePerformanceDxe.inf
- # DP shell command Support
- #Enable DpApp to visualize UEFI Performance
- INF ShellPkg/DynamicCommand/DpDynamicCommand/DpApp.inf
Rebuild and flash EDK II to your board.
The simplest way to view the Performance Record is to boot into UEFI-Shell and entering the command dp to get a report like this one:
Code: dp
- DP Build Version: 2.5
- System Performance Timer Frequency: 8,000 (KHz)
- ==[ Major Phases ]========
- PEI Phase Duration: 270 (ms)
- DXE Phase Duration: 4431 (ms)
- Total Duration: 4701 (ms)
- ==[ Drivers by Handle ]========
- Index: Handle Driver Name Description Time(us)
- -------------------------------------------------------------------------------
- 5: [ 7] PcdDxe LoadImage: 42451
- 6: [ 7] PcdDxe StartImage: 25549
- 7: [ 9] AcpiTableDxe LoadImage: 45159
- 8: [ 9] AcpiTableDxe StartImage: 6383
- 9: [ B] SmbiosDxe LoadImage: 43670
- 10: [ B] SmbiosDxe StartImage: 6384
- 11: [ D] ReportStatusCodeRouterRuntimeDxe LoadImage: 50266
- 12: [ D] ReportStatusCodeRouterRuntimeDxe StartImage: 12741
- 13: [ F] RuntimeDxe LoadImage: 43615
- 14: [ F] RuntimeDxe StartImage: 6365
- 15: [ 11] SecurityStubDxe LoadImage: 45777
- 16: [ 11] SecurityStubDxe StartImage: 19165
- 17: [ 14] ArmGicDxe LoadImage: 42711
- 18: [ 14] ArmGicDxe StartImage: 12781
- 19: [ 16] ResetSystemRuntimeDxe LoadImage: 47905
- 20: [ 16] ResetSystemRuntimeDxe StartImage: 24912
- 21: [ 18] MetronomeDxe LoadImage: 43760
- 22: [ 18] MetronomeDxe StartImage: 6391
- 23: [ 1A] HiiDatabase LoadImage: 44912
- 24: [ 1A] HiiDatabase StartImage: 44696
- 25: [ 1C] SerialDxe LoadImage: 43671
- 26: [ 1C] SerialDxe StartImage: 12771
- 27: [ 1E] FsBdInfoDxe LoadImage: 43760
- 28: [ 1E] FsBdInfoDxe StartImage: 57055
- 29: [ 1F] SdMmcDxe LoadImage: 42890
- 30: [ 1F] SdMmcDxe StartImage: 6379
- 31: [ 20] SdhcDxe LoadImage: 42972
- 33: [ 20] SdhcDxe StartImage: 254380
- 35: [ 1F] SdMmcDxe DB:Start: 53147
- 37: [ 1F] SdMmcDxe DB:Start: 175490
- 38: [ 23] CapsuleUpdatePolicyDxe LoadImage: 47345
- 40: [ 23] CapsuleUpdatePolicyDxe StartImage: 6398
- 42: [ 25] EsrtFmpDxe LoadImage: 44021
- 45: [ 26] iMX8LcdGraphicsOutputDxe LoadImage: 48315
- 47: [ 26] iMX8LcdGraphicsOutputDxe StartImage: 191348
- 49: [ 28] iMXNorFlashDxe LoadImage: 44832
- 52: [ 29] DevicePathDxe LoadImage: 45076
- 54: [ 29] DevicePathDxe StartImage: 19170
- 56: [ 2B] EbcDxe LoadImage: 42626
- 58: [ 2B] EbcDxe StartImage: 25559
- 60: [ 2D] VariableRuntimeDxe LoadImage: 46944
- 62: [ 2D] VariableRuntimeDxe StartImage: 73222
- 67: [ 2F] SmbiosPlatformDxe LoadImage: 46734
- 69: [ 2F] SmbiosPlatformDxe StartImage: 193739
- 70: [ 30] FirmwarePerformanceDxe LoadImage: 49359
- 73: [ 31] ArmCpuDxe LoadImage: 42450
- 75: [ 31] ArmCpuDxe StartImage: 10074
- 77: [ 33] CapsuleRuntimeDxe LoadImage: 46518
- 79: [ 33] CapsuleRuntimeDxe StartImage: 5750
- 81: [ 35] MonotonicCounterRuntimeDxe LoadImage: 49662
- 83: [ 35] MonotonicCounterRuntimeDxe StartImage: 13537
- 85: [ 37] ArmTimerDxe LoadImage: 43159
- 87: [ 37] ArmTimerDxe StartImage: 6406
- 89: [ 39] RealTimeClock LoadImage: 45899
- 91: [ 39] RealTimeClock StartImage: 39619
- 93: [ 3B] FaultTolerantWriteDxe LoadImage: 47901
- 96: [ 3C] FmpDxe LoadImage: 44486
- 98: [ 3C] FmpDxe StartImage: 103132
- 99: [ 3D] EsrtDxe LoadImage: 42985
- 101: [ 3D] EsrtDxe StartImage: 6390
- 103: [ 3F] LogoDxe LoadImage: 48235
- 105: [ 3F] LogoDxe StartImage: 6391
- 107: [ 41] iMX8Dxe LoadImage: 42373
- 109: [ 41] iMX8Dxe StartImage: 32041
- 112: [ 44] SetupBrowser LoadImage: 45269
- 114: [ 44] SetupBrowser StartImage: 19191
- 117: [ 47] BdsDxe LoadImage: 42649
- 119: [ 47] BdsDxe StartImage: 67732
- 121: [ 49] WatchdogTimer LoadImage: 45343
- 123: [ 49] WatchdogTimer StartImage: 6399
- 128: [ 4B] DisplayEngine LoadImage: 45619
- 130: [ 4B] DisplayEngine StartImage: 15145
- 132: [ 4D] ConPlatformDxe LoadImage: 46135
- 134: [ 4D] ConPlatformDxe StartImage: 12787
- 138: [ 4F] ConSplitterDxe LoadImage: 46136
- 142: [ 4F] ConSplitterDxe StartImage: 70516
- 199: [ 57] GraphicsConsoleDxe LoadImage: 47537
- 208: [ 57] GraphicsConsoleDxe StartImage: 6368
- 209: [ 58] TerminalDxe LoadImage: 45090
- 219: [ 58] TerminalDxe StartImage: 6364
- 220: [ 59] DiskIoDxe LoadImage: 44123
- 231: [ 59] DiskIoDxe StartImage: 6369
- 232: [ 5A] PartitionDxe LoadImage: 45176
- 244: [ 5A] PartitionDxe StartImage: 6368
- 245: [ 5B] Fat LoadImage: 41153
- 258: [ 5B] Fat StartImage: 6367
- 259: [ 5C] EnglishDxe LoadImage: 45964
- 273: [ 5C] EnglishDxe StartImage: 12810
- 287: [ 5E] FvSimpleFileSystem LoadImage: 47363
- 301: [ 5E] FvSimpleFileSystem StartImage: 6368
- 302: [ 5F] BootGraphicsResourceTableDxe LoadImage: 49898
- 317: [ 5F] BootGraphicsResourceTableDxe StartImage: 12822
- 372: [ 57] GraphicsConsoleDxe DB:Start: 27942
- 376: [ 4D] ConPlatformDxe DB:Start: 11502
- 383: [ 4F] ConSplitterDxe DB:Start: 33026
- 411: [ 58] TerminalDxe DB:Start: 49937
- 427: [ 4D] ConPlatformDxe DB:Start: 5599
- 430: [ 4D] ConPlatformDxe DB:Start: 11498
- 630: [ 5E] FvSimpleFileSystem DB:Start: 5308
- 658: [ 5E] FvSimpleFileSystem DB:Start: 6186
- 1004: [ 58] TerminalDxe DB:Start: 1040
- 1127: [ 59] DiskIoDxe DB:Start: 3546
- 1129: [ 5A] PartitionDxe DB:Start: 199626
- 1163: [ 59] DiskIoDxe DB:Start: 7944
- 1165: [ 5A] PartitionDxe DB:Start: 2870
- 1200: [ 59] DiskIoDxe DB:Start: 4550
- 1202: [ 5A] PartitionDxe DB:Start: 10441
- 1214: [ 5B] Fat DB:Start: 6313
- 1237: [ 59] DiskIoDxe DB:Start: 6248
- 1239: [ 5A] PartitionDxe DB:Start: 6160
- 1274: [ 59] DiskIoDxe DB:Start: 3538
- 1276: [ 5A] PartitionDxe DB:Start: 10789
- 1311: [ 59] DiskIoDxe DB:Start: 7508
- 1313: [ 5A] PartitionDxe DB:Start: 8803
- 1348: [ 59] DiskIoDxe DB:Start: 7472
- 1350: [ 5A] PartitionDxe DB:Start: 95688
- 1384: [ 59] DiskIoDxe DB:Start: 7947
- 1386: [ 5A] PartitionDxe DB:Start: 3936
- 1421: [ 59] DiskIoDxe DB:Start: 3535
- 1423: [ 5A] PartitionDxe DB:Start: 11890
- 1435: [ 5B] Fat DB:Start: 6311
- ==[ PEIMs ]========
- Index: Instance GUID Token Time(us)
- -------------------------------------------------------------------------------
- ==[ General ]========
- Index Name Description Time(us)
- -------------------------------------------------------------------------------
- 3: CoreInitializeDispatche CoreInitializeDispatche 4552
- 4: CoreDispatcher CoreDispatcher 4236705
- 333: PlatformBootManagerBefo PlatformBootManagerBefo 21166
- 362: EfiBootManagerConnectAl EfiBootManagerConnectAl 227494
- 453: ConOutReady ConOutReady 591615319
- 468: ConInReady ConInReady 591615433
- 497: ErrOutReady ErrOutReady 591615665
- 498: PlatformBootManagerAfte PlatformBootManagerAfte 7960
- 499: BdsWait BdsWait 3212
- 500: EsrtReadyToBootEventNot EsrtReadyToBootEventNot 120126
- 529: ConOutReady ConOutReady 591825949
- 544: ConInReady ConInReady 591826059
- 573: ErrOutReady ErrOutReady 591826292
- ==[ Cumulative ]========
- (Times in microsec.) Cumulative Average Shortest Longest
- Name Count Duration Duration Duration Duration
- -------------------------------------------------------------------------------
- LoadImage: 49 2220070 45307 41153 50266
- StartImage: 49 1796807 36669 12 289917
- DB:Start: 42 797851 18996 4 199626
- DB:Support: 1866 5242 2 0 18
For more information refer to the official EDK II "Performance Infrastructure" wiki entry.
