NVIDIA Tegra
NVIDIA DRIVE OS 5.1 Linux

Developer Guide
5.1.0.2 Release


 
Boot Profiling Utility for AV+L/Q
 
Determining the Overall System Boot Time?
This topic describes how to profile the amount of time it takes to boot on platforms that use NVIDIA® Tegra® devices.
To enable profile dumping (virtual machine instances only)
Use debug server command d to dump QB profiling data.
The following is an example of the output.
Profiling Event
Time Stamp
Time Taken
D-S
d
 
Dumping profile info for MB1:
 
 
MB1 entry
23310us
 
MB1 done
687991us
664681us
 
 
 
Dumping profile info for MB2:
 
 
MB2 entry
689504us
 
MB2 done
1085614us
396110us
 
 
 
Dumping profile info for BPMP FW:
 
 
[bpmp] start
1086130us
 
[bpmp] profiler_init
1101532us
15402us
[bpmp] serial
1143104us
41572us
[bpmp] r
1143150us
46us
[bpmp] ringbuf_console
1143786us
636us
[bpmp] workqueue
1193343us
49557us
[bpmp] debugfs
1193561us
218us
[bpmp] mail_mach
1193574us
13us
[bpmp] dt
1224113us
30539us
[bpmp] mail
1225124us
1011us
[bpmp] chipid
1225329us
205us
[bpmp] fuse
1225698us
369us
[bpmp] sku
1225934us
236us
[bpmp] speedo
1226184us
250us
[bpmp] ec
1227532us
1348us
[bpmp] vmon
1228069us
537us
[bpmp] adc
1229281us
1212us
[bpmp] fmon
1262227us
32946us
[bpmp] reset
1264080us
1853us
[bpmp] nvhs
1265208us
1128us
[bpmp] clk
1400108us
134900us
[bpmp] io_dpd
1400555us
447us
[bpmp] thermal
1400804us
249us
[bpmp] i2c
1413136us
12332us
[bpmp] regulator
1418199us
5063us
[bpmp] avfs_clk_platform
1455580us
37381us
[bpmp] soctherm
1457911us
2331us
[bpmp] aotag
1458618us
707us
[bpmp] powergate
1458958us
340us
[bpmp] dvs
1485399us
26441us
[bpmp] pm
1486171us
772us
[bpmp] pg_late
1486831us
660us
[bpmp] strap
1487063us
232us
[bpmp] tag
1487253us
190us
[bpmp] emc
1525274us
38021us
[bpmp] clk_dt
1530788us
5514us
[bpmp] avfs_ccplex_platform
1531054us
266us
[bpmp] tj_init
1532038us
984us
[bpmp] uphy_dt
1533096us
1058us
[bpmp] uphy
1537593us
4497us
[bpmp] mrq
1537810us
217us
[bpmp] fmon_post
1538474us
664us
[bpmp] clk_dt_late
1570660us
32186us
[bpmp] machine_check
1571203us
543us
[bpmp] tag_lateinit
1571911us
708us
[bpmp] pm_post
1576511us
4600us
[bpmp] dbells
1576687us
176us
[bpmp] avfs_clk_platform_post
1577242us
555us
[bpmp] dmce
1577972us
730us
[bpmp] cvc
1578253us
281us
[bpmp] avfs_clk_mach_post
1592341us
14088us
[bpmp] gboost_init
1595122us
2781us
[bpmp] aotag_hsm
1597306us
2184us
[bpmp] regulator_post
1599502us
2196us
[bpmp] rm
1601793us
2291us
[bpmp] sc7_diag
1603224us
1431us
[bpmp] thermal_test
1605112us
1888us
[bpmp] serial_late
1607397us
2285us
[bpmp] clk_post
1609565us
2168us
[bpmp] clk_dt_post
1611506us
1941us
[bpmp] mc_pcie
1613701us
2195us
[bpmp] pg_post
1621252us
7551us
[bpmp] sku_debugfs
1621448us
196us
 
 
 
Dumping profile info for TOS FW:
 
 
[TF] early setup entry
1091219us
 
[TF] early setup exit
1091339us
120us
[TF] arch setup entry
1091402us
63us
[TF] arch setup exit
1101841us
10439us
[TF] plat setup entry
1104004us
2163us
[TF] plat setup exit
1107318us
3314us
[TF] bl31 exit
1167951us
60633us
 
 
 
