Closed aep closed 5 years ago
popcornmix
commented
5 years ago it looks like the majority of time is spent on detecting a monitor.
How are you determining this?
Do you have a hdmi monitor attached? Any different without?
sudo vcdbg log msg will show firmware side logging from boot with timestamps which may be useful.
aep
commented
5 years ago How are you determining this?
well, starring at boot output mostly. but obviously without having the source there's no way to tell what it really does.
sudo vcdbg log msg
ah nice. are they different then whats on uart? Need to find a userspace with that command.
Raspberry Pi Bootcode
Found SD card, config.txt = 1, start.elf = 1, recovery.elf = 0, timeout = 0
Read File: config.txt, 30725 (bytes)
Raspberry Pi Bootcode
Read File: config.txt, 30725
Read File: start.elf, 2864164 (bytes)
Read File: fixup.dat, 6695 (bytes)
MESS:00:00:02.405753:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:02.421113:0: brfs: File read: 30725 bytes
MESS:00:00:02.445442:0: HDMI:EDID version 1.3, 1 extensions, screen size 34x19 cm
MESS:00:00:02.451274:0: HDMI:EDID features - videodef 0x80 standby suspend active off; colour encoding:RGB444|YCbCr422; sRGB is not default colourspace; preferred format is native; does not support GTF
MESS:00:00:02.468925:0: HDMI:EDID found preferred DMT detail timing format: 1366x768p @ 60 Hz (81)
MESS:00:00:02.477553:0: HDMI:EDID found DMT format: code 4, 640x480p @ 60 Hz in established timing I/II
MESS:00:00:02.486664:0: HDMI:EDID found DMT format: code 5, 640x480p @ 72 Hz in established timing I/II
MESS:00:00:02.495779:0: HDMI:EDID found DMT format: code 6, 640x480p @ 75 Hz in established timing I/II
MESS:00:00:02.504894:0: HDMI:EDID found DMT format: code 8, 800x600p @ 56 Hz in established timing I/II
MESS:00:00:02.514008:0: HDMI:EDID found DMT format: code 9, 800x600p @ 60 Hz in established timing I/II
MESS:00:00:02.523123:0: HDMI:EDID found DMT format: code 10, 800x600p @ 72 Hz in established timing I/II
MESS:00:00:02.532324:0: HDMI:EDID found DMT format: code 11, 800x600p @ 75 Hz in established timing I/II
MESS:00:00:02.541527:0: HDMI:EDID found DMT format: code 16, 1024x768p @ 60 Hz in established timing I/II
MESS:00:00:02.550814:0: HDMI:EDID found DMT format: code 17, 1024x768p @ 70 Hz in established timing I/II
MESS:00:00:02.560103:0: HDMI:EDID found DMT format: code 18, 1024x768p @ 75 Hz in established timing I/II
MESS:00:00:02.569444:0: HDMI:EDID standard timings block x 8: 0x81C0 0101 0101 0101 0101 0101 0101 0101
MESS:00:00:02.578609:0: HDMI:EDID found DMT format: code 85, 1280x720p @ 60 Hz (16:9) in standard timing 0
MESS:00:00:02.600937:0: HDMI:EDID parsing v3 CEA extension 0
MESS:00:00:02.604916:0: HDMI:EDID monitor support - underscan IT formats:no, basic audio:yes, yuv444:yes, yuv422:yes, #native DTD:0
MESS:00:00:02.616464:0: HDMI:EDID found CEA detail timing format: 720x480p @ 60 Hz (2)
MESS:00:00:02.624104:0: HDMI:EDID found CEA detail timing format: 1280x720p @ 60 Hz (4)
MESS:00:00:02.631832:0: HDMI:EDID found CEA detail timing format: 1280x720p @ 50 Hz (19)
MESS:00:00:02.639644:0: HDMI:EDID found CEA detail timing format: 720x576p @ 50 Hz (17)
MESS:00:00:02.647361:0: HDMI:EDID found CEA format: code 1, 640x480p @ 60Hz
MESS:00:00:02.654129:0: HDMI:EDID found CEA format: code 2, 720x480p @ 60Hz
MESS:00:00:02.660900:0: HDMI:EDID found CEA format: code 3, 720x480p @ 60Hz
MESS:00:00:02.667672:0: HDMI:EDID found CEA format: code 17, 720x576p @ 50Hz
MESS:00:00:02.674529:0: HDMI:EDID found CEA format: code 18, 720x576p @ 50Hz
MESS:00:00:02.681387:0: HDMI:EDID found CEA format: code 19, 1280x720p @ 50Hz
MESS:00:00:02.688331:0: HDMI:EDID found CEA format: code 4, 1280x720p @ 60Hz
MESS:00:00:02.695213:0: HDMI:EDID found audio format 2 channels PCM, sample rate: 32|44|48|96 kHz, sample size: 16|20|24 bits
MESS:00:00:02.706198:0: HDMI:EDID found HDMI VSDB length 5
MESS:00:00:02.711415:0: HDMI:EDID HDMI VSDB has physical address 1.0.0.0
MESS:00:00:02.717829:0: HDMI:EDID HDMI VSDB has no extension fields
MESS:00:00:02.723843:0: HDMI:EDID filtering formats with pixel clock > 162 MHz or h. blanking > 1023
MESS:00:00:02.732833:0: HDMI:EDID preferred mode remained as DMT (81) 1366x768p @ 60 Hz with pixel clock 85 MHz
MESS:00:00:02.757789:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:02.773018:0: HDMI:Setting property pixel encoding to Default
MESS:00:00:02.777937:0: HDMI:Setting property pixel clock type to PAL
MESS:00:00:02.784099:0: HDMI:Setting property content type flag to No data
MESS:00:00:02.790696:0: HDMI:Setting property fuzzy format match to enabled
MESS:00:00:02.797465:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
MESS:00:00:02.985607:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
MESS:00:00:02.991427:0: hdmi: HDMI:>>>>>>>>>>>>>Rx sensed, reading EDID<<<<<<<<<<<<<
MESS:00:00:03.010917:0: hdmi: HDMI:EDID version 1.3, 1 extensions, screen size 34x19 cm
MESS:00:00:03.017270:0: hdmi: HDMI:EDID features - videodef 0x80 standby suspend active off; colour encoding:RGB444|YCbCr422; sRGB is not default colourspace; preferred format is native; does not support GTF
MESS:00:00:03.035445:0: hdmi: HDMI:EDID found preferred DMT detail timing format: 1366x768p @ 60 Hz (81)
MESS:00:00:03.044590:0: hdmi: HDMI:EDID found DMT format: code 4, 640x480p @ 60 Hz in established timing I/II
MESS:00:00:03.054222:0: hdmi: HDMI:EDID found DMT format: code 5, 640x480p @ 72 Hz in established timing I/II
MESS:00:00:03.063857:0: hdmi: HDMI:EDID found DMT format: code 6, 640x480p @ 75 Hz in established timing I/II
MESS:00:00:03.073493:0: hdmi: HDMI:EDID found DMT format: code 8, 800x600p @ 56 Hz in established timing I/II
MESS:00:00:03.083128:0: hdmi: HDMI:EDID found DMT format: code 9, 800x600p @ 60 Hz in established timing I/II
MESS:00:00:03.092763:0: hdmi: HDMI:EDID found DMT format: code 10, 800x600p @ 72 Hz in established timing I/II
MESS:00:00:03.102486:0: hdmi: HDMI:EDID found DMT format: code 11, 800x600p @ 75 Hz in established timing I/II
MESS:00:00:03.112209:0: hdmi: HDMI:EDID found DMT format: code 16, 1024x768p @ 60 Hz in established timing I/II
MESS:00:00:03.122018:0: hdmi: HDMI:EDID found DMT format: code 17, 1024x768p @ 70 Hz in established timing I/II
MESS:00:00:03.131826:0: hdmi: HDMI:EDID found DMT format: code 18, 1024x768p @ 75 Hz in established timing I/II
MESS:00:00:03.141689:0: hdmi: HDMI:EDID standard timings block x 8: 0x81C0 0101 0101 0101 0101 0101 0101 0101
MESS:00:00:03.151374:0: hdmi: HDMI:EDID found DMT format: code 85, 1280x720p @ 60 Hz (16:9) in standard timing 0
MESS:00:00:03.174222:0: hdmi: HDMI:EDID parsing v3 CEA extension 0
MESS:00:00:03.178721:0: hdmi: HDMI:EDID monitor support - underscan IT formats:no, basic audio:yes, yuv444:yes, yuv422:yes, #native DTD:0
MESS:00:00:03.190789:0: hdmi: HDMI:EDID found CEA detail timing format: 720x480p @ 60 Hz (2)
MESS:00:00:03.198950:0: hdmi: HDMI:EDID found CEA detail timing format: 1280x720p @ 60 Hz (4)
MESS:00:00:03.207199:0: hdmi: HDMI:EDID found CEA detail timing format: 1280x720p @ 50 Hz (19)
MESS:00:00:03.215532:0: hdmi: HDMI:EDID found CEA detail timing format: 720x576p @ 50 Hz (17)
MESS:00:00:03.223770:0: hdmi: HDMI:EDID found CEA format: code 1, 640x480p @ 60Hz
MESS:00:00:03.231059:0: hdmi: HDMI:EDID found CEA format: code 2, 720x480p @ 60Hz
MESS:00:00:03.238350:0: hdmi: HDMI:EDID found CEA format: code 3, 720x480p @ 60Hz
MESS:00:00:03.245642:0: hdmi: HDMI:EDID found CEA format: code 17, 720x576p @ 50Hz
MESS:00:00:03.253021:0: hdmi: HDMI:EDID found CEA format: code 18, 720x576p @ 50Hz
MESS:00:00:03.260400:0: hdmi: HDMI:EDID found CEA format: code 19, 1280x720p @ 50Hz
MESS:00:00:03.267865:0: hdmi: HDMI:EDID found CEA format: code 4, 1280x720p @ 60Hz
MESS:00:00:03.275268:0: hdmi: HDMI:EDID found audio format 2 channels PCM, sample rate: 32|44|48|96 kHz, sample size: 16|20|24 bits
MESS:00:00:03.286774:0: hdmi: HDMI:EDID found HDMI VSDB length 5
MESS:00:00:03.292511:0: hdmi: HDMI:EDID HDMI VSDB has physical address 1.0.0.0
MESS:00:00:03.299446:0: hdmi: HDMI:EDID HDMI VSDB has no extension fields
MESS:00:00:03.305982:0: hdmi: HDMI:EDID filtering formats with pixel clock > 162 MHz or h. blanking > 1023
MESS:00:00:03.315491:0: hdmi: HDMI:EDID preferred mode remained as DMT (81) 1366x768p @ 60 Hz with pixel clock 85 MHz
MESS:00:00:03.325664:0: hdmi: HDMI: hotplug attached with HDMI support
MESS:00:00:03.331931:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
MESS:00:00:03.343071:0: hdmi: HDMI: power_on to DMT mode 1366x768@60
MESS:00:00:03.350885:0: hdmi: HDMI: Action callback added to queue to happen at frame 2
MESS:00:00:03.357190:0: hdmi: HDMI: Action stop_3d_mode added to queue to happen at frame 2
MESS:00:00:03.365262:0: hdmi: HDMI: Action unmute added to queue to happen at frame 3
MESS:00:00:03.372819:0: hdmi: HDMI: Action cec_init added to queue to happen at frame 3
MESS:00:00:03.401187:0: *** Restart logging
MESS:00:00:03.403676:0: brfs: File read: 30725 bytes
MESS:00:00:03.412515:0: brfs: File read: /mfs/sd/cmdline.txt
MESS:00:00:03.416494:0: Read command line from file 'cmdline.txt':
MESS:00:00:03.422380:0: 'dwc_otg.lpm_enable=0 console=serial0,115200 kgdboc=serial0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=squashfs,ext4 rootwait'
MESS:00:00:03.436521:0: brfs: File read: 133 bytes
MESS:00:00:03.945456:0: brfs: File read: /mfs/sd/kernel.img
MESS:00:00:03.949336:0: Loading 'kernel.img' to 0x8000 size 0x8250b8
MESS:00:00:03.959787:0: Kernel trailer DTOK property says yes
MESS:00:00:03.963827:0: Kernel trailer DDTK property says yes
MESS:00:00:03.969330:0: brfs: File read: 8540344 bytes
MESS:00:00:03.980382:0: brfs: File read: /mfs/sd/bcm2708-rpi-0-w.dtb
MESS:00:00:03.985040:0: Loading 'bcm2708-rpi-0-w.dtb' to 0x82d0b8 size 0x5b13
MESS:00:00:04.080302:0: brfs: File read: 23315 bytes
MESS:00:00:04.087446:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:04.102462:0: dtparam: random=on
MESS:00:00:04.111147:0: dtparam: watchdog=on
MESS:00:00:04.119937:0: dtparam: audio=on
MESS:00:00:04.135018:0: dtparam: i2c0=on
MESS:00:00:04.147123:0: dtparam: i2c1=on
MESS:00:00:04.160750:0: dtparam: spi=on
MESS:00:00:05.165061:0: gpioman: gpioman_get_pin_num: pin EMMC_ENABLE not defined
MESS:00:00:05.205996:0: Device tree loaded to 0x1bfea100 (size 0x5ee4)
MESS:00:00:05.211722:0: uart: Set PL011 baud rate to 103448.300000 Hz
MESS:00:00:05.218534:0: uart: Baud rate change done...
MESS:00:00:05.221966:0: uart: Baud rate[ 0.000000] Booting Linux on physical CPU 0x0
with or without monitor makes no noticable difference (about 100ms faster without)
6by9
commented
5 years ago A moderate chunk of that time is querying the EDID from your monitor (timing out if it isn't connected).
As per the docs, you can override reading the EDID and provide your own one via a file.
hdmi_edid_file=1 in /boot/config.txt, and save your monitor EDID with sudo /opt/vc/bin/tvservice -d /boot/edid.dat. Obviously this locks the display type, and should stop it dropping back to composite (may requrire hdmi_force_mode=1 and/or hdmi_force_hotplug=1 as well).
Specifying your desired mode with hdmi_group and hdmi_mode rather relying on the firmware to choose the most appropriate mode may also speed things up slightly.
aep
commented
5 years ago thanks for your help. sounds like that might fix it.
can't test unfortunately since we're switching to a different HW.
the rpi zero takes a full 5 seconds to get to uboot, which is slower than booting linux including a decent sized userspace.
it looks like the majority of time is spent on detecting a monitor. disable_splash=1 has no effect.
the zero would be considerably more useful if we could half the bootup time by disabling hdmi bringup.