firmware_ECBootTime prints something that it calls "EC cold boot time" (and checks that it is under 1 second).
However, the script simply records the timestamp at which either of these 2 strings is printed:
ec_ready = ["(?ms)UART.*UART.*?\[([0-9.]+) "]
ec_ready = ["([0-9.]+) Inits done"]
The first one is printed very early in the boot process (and the first CPRINTS timestamp is used). The second one is printed at the end of common/main.c main() function.
--- UART initialized after reboot ---
[Reset cause: soft ap-off]
[Image: RO, soraka_v1.1.8494-bdafeef32 2018-05-29 08:25:22 drinkcat@drinkcat.tpe.corp.google.com]
[0.001158 init buttons]
[0.001390 Inits done]
[0.002235 Board ID = 7]
Restarting system with PMIC.
�
--- UART initialized after reboot ---
[Reset cause: reset-pin ap-off]
[Image: RO, soraka_v1.1.8494-bdafeef32 2018-05-29 08:25:22 drinkcat@drinkcat.tpe.corp.google.com]
[0.001193 init buttons]
[0.001414 Inits done]
[0.041069 event set 0x0000000004000000]
[0.047173 SW 0x05]
[0.047688 hash start 0x00040000 0x0001f9e0]
For example, on Soraka, it catches this line: "[0.001390 Inits done]" (despite the fact that there is a PMIC reset afterwards).
Essentially, "EC cold boot time" measures the time it takes for the EC to run the "main" function: this does not take much time on any platform.
This time should probably:
- Take into account any time spent by EC chip to initialize, nor to load the firmware (for EC chips that copy their FW from external flash, for example).
- Take into account any time after the main function, where the EC is still initializing (tasks, hook, etc.), although this is harder to measure/quantify.