Dumping profile info for CPU BL:
 
 
qb: EL2 Init TS
1168114us
 
qb: CacheFlush
1169202us
1088us
qb: PreMMUInit
1172854us
3652us
qb: MMU Init
1175794us
2940us
qb: BPMP Init
1538608us
362814us
qb: Driver Init
1542908us
4300us
qb: DT Init
1573859us
30951us
qb: SCE Init Done
1573865us
6us
qb: Scrub Start
1573866us
1us
qb: Scrub End
1573867us
1us
qb: PT Init
1574896us
1029us
qb: QbLateRegisterDevice
1587704us
12808us
qb: LoadKernel
1643690us
55986us
qb: LoadRamdisk
1643712us
22us
qb: LoadDTB
1643725us
13us
qb: KernelEnv Setup
1644105us
380us
qb: Kernel Handoff
1644222us
117us
 
 
 
Dumping profile info for Hypervisor:
 
 
HV: Start
1645542us
 
HV: Start preinit resources
1645740us
198us
HV: Done preinit resources
1645794us
54us
HV: Start loading containers
1645854us
60us
HV: Done loading containers
1664062us
18208us
HV: Done with guest_init
1677347us
13285us
HV: Start memory allocation & mapping(ivc, guest)
1678892us
1545us
HV: plat: gpio init done
1681952us
3060us
HV: plat: host1x init done
1682340us
388us
HV: plat: smmu init done
1682475us
135us
HV: plat: mc init done
1682670us
195us
HV: plat: gpu init done
1682686us
16us
HV: plat: ape init done
1682758us
72us
HV: plat: capture init done
1682945us
187us
HV: plat: hsp init done
1683136us
191us
HV: plat: se init done
1683142us
6us
HV: plat: bpmp init done
1683328us
186us
HV: plat: xhci init done
1683348us
20us
HV: plat: pci init done
1683429us
81us
HV: Done with memory operations
1708920us
25491us
HV: Before printing hello
1708922us
2us
HV: Start Asynchronous SMP
1709279us
357us
 
 
 
Dumping profile info for guest 0 Guest OS:
 
 
pl: EL1 Init TS
2158420us
 
pl: CacheFlush
2158883us
463us
pl: PreMMUInit
2158999us
116us
pl: MMU Init
2159330us
331us
pl: Driver Init
2160007us
677us
pl: DT Init
2162576us
2569us
pl: Kernel Handoff
2181635us
19059us
osl: EL1 Init TS
2182251us
616us
osl: CacheFlush
2183536us
1285us
osl: PreMMUInit
2188208us
4672us
osl: MMU Init
2189310us
1102us
osl: Driver Init
2189469us
159us
osl: DT Init
2191336us
1867us
osl: PT Init
2201837us
10501us
osl: LoadKernel
2565655us
363818us
osl: LoadRamdisk
2584954us
19299us
osl: LoadDTB
2587258us
2304us
osl: KernelEnv Setup
2597430us
10172us
osl: Kernel Handoff
2597585us
155us
 
 
 
Dumping profile info for guest 1 IX service:
 
 
pl: EL1 Init TS
2187840us
 
pl: CacheFlush
2188898us
1058us
pl: PreMMUInit
2189030us
132us
pl: MMU Init
2189363us
333us
pl: Driver Init
2189492us
129us
pl: DT Init
2190855us
1363us
pl: Kernel Handoff
2199615us
8760us
osl: EL1 Init TS
2200185us
570us
osl: CacheFlush
2201861us
1676us
osl: PreMMUInit
2202262us
401us
osl: MMU Init
2202636us
374us
osl: Driver Init
2202787us
151us
osl: DT Init
2204057us
1270us
osl: PT Init
2237909us
33852us
osl: LoadKernel
2487777us
249868us
osl: LoadDTB
2544418us
56641us
osl: KernelEnv Setup
2553722us
9304us
osl: Kernel Handoff
2553879us
157us
 
 
 
Dumping profile info for guest 2 Comms service:
 
 
pl: EL1 Init TS
2161032us
 
pl: CacheFlush
2161733us
701us
pl: PreMMUInit
2161969us
236us
pl: MMU Init
2162316us
347us
pl: Driver Init
2162447us
131us
pl: DT Init
2164402us
1955us
pl: Kernel Handoff
2173401us
8999us
osl: EL1 Init TS
2173717us
316us
osl: CacheFlush
2174166us
449us
osl: PreMMUInit
2174597us
431us
osl: MMU Init
2174937us
340us
osl: Driver Init
2175095us
158us
osl: DT Init
2175992us
897us
osl: PT Init
2186983us
10991us
osl: LoadKernel
2393420us
206437us
osl: LoadDTB
2481219us
87799us
osl: KernelEnv Setup
2490458us
9239us
osl: Kernel Handoff
2490585us
127us
 
 
 
Dumping profile info for guest 3 Security service:
 
 
pl: EL1 Init TS
2168471us
 
pl: CacheFlush
2169698us
1227us
pl: PreMMUInit
2169819us
121us
pl: MMU Init
2170558us
739us
pl: Driver Init
2170842us
284us
pl: DT Init
2175422us
4580us
pl: Kernel Handoff
2184728us
9306us
osl: EL1 Init TS
2185193us
465us
osl: CacheFlush
2185921us
728us
osl: PreMMUInit
2186357us
436us
osl: MMU Init
2186693us
336us
osl: Driver Init
2186815us
122us
osl: DT Init
2188776us
1961us
osl: PT Init
2201857us
13081us
osl: LoadKernel
2443559us
241702us
osl: LoadDTB
2525936us
82377us
osl: KernelEnv Setup
2539408us
13472us
osl: Kernel Handoff
2539565us
157us
 
 
 
Dumping profile info for guest 4 Safety service:
 
 
pl: EL1 Init TS
2163554us
 
pl: CacheFlush
2164402us
848us
pl: PreMMUInit
2164719us
317us
pl: MMU Init
2165236us
517us
pl: Driver Init
2165379us
143us
pl: DT Init
2166310us
931us
pl: Kernel Handoff
2176809us
10499us
osl: EL1 Init TS
2177365us
556us
osl: CacheFlush
2178114us
749us
osl: PreMMUInit
2178538us
424us
osl: MMU Init
2178899us
361us
osl: Driver Init
2179008us
109us
osl: DT Init
2180112us
1104us
osl: PT Init
2212502us
32390us
osl: LoadKernel
2418201us
205699us
osl: LoadDTB
2525438us
107237us
osl: KernelEnv Setup
2536874us
11436us
osl: Kernel Handoff
2537030us
156us
 
 
 
Dumping profile info for guest 5 OTA service:
 
 
pl: EL1 Init TS
2159387us
 
pl: CacheFlush
2160106us
719us
pl: PreMMUInit
2160245us
139us
pl: MMU Init
2160791us
546us
pl: Driver Init
2160902us
111us
pl: DT Init
2162774us
1872us
pl: Kernel Handoff
2169992us
7218us
osl: EL1 Init TS
2170512us
520us
osl: CacheFlush
2172032us
1520us
osl: PreMMUInit
2172579us
547us
osl: MMU Init
2172924us
345us
osl: Driver Init
2173116us
192us
osl: DT Init
2177565us
4449us
osl: PT Init
2188226us
10661us
osl: LoadKernel
2524757us
336531us
osl: LoadDTB
2527591us
2834us
osl: KernelEnv Setup
2542003us
14412us
osl: Kernel Handoff
2542140us
137us
 
 
 
Dumping profile info for guest 6 BPMP Server:
 
 
LK_INIT_LEVEL_KERNEL
1771106us
 
LK_INIT_LEVEL_THREADING
1771244us
138us
LK_INIT_LEVEL_ARCH
1771273us
29us
LK_INIT_LEVEL_PLATFORM
1773685us
2412us
LK_INIT_LEVEL_TARGET
1773932us
247us
Notifying system manager
1811349us
37417us
Notified system manager
1811512us
163us
LK_INIT_LEVEL_APPS
1832264us
20752us
 
 
 
Dumping profile info for guest 7 Resource Manager Server:
 
 
Start_Profiler
1920552us
 
BPMP Channel Init
1972657us
52105us
 
 
 
Dumping profile info for guest 8 Monitor Partition Server:
 
 
 
 
 
Dumping profile info for guest 9 I2C Server:
 
 
LK_INIT_LEVEL_KERNEL
1743134us
 
LK_INIT_LEVEL_THREADING
1743189us
55us
LK_INIT_LEVEL_ARCH
1743216us
27us
LK_INIT_LEVEL_PLATFORM
1743519us
303us
LK_INIT_LEVEL_TARGET
1743836us
317us
Notifying system manager
1749443us
5607us
LK_INIT_LEVEL_APPS
1756563us
7120us
Notified system manager
2155871us
399308us
 
 
 
Dumping profile info for guest 10 System Manager Server:
 
 
LK_INIT_LEVEL_KERNEL
1743695us
 
LK_INIT_LEVEL_THREADING
1743748us
53us
LK_INIT_LEVEL_ARCH
1743776us
28us
LK_INIT_LEVEL_PLATFORM
1744023us
247us
LK_INIT_LEVEL_TARGET
1744244us
221us
Waiting for ack from vm 6 on IVC 59
1790292us
46048us
LK_INIT_LEVEL_APPS
1790345us
53us
Got ACK from vm 6 on IVC 59
1811653us
21308us
Waiting for ack from vm 7 on IVC 62
1811688us
35us
Got ACK from vm 7 on IVC 62
2154604us
342916us
Waiting for ack from vm 7 on IVC 71
2154625us
21us
Got ACK from vm 7 on IVC 71
2154868us
243us
Waiting for ack from vm 7 on IVC 285
2154883us
15us
Got ACK from vm 7 on IVC 285
2155220us
337us
Waiting for ack from vm 7 on IVC 109
2155235us
15us
Got ACK from vm 7 on IVC 109
2155545us
310us
Waiting for ack from vm 8 on IVC 60
2155562us
17us
Got ACK from vm 8 on IVC 60
2155703us
141us
Waiting for ack from vm 9 on IVC 61
2155718us
15us
Got ACK from vm 9 on IVC 61
2155900us
182us
Waiting for ack from vm 11 on IVC 75
2155917us
17us
Got ACK from vm 11 on IVC 75
2156074us
157us
Waiting for ack from vm 12 on IVC 78
2156089us
15us
Got ACK from vm 12 on IVC 78
2156235us
146us
Waiting for ack from vm 13 on IVC 72
2156253us
18us
Got ACK from vm 13 on IVC 72
2156461us
208us
Waiting for ack from vm 14 on IVC 73
2156480us
19us
Got ACK from vm 14 on IVC 73
2156657us
177us
 
 
 
Dumping profile info for guest 11 Storage Server:
 
 
LK_INIT_LEVEL_KERNEL
1744961us
 
LK_INIT_LEVEL_THREADING
1745091us
130us
LK_INIT_LEVEL_ARCH
1745122us
31us
LK_INIT_LEVEL_PLATFORM
1746479us
1357us
LK_INIT_LEVEL_TARGET
1849496us
103017us
Notifying system manager
1854066us
4570us
LK_INIT_LEVEL_APPS
1868654us
14588us
Notified system manager
2156041us
287387us
 
 
 
Dumping profile info for guest 12 Security Engine Server:
 
 
LK_INIT_LEVEL_KERNEL
1741307us
 
LK_INIT_LEVEL_THREADING
1741409us
102us
LK_INIT_LEVEL_ARCH
1741440us
31us
LK_INIT_LEVEL_PLATFORM
1741755us
315us
LK_INIT_LEVEL_TARGET
1742756us
1001us
Notifying system manager
1743281us
525us
LK_INIT_LEVEL_APPS
1750347us
7066us
Notified system manager
2156201us
405854us
The output includes the profiling event, the timestamp of each event, and the amount of time taken for each event, where applicable.
Determining the Overall System Boot Time?
The last IVC acknowledgement (got ACK from VM 14 on IVC 73) received at Guest 10 System Manager Server defines the system readiness and can be used as the overall system boot time.
Activity Diagram (alpha version):
Capture output of debug server d to a file (e.g., bootlog.txt) and use the following command on the Ubuntu developer machine to generate the activity diagram. The bootchart utility can be found in the boot_profiler_tool/t19x folder.
Follow the installation instructions in the README.md:
python3.5 bootlog2chart.py --bootProfileLog <SDK_PATH>bootlog.txt
https://nvbugswb.nvidia.com/NVBugs5/DownloadAttachment.aspx?attachmentguid=dae3c900-fb9c-4395-aaac-7d1b3b7213c0