[RPi 2B] start_x.elf possible regression in 1.20190620: no HDMI init on boot when using bootcode.bin-only SD card boot mode

After updating my old OSMC install to current version I got non-working HDMI with my monitor. Spent several hours debugging and nailed it down to something that had changed between 1.20190517 and 1.20190620 releases.

Symptoms:

With start_x.elf/fixup_x.elf from 1.20190517: everything works fine - I got rainbow display on power on and normal console output. Tested with two kernels, 4.14.y and 4.19.y.
Then I replace start_x.elf/fixup_x.elf with files coming from 1.20190620 (or any older up to current master) release - tried them all.
On reboot or power on display does not initialize: no "rainbow", no console output, nothing.
System boots fine and is accessible both from serial console and over the network. Executing tvservice with different parameters shows this:

# tvservice -s
state 0x120002 [TV is off]

# tvservice -m DMT
Group DMT has 0 modes:

# tvservice -m CEA
Group CEA has 0 modes:

# tvservice -n
device_name=SAM-SME1920NR

# tvservice -p
Powering on HDMI with preferred settings

# tvservice -s
state 0x12000a [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive

# tvservice -m CEA
Group CEA has 0 modes:

# tvservice -m DMT
Group DMT has 0 modes:

# tvservice -d SAM-SME1920NR.edid
Written 256 bytes to SAM-SME1920NR.edid

# /opt/vc/bin/edidparser SAM-SME1920NR.edid
Enabling fuzzy format match...
Parsing SAM-SME1920NR.edid...
HDMI:EDID version 1.3, 1 extensions, screen size 38x30 cm
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
HDMI:EDID found monitor range descriptor tag 0xfd
HDMI:EDID monitor range offsets: V min=0, V max=0, H min=0, H max=0
HDMI:EDID monitor range: vertical is 56-75 Hz, horizontal is 30-81 kHz, max pixel clock is 140 MHz
HDMI:EDID monitor range does not support GTF
HDMI:EDID found monitor name descriptor tag 0xfc
HDMI:EDID monitor name is SME1920NR
HDMI:EDID found monitor S/N descriptor tag 0xff
HDMI:EDID found preferred DMT detail timing format: 1280x1024p @ 60 Hz (35)
HDMI:EDID established timing I/II bytes are BF EF 80
HDMI:EDID found DMT format: code 4, 640x480p @ 60 Hz in established timing I/II
HDMI:EDID found DMT format: code 5, 640x480p @ 72 Hz in established timing I/II
HDMI:EDID found DMT format: code 6, 640x480p @ 75 Hz in established timing I/II
HDMI:EDID found DMT format: code 8, 800x600p @ 56 Hz in established timing I/II
HDMI:EDID found DMT format: code 9, 800x600p @ 60 Hz in established timing I/II
HDMI:EDID found DMT format: code 10, 800x600p @ 72 Hz in established timing I/II
HDMI:EDID found DMT format: code 11, 800x600p @ 75 Hz in established timing I/II
HDMI:EDID found DMT format: code 16, 1024x768p @ 60 Hz in established timing I/II
HDMI:EDID found DMT format: code 17, 1024x768p @ 70 Hz in established timing I/II
HDMI:EDID found DMT format: code 18, 1024x768p @ 75 Hz in established timing I/II
HDMI:EDID found DMT format: code 36, 1280x1024p @ 75 Hz in established timing I/II
HDMI:EDID standard timings block x 8: 0x8140 714F 8100 810F 0101 0101 0101 0101
HDMI:EDID found DMT format: code 32, 1280x960p @ 60 Hz (4:3) in standard timing 0
HDMI:EDID found DMT format: code 21, 1152x864p @ 75 Hz (4:3) in standard timing 1
HDMI:EDID found DMT format: code 28, 1280x800p @ 60 Hz (16:10) in standard timing 2
HDMI:EDID found DMT format: code 29, 1280x800p @ 75 Hz (16:10) in standard timing 3
HDMI:EDID parsing v3 CEA extension 0
HDMI:EDID monitor support - underscan IT formats:no, basic audio:yes, yuv444:yes, yuv422:no, #native DTD:1
HDMI:EDID found CEA detail timing format: 720x480p @ 60 Hz (2)
HDMI:EDID found audio format 2 channels PCM, sample rate: 32|44|48 kHz, sample size: 16|20|24 bits
HDMI:EDID found HDMI VSDB length 7
HDMI:EDID HDMI VSDB has physical address 2.0.0.0
HDMI:EDID HDMI VSDB supports AI:yes, dual link DVI:no
HDMI:EDID HDMI VSDB deep colour support - 48-bit:no 36-bit:no 30-bit:no DC_yuv444:no
HDMI:EDID HDMI VSDB max TMDS clock 225 MHz
HDMI:EDID HDMI VSDB has no latency information
HDMI:EDID found CEA format: code 16, 1920x1080p @ 60Hz (native)
HDMI:EDID found CEA format: code 4, 1280x720p @ 60Hz (native)
HDMI:EDID found CEA format: code 2, 720x480p @ 60Hz
HDMI:EDID found Video Capability DB length 2
HDMI:EDID video capability: CE:3 IT:3 PT:0 QS:0
HDMI:EDID adding mandatory support for CEA (1) 640x480p @ 60Hz
HDMI:EDID adding mandatory support for CEA (3) 720x480p @ 60Hz
HDMI:EDID filtering formats with pixel clock > 162 MHz or h. blanking > 1023
HDMI:EDID best score mode initialised to DMT (4) 640x480p @ 60 Hz with pixel clock 25 MHz (score 0)
HDMI:EDID best score mode is now CEA (1) 640x480p @ 60 Hz with pixel clock 25 MHz (score 43432)
HDMI:EDID best score mode is now CEA (2) 720x480p @ 60 Hz with pixel clock 27 MHz (score 4545736)
HDMI:EDID CEA mode (3) 720x480p @ 60 Hz with pixel clock 27 MHz has a score of 45736
HDMI:EDID CEA mode (4) 1280x720p @ 60 Hz with pixel clock 74 MHz has a score of 107944
HDMI:EDID DMT mode (4) 640x480p @ 60 Hz with pixel clock 25 MHz has a score of 36864
HDMI:EDID DMT mode (5) 640x480p @ 72 Hz with pixel clock 31 MHz has a score of 44236
HDMI:EDID DMT mode (6) 640x480p @ 75 Hz with pixel clock 31 MHz has a score of 46080
HDMI:EDID DMT mode (8) 800x600p @ 56 Hz with pixel clock 36 MHz has a score of 53760
HDMI:EDID DMT mode (9) 800x600p @ 60 Hz with pixel clock 40 MHz has a score of 57600
HDMI:EDID DMT mode (10) 800x600p @ 72 Hz with pixel clock 50 MHz has a score of 69120
HDMI:EDID DMT mode (11) 800x600p @ 75 Hz with pixel clock 49 MHz has a score of 72000
HDMI:EDID CEA mode (16) 1920x1080p @ 60 Hz with pixel clock 148 MHz has a score of 211624
HDMI:EDID DMT mode (16) 1024x768p @ 60 Hz with pixel clock 65 MHz has a score of 94370
HDMI:EDID DMT mode (17) 1024x768p @ 70 Hz with pixel clock 75 MHz has a score of 110100
HDMI:EDID DMT mode (18) 1024x768p @ 75 Hz with pixel clock 78 MHz has a score of 117964
HDMI:EDID DMT mode (21) 1152x864p @ 75 Hz with pixel clock 108 MHz has a score of 174298
HDMI:EDID DMT mode (28) 1280x800p @ 60 Hz with pixel clock 83 MHz has a score of 147880
HDMI:EDID DMT mode (29) 1280x800p @ 75 Hz with pixel clock 106 MHz has a score of 178600
HDMI:EDID DMT mode (32) 1280x960p @ 60 Hz with pixel clock 108 MHz has a score of 172456
HDMI:EDID best score mode is now DMT (35) 1280x1024p @ 60 Hz with pixel clock 108 MHz (score 5235929)
HDMI:EDID DMT mode (36) 1280x1024p @ 75 Hz with pixel clock 135 MHz has a score of 196608
HDMI:EDID preferred mode remained as DMT (35) 1280x1024p @ 60 Hz with pixel clock 108 MHz
HDMI:EDID has HDMI support and audio support
/opt/vc/bin/edidparser exited with code 0

After executing tvservice -p display shows that its preffered mode had been set but remains totally blank/black.

After rolling back start_x.elf/fixup_x.elf to those from 1.20190517 everything gets back to normal - rainbow display on power on or reboot, normal console output, normal output w.r.t. DMT/CEA modes from tvservice -m XXX.

System

# vcgencmd version
Jun 20 2019 16:14:44
Copyright (c) 2012 Broadcom
version a59fb7a74180be0111dbc5c18a37ec6df86f14a3 (clean) (release) (start_x)

# uname -a
Linux lx2pi2 4.19.122-1-osmc #1 SMP PREEMPT Wed May 27 07:09:59 UTC 2020 armv7l GNU/Linux

Model of Raspberry Pi: Pi2B

Logs These messages appear in kernel log (dmesg) if/when issue is taking place:

[    0.742477] bcm2708_fb soc:fb: Unable to determine number of FB's. Assuming 1
[    0.742536] bcm2708_fb soc:fb: FB found 1 display(s)
[    0.743389] raspberrypi-firmware soc:firmware: Request 0x00048003 returned status 0x80000001
[    0.743444] bcm2708_fb soc:fb: Failed to allocate GPU framebuffer (-22)
[    0.743504] bcm2708_fb soc:fb: probe failed, err -22
[    0.743626] bcm2708_fb: probe of soc:fb failed with error -22

Can you confirm that you get no HDMI output on current releases?

What's in your config.txt?

Most likely commit in that timeframe is "Update everything needed to get the new FKMS mailbox working" @6by9

@lexa2 vcdbg log msg might be useful for the working/failing cases. And tvservice -s. It looks like 1280x1024p is perferred for failing case, useful to know if that's the case for working case. Can you post SAM-SME1920NR.edid (should be able to drag/drop to this github issue)

If you copy start4x.elf to start_x.elf, and fixup4x.dat to fixup_x.dat, does that work?

Pi0-3 and Pi4 are currently built from different branches, but the Pi4 version should run quite happily on the Pi0-3, although without hardware codec support.

@pelwell As stated in the first post - I had tried each and every release, including current master branch.

config.txt:

start_x=1
sdtv_aspect=1
disable_overscan=1
framebuffer_depth=32
framebuffer_ignore_aplha=1
max_usb_current=1
gpu_mem_256=112
gpu_mem_512=144
gpu_mem_1024=256
avoid_warnings=2
hdmi_ignore_cec_init=1

Had tried each and every available sdtv and hdmi related config commands with various values (hdmi_group, hdmi_mode, hdmi_drive, enable_tvout, hdmi_safe, hdmi_force_hotplug, config_hdmi_boost, hdmi_blanking to name a few), no success. What hadn't tried: disabling EDID parsing or providing some other EDID in a separate file.

@popcornmix Dot-edid is "an unsupported file format" for github :-). So I put it into zip, hope you will be able to handle it. If not - ping me and I will pack it into tar.gz or whatever that will suite you. SAM-SME1920NR.zip

Will try execute vcdbg log msg and post back results for failing and working cases here. As for prefered mode - output device is an older 1280x1024 5:4 TFT thus 1280x1024p is expected to be preffered. What is odd for this device is that it also supports 720p and 1080p in CEA despite panel being too low in res to display all details in 1080p. Nevertheless it is still a useful feature for cases when you need to test some 1080p only equipment.

@6by9 Thanks for hint, will give it a try now. But even in case this workaround would work it won't be a viable solution for me as I need hw decoding working for H.264 here as primary board use is OSMC - Kodi-based mediacenter.

Okay, have an important update: there are two different issues going on here.

First one was introduced between 1.20190517 and 1.20190620 and seems to be related to GPU failing to fetch EDID from HDMI device. Providing edid.dat (contents are that of SAM-SME1920NR.edid I had dumped earlier) and enabling hdmi_edid_file=1 in config.txt fully workarounds the issue.

Second one was introduced somewhere in master branch but this change hadn't landed to stable yet. For now it means that only 1.20200527 and 1.20200601+arm64 are affected, while 1.20200601 and all other based on stable branch are not. Second issue is that I get no display output even with edid.dat override in place.

Will post more debug info/logs/findings soon.

First of all, here is vcdbg log msg output for working case (1.20190517, no edid.dat workaround as it is not needed):

004397.400: brfs: File read: /mfs/sd/config.txt
004397.960: brfs: File read: 373 bytes
004834.578: HDMI:EDID version 1.3, 1 extensions, screen size 38x30 cm
004834.690: 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
004834.823: HDMI:EDID found preferred DMT detail timing format: 1280x1024p @ 60 Hz (35)
004834.911: HDMI:EDID found DMT format: code 4, 640x480p @ 60 Hz in established timing I/II
004834.987: HDMI:EDID found DMT format: code 5, 640x480p @ 72 Hz in established timing I/II
004835.072: HDMI:EDID found DMT format: code 6, 640x480p @ 75 Hz in established timing I/II
004835.152: HDMI:EDID found DMT format: code 8, 800x600p @ 56 Hz in established timing I/II
004835.237: HDMI:EDID found DMT format: code 9, 800x600p @ 60 Hz in established timing I/II
004835.313: HDMI:EDID found DMT format: code 10, 800x600p @ 72 Hz in established timing I/II
004835.399: HDMI:EDID found DMT format: code 11, 800x600p @ 75 Hz in established timing I/II
004835.486: HDMI:EDID found DMT format: code 16, 1024x768p @ 60 Hz in established timing I/II
004835.572: HDMI:EDID found DMT format: code 17, 1024x768p @ 70 Hz in established timing I/II
004835.661: HDMI:EDID found DMT format: code 18, 1024x768p @ 75 Hz in established timing I/II
004835.750: HDMI:EDID found DMT format: code 36, 1280x1024p @ 75 Hz in established timing I/II
004835.878: HDMI:EDID standard timings block x 8: 0x8140 714F 8100 810F 0101 0101 0101 0101
004835.969: HDMI:EDID found DMT format: code 32, 1280x960p @ 60 Hz (4:3) in standard timing 0
004836.057: HDMI:EDID found DMT format: code 21, 1152x864p @ 75 Hz (4:3) in standard timing 1
004836.155: HDMI:EDID found DMT format: code 28, 1280x800p @ 60 Hz (16:10) in standard timing 2
004836.249: HDMI:EDID found DMT format: code 29, 1280x800p @ 75 Hz (16:10) in standard timing 3
004849.309: HDMI:EDID parsing v3 CEA extension 0
004849.383: HDMI:EDID monitor support - underscan IT formats:no, basic audio:yes, yuv444:yes, yuv422:no, #native DTD:1
004849.465: HDMI:EDID found CEA detail timing format: 720x480p @ 60 Hz (2)
004849.562: HDMI:EDID found audio format 2 channels PCM, sample rate: 32|44|48 kHz, sample size: 16|20|24 bits
004849.620: HDMI:EDID found HDMI VSDB length 7
004849.684: HDMI:EDID HDMI VSDB has physical address 2.0.0.0
004849.741: HDMI:EDID HDMI VSDB supports AI:yes, dual link DVI:no
004849.808: HDMI:EDID HDMI VSDB deep colour support - 48-bit:no 36-bit:no 30-bit:no DC_yuv444:no
004849.875: HDMI:EDID HDMI VSDB max TMDS clock 225 MHz
004849.934: HDMI:EDID HDMI VSDB has no latency information
004850.016: HDMI:EDID found CEA format: code 16, 1920x1080p @ 60Hz (native)
004850.095: HDMI:EDID found CEA format: code 4, 1280x720p @ 60Hz (native)
004850.165: HDMI:EDID found CEA format: code 2, 720x480p @ 60Hz
004850.227: HDMI:EDID found Video Capability DB length 2
004850.296: HDMI:EDID video capability: CE:3 IT:3 PT:0 QS:0
004850.377: HDMI:EDID filtering formats with pixel clock > 162 MHz or h. blanking > 1023
004850.570: HDMI:EDID preferred mode remained as DMT (35) 1280x1024p @ 60 Hz with pixel clock 108 MHz
005614.311: brfs: File read: /mfs/sd/config.txt
005614.756: HDMI:Setting property pixel encoding to Default
005614.812: HDMI:Setting property pixel clock type to PAL
005614.872: HDMI:Setting property content type flag to No data
005614.929: HDMI:Setting property fuzzy format match to enabled
005615.065: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
005624.925: gpioman: gpioman_get_pin_num: pin WL_LPO_CLK not defined
005624.992: gpioman: gpioman_get_pin_num: pin BT_ON not defined
005625.052: gpioman: gpioman_get_pin_num: pin WL_ON not defined
005649.662: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined
005650.947: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
005651.030: hdmi: HDMI:>>>>>>>>>>>>>Rx sensed, reading EDID<<<<<<<<<<<<<
005663.137: hdmi: HDMI:EDID version 1.3, 1 extensions, screen size 38x30 cm
005663.252: 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
005663.391: hdmi: HDMI:EDID found preferred DMT detail timing format: 1280x1024p @ 60 Hz (35)
005663.484: hdmi: HDMI:EDID found DMT format: code 4, 640x480p @ 60 Hz in established timing I/II
005663.563: hdmi: HDMI:EDID found DMT format: code 5, 640x480p @ 72 Hz in established timing I/II
005663.652: hdmi: HDMI:EDID found DMT format: code 6, 640x480p @ 75 Hz in established timing I/II
005663.736: hdmi: HDMI:EDID found DMT format: code 8, 800x600p @ 56 Hz in established timing I/II
005663.825: hdmi: HDMI:EDID found DMT format: code 9, 800x600p @ 60 Hz in established timing I/II
005663.904: hdmi: HDMI:EDID found DMT format: code 10, 800x600p @ 72 Hz in established timing I/II
005663.994: hdmi: HDMI:EDID found DMT format: code 11, 800x600p @ 75 Hz in established timing I/II
005664.085: hdmi: HDMI:EDID found DMT format: code 16, 1024x768p @ 60 Hz in established timing I/II
005664.175: hdmi: HDMI:EDID found DMT format: code 17, 1024x768p @ 70 Hz in established timing I/II
005664.255: hdmi: HDMI:EDID found DMT format: code 18, 1024x768p @ 75 Hz in established timing I/II
005664.349: hdmi: HDMI:EDID found DMT format: code 36, 1280x1024p @ 75 Hz in established timing I/II
005664.481: hdmi: HDMI:EDID standard timings block x 8: 0x8140 714F 8100 810F 0101 0101 0101 0101
005664.579: hdmi: HDMI:EDID found DMT format: code 32, 1280x960p @ 60 Hz (4:3) in standard timing 0
005664.670: hdmi: HDMI:EDID found DMT format: code 21, 1152x864p @ 75 Hz (4:3) in standard timing 1
005664.773: hdmi: HDMI:EDID found DMT format: code 28, 1280x800p @ 60 Hz (16:10) in standard timing 2
005664.870: hdmi: HDMI:EDID found DMT format: code 29, 1280x800p @ 75 Hz (16:10) in standard timing 3
005677.934: hdmi: HDMI:EDID parsing v3 CEA extension 0
005678.012: hdmi: HDMI:EDID monitor support - underscan IT formats:no, basic audio:yes, yuv444:yes, yuv422:no, #native DTD:1
005678.101: hdmi: HDMI:EDID found CEA detail timing format: 720x480p @ 60 Hz (2)
005678.203: hdmi: HDMI:EDID found audio format 2 channels PCM, sample rate: 32|44|48 kHz, sample size: 16|20|24 bits
005678.268: hdmi: HDMI:EDID found HDMI VSDB length 7
005678.335: hdmi: HDMI:EDID HDMI VSDB has physical address 2.0.0.0
005678.399: hdmi: HDMI:EDID HDMI VSDB supports AI:yes, dual link DVI:no
005678.470: hdmi: HDMI:EDID HDMI VSDB deep colour support - 48-bit:no 36-bit:no 30-bit:no DC_yuv444:no
005678.541: hdmi: HDMI:EDID HDMI VSDB max TMDS clock 225 MHz
005678.603: hdmi: HDMI:EDID HDMI VSDB has no latency information
005678.690: hdmi: HDMI:EDID found CEA format: code 16, 1920x1080p @ 60Hz (native)
005678.773: hdmi: HDMI:EDID found CEA format: code 4, 1280x720p @ 60Hz (native)
005678.849: hdmi: HDMI:EDID found CEA format: code 2, 720x480p @ 60Hz
005678.915: hdmi: HDMI:EDID found Video Capability DB length 2
005678.989: hdmi: HDMI:EDID video capability: CE:3 IT:3 PT:0 QS:0
005679.073: hdmi: HDMI:EDID filtering formats with pixel clock > 162 MHz or h. blanking > 1023
005679.273: hdmi: HDMI:EDID preferred mode remained as DMT (35) 1280x1024p @ 60 Hz with pixel clock 108 MHz
005679.336: hdmi: HDMI: hotplug attached with HDMI support
005679.414: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
005681.863: hdmi: HDMI: power_on to DMT mode SXGA@60
005685.082: hdmi: HDMI: Action callback added to queue to happen at frame 2
005685.144: hdmi: HDMI: Action stop_3d_mode added to queue to happen at frame 2
005685.212: hdmi: HDMI: Action unmute added to queue to happen at frame 3
005751.876: *** Restart logging
005751.942: brfs: File read: 373 bytes
006503.671: brfs: File read: /mfs/sd/cmdline.txt
006503.753: Read command line from file 'cmdline.txt':
006503.808: 'root=UUID=69c114cd-8a17-4cee-bc25-92fdc8332a00 rootfstype=ext4 rootwait osmcdev=rbp2 elevator=deadline'
006504.109: brfs: File read: 103 bytes
011936.291: brfs: File read: /mfs/sd/kernel7.img
011936.351: Loading 'kernel7.img' to 0x8000 size 0x868768
011940.746: No kernel trailer - assuming DT-capable
011940.837: brfs: File read: 8816488 bytes
012317.840: brfs: File read: /mfs/sd/bcm2709-rpi-2-b.dtb
012317.904: Loading 'bcm2709-rpi-2-b.dtb' to 0x870768 size 0x62f2
012477.252: brfs: File read: 25330 bytes
012787.910: brfs: File read: /mfs/sd/config.txt
014026.436: gpioman: gpioman_get_pin_num: pin EMMC_ENABLE not defined
014116.219: Device tree loaded to 0x2efe9900 (size 0x66bd)
016865.322: vchiq_core: vchiq_init_state: slot_zero = 0xee580000, is_master = 1
016869.664: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
016875.083: TV service:host side not connected, dropping notification 0x00000002, 0x00000002, 0x00000023
028386.086: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
028686.870: camsubs: Camera not found
028686.956: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
028987.728: camsubs: Camera not found
028987.807: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
028988.577: camsubs: Camera not found
028988.653: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
028989.412: camsubs: Camera not found
028989.490: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
028990.259: camsubs: Camera not found

From here on I switch to 1.20190620 (edid.dat still off) and get non-working HDMI output.

In dmesg there these lines related to framebuffer:

[    0.742513] bcm2708_fb soc:fb: FB found 1 display(s)
[    0.750303] Console: switching to colour frame buffer device 90x30
[    0.754389] bcm2708_fb soc:fb: Registered framebuffer for display 0, size 720x480

Here is output from tvservice right after the bootup:

# tvservice -s
state 0x40002 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced

# tvservice -m DMT
Group DMT has 0 modes:

# tvservice -m CEA
Group CEA has 0 modes:

# tvservice -n
device_name=SAM-SME1920NR

# tvservice -p
Powering on HDMI with preferred settings

# tvservice -s
state 0x12000a [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive

# tvservice -m CEA
Group CEA has 0 modes:

# tvservice -m DMT
Group DMT has 0 modes:

Then I try to start up Kodi but still get blank screen. Following lines appear in dmesg:

[  198.466832] Console: switching to colour dummy device 80x30
[  198.482074] raspberrypi-firmware soc:firmware: Request 0x00048003 returned status 0x80000001
[  198.482092] bcm2708_fb soc:fb: Failed to allocate GPU framebuffer (-22)
[  198.482101] detected fb_set_par error, error code: -22

Then I run vcdbg log msg and get following output (it is for non-working case):

004349.423: brfs: File read: /mfs/sd/config.txt
004350.014: brfs: File read: 373 bytes
005566.714: brfs: File read: /mfs/sd/config.txt
005567.279: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
005578.653: gpioman: gpioman_get_pin_num: pin WL_LPO_CLK not defined
005578.724: gpioman: gpioman_get_pin_num: pin BT_ON not defined
005578.787: gpioman: gpioman_get_pin_num: pin WL_ON not defined
005603.564: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined
005604.848: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
005604.938: *** Restart logging
005605.000: brfs: File read: 373 bytes
006033.038: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
006033.108: HDMI0: hdmi_pixel_encoding: 162000000

006033.354: vec: vec_middleware_power_on: vec_base: 0x7e806000 rev-id 0x00002708 @ vec: 0x7e806100 @ 0x00000420 enc: 0x7e806060 @ 0x00000220 cgmsae: 0x7e80605c @ 0x00000000
006370.937: brfs: File read: /mfs/sd/cmdline.txt
006371.019: Read command line from file 'cmdline.txt':
006371.074: 'root=UUID=69c114cd-8a17-4cee-bc25-92fdc8332a00 rootfstype=ext4 rootwait osmcdev=rbp2 elevator=deadline'
006371.375: brfs: File read: 103 bytes
011804.057: brfs: File read: /mfs/sd/kernel7.img
011804.117: Loading 'kernel7.img' to 0x8000 size 0x868768
011808.511: No kernel trailer - assuming DT-capable
011808.600: brfs: File read: 8816488 bytes
012185.732: brfs: File read: /mfs/sd/bcm2709-rpi-2-b.dtb
012185.794: Loading 'bcm2709-rpi-2-b.dtb' to 0x870768 size 0x62f2
012356.767: brfs: File read: 25330 bytes
012667.178: brfs: File read: /mfs/sd/config.txt
015046.587: gpioman: gpioman_get_pin_num: pin EMMC_ENABLE not defined
015136.969: Device tree loaded to 0x2efe9900 (size 0x66b9)
018339.170: vchiq_core: vchiq_init_state: slot_zero = 0xee580000, is_master = 1
029730.710: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
030031.477: camsubs: Camera not found
030031.553: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
030332.328: camsubs: Camera not found
030332.406: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
030333.163: camsubs: Camera not found
030333.234: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
030334.008: camsubs: Camera not found
030334.083: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
030334.836: camsubs: Camera not found
128152.677: TV service:host side not connected, dropping notification 0x00000008, 0x00000002, 0x00000023

And then a one-time-event happened: I killed Kodi process and all out of a sudden linux 90x30 text console appeared on the screen. I tired starting Kodi up again and this time it came up normally with everything displayed as it should. Killed Kodi again and linux text console appeared. Did it several times with consistent results.

In dmesg the following lines appeared:

...
[  270.464812] Console: switching to colour frame buffer device 90x30
[  370.405030] Console: switching to colour dummy device 80x30
[  514.217609] Console: switching to colour frame buffer device 90x30
...

Then I tried rebooting and got back to the black screen with no output. I wasn't able to reproduce this "magical self-fix" behaviour in any later attempt.

There's another interesting observation. Each time I swap bootcode.bin/start_x.elf/fixup_x.dat to some other version I also swap (actually, change symlink) /opt/vc to resp. version as well. What I noticed is that the output from tvservice differs significantly for binary from 1.20190517 vs 1.20190620-1. Thus I had quickly mocked up a script that allows to execute tvservice binary with LD_LIBRARY_PATH pointing to resp. lib folder and got the following:

# for d in firm* ; do ( cd $d/hardfp/opt/vc/bin/ ; echo -n "${d%%*/} "; lx2tvservice -n ; ) ; done
firmware-1.20181112 device_name=SAM-SME1920NR
firmware-1.20190215 device_name=SAM-SME1920NR
firmware-1.20190401 device_name=SAM-SME1920NR
firmware-1.20190517 device_name=SAM-SME1920NR
firmware-1.20190620 device_name=Unk-Composite dis
firmware-1.20190620-1 device_name=Unk-Composite dis
firmware-1.20190709 device_name=Unk-Composite dis
firmware-1.20190718 device_name=Unk-Composite dis
firmware-1.20190925 device_name=Unk-Composite dis
firmware-1.20200212 device_name=Unk-Composite dis
firmware-1.20200512 device_name=Unk-Composite dis
firmware-1.20200527 device_name=Unk-Composite dis
firmware-1.20200601 device_name=Unk-Composite dis
firmware-1.20200601-arm64 device_name=Unk-Composite dis

# for d in firm* ; do ( cd $d/hardfp/opt/vc/bin/ ; echo -n "${d%%*/} "; lx2tvservice -s ; ) ; done
firmware-1.20181112 state 0x40002 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced
firmware-1.20190215 state 0x40002 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced
firmware-1.20190401 state 0x40002 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced
firmware-1.20190517 state 0x40002 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced
firmware-1.20190620 state 0x40000 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced
firmware-1.20190620-1 state 0x40000 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced
firmware-1.20190709 state 0x40000 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced
firmware-1.20190718 state 0x40000 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced
firmware-1.20190925 state 0x40000 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced
firmware-1.20200212 state 0x40000 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced
firmware-1.20200512 state 0x40000 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced
firmware-1.20200527 state 0x40000 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced
firmware-1.20200601 state 0x40000 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced
firmware-1.20200601-arm64 state 0x40000 [NTSC 4:3], 720x480 @ 60.00Hz, interlaced

# ( cd firmware-1.20190517/hardfp/opt/vc/bin/ ; lx2tvservice -o ; )

# for d in firm* ; do ( cd $d/hardfp/opt/vc/bin/ ; echo -n "${d%%*/} "; lx2tvservice -s ; ) ; done
firmware-1.20181112 state 0x120002 [TV is off]
firmware-1.20190215 state 0x120002 [TV is off]
firmware-1.20190401 state 0x120002 [TV is off]
firmware-1.20190517 state 0x120002 [TV is off]
firmware-1.20190620 state 0x120000 [TV is off]
firmware-1.20190620-1 state 0x120000 [TV is off]
firmware-1.20190709 state 0x120000 [TV is off]
firmware-1.20190718 state 0x120000 [TV is off]
firmware-1.20190925 state 0x120000 [TV is off]
firmware-1.20200212 state 0x120000 [TV is off]
firmware-1.20200512 state 0x120000 [TV is off]
firmware-1.20200527 state 0x120000 [TV is off]
firmware-1.20200601 state 0x120000 [TV is off]
firmware-1.20200601-arm64 state 0x120000 [TV is off]

# ( cd firmware-1.20190517/hardfp/opt/vc/bin/ ; lx2tvservice -p ; )

# for d in firm* ; do ( cd $d/hardfp/opt/vc/bin/ ; echo -n "${d%%*/} "; lx2tvservice -s ; ) ; done
firmware-1.20181112 state 0x12000a [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20190215 state 0x12000a [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20190401 state 0x12000a [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20190517 state 0x12000a [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20190620 state 0x120000 [TV is off]
firmware-1.20190620-1 state 0x120000 [TV is off]
firmware-1.20190709 state 0x120000 [TV is off]
firmware-1.20190718 state 0x120000 [TV is off]
firmware-1.20190925 state 0x120000 [TV is off]
firmware-1.20200212 state 0x120000 [TV is off]
firmware-1.20200512 state 0x120000 [TV is off]
firmware-1.20200527 state 0x120000 [TV is off]
firmware-1.20200601 state 0x120000 [TV is off]
firmware-1.20200601-arm64 state 0x120000 [TV is off]

There's a clear division in behaviour into two groups: 1.20190517 and earlier vs 1.20190620 and later. Group one is (a) able to read HDMI device name and (b) properly reports DMT/35 mode when it is activated by the tvservice -p. Group two displays "Unk-Composite dis" as a display device name and reports that "TV is off" despite monitor reporting running in native resolution (but still being blank). Also there are differences in reported state values between two groups.

With edid.dat workaround in place and 1.20200601 in use behaviour changes a bit:

# for d in firm* ; do ( cd $d/hardfp/opt/vc/bin/ ; echo -n "${d%%*/} "; lx2tvservice -n ; ) ; done
firmware-1.20181112 device_name=SAM-SME1920NR
firmware-1.20190215 device_name=SAM-SME1920NR
firmware-1.20190401 device_name=SAM-SME1920NR
firmware-1.20190517 device_name=SAM-SME1920NR
firmware-1.20190620 device_name=SAM-SME1920NR
firmware-1.20190620-1 device_name=SAM-SME1920NR
firmware-1.20190709 device_name=SAM-SME1920NR
firmware-1.20190718 device_name=SAM-SME1920NR
firmware-1.20190925 device_name=SAM-SME1920NR
firmware-1.20200212 device_name=SAM-SME1920NR
firmware-1.20200512 device_name=SAM-SME1920NR
firmware-1.20200527 device_name=SAM-SME1920NR
firmware-1.20200601 device_name=SAM-SME1920NR
firmware-1.20200601-arm64 device_name=SAM-SME1920NR

# for d in firm* ; do ( cd $d/hardfp/opt/vc/bin/ ; echo -n "${d%%*/} "; lx2tvservice -s ; ) ; done
firmware-1.20181112 state 0x12000a [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20190215 state 0x12000a [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20190401 state 0x12000a [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20190517 state 0x12000a [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20190620 state 0xa [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20190620-1 state 0xa [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20190709 state 0xa [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20190718 state 0xa [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20190925 state 0xa [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20200212 state 0xa [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20200512 state 0xa [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20200527 state 0xa [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20200601 state 0xa [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive
firmware-1.20200601-arm64 state 0xa [HDMI DMT (35) RGB full 5:4], 1280x1024 @ 60.00Hz, progressive

Here we see that both groups are able to read HDMI device name (I think it means - are able to extract it from provided edid.dat) and both groups are properly showing DMT/35 mode as being active. State codes still remain a bit different between groups.

@6by9 Forgot to mention: tried renaming "4x" to "_x" and using them instead. Board was able to boot but HDMI remained borked. In general behaviour for "4x" was the same as with resp. version of "_x". I hadn't tested if hw codecs work with "4x" though.

Sorry, more information requests.

Please provide the output of cat /proc/cpuinfo | grep Revision - the Pi2 has a couple of revisions, including one that switches between BCM2836 and BCM2837.

vcgencmd get_mem gpu.

vcgencmd version and uname -a for what you have tried. We try our best to maintain backwards compatibility, but sometimes fail for odd combinations of kernel and firmware.

Minor note from your initial post, tvservice -p turns on the monitor, but does not reinitialise fbdev and the frame buffer, therefore your TV is likely to be on but totally black. You need to call fbset with some changed parameter to retrigger that, eg fbset -depth 16 (assuming depth isn't already 16, in which case use 32). This is probably why your killing Kodi brought the screen back to life as it tickled fbdev.

I was also slightly wrong with my comment of hardware codecs not working with start4x.elf - it's MPEG2 and MPEG4 codecs that don't work. H264 should be fine as it is supported on Pi4.

@6by9 uname -a and vcgencmd version are available in the first post. Re uname - in addition to 4.19.122-1-osmc I had also tried the same with kernel 4.14.78-4-osmc. Nevertheless let's focus on bootloaders for now as missing "rainbow" on boot means that this is not a kernel issue. As for console init - at failed state all calls to fbset, including fbset -depth 16 or fbset -depth 32 result in either error message both on console and in dmesg or fbset hanging waiting on an ioctl syscall. I don't have time to retry it and send output here right now for fbset, may do at a later time. Yet again - let's fix pre-kernel boot first so "rainbow" screen appears without edid.dat workaround and afterwards we may continue with kernel/userspace things.

Other requested stuff:

# cat /proc/cpuinfo | grep Revision
Revision        : a01041

# vcgencmd get_mem gpu
gpu=256M

I had the same revision of Pi2 to hand.

Linux raspberrypi 4.19.118-v7+ #1311 SMP Mon Apr 27 14:21:24 BST 2020 armv7l

The programs included with the Debian GNU/Linux system are free software;
the exact distribution terms for each program are described in the
individual files in /usr/share/doc/*/copyright.

Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
Last login: Tue Jun 16 12:24:21 2020
pi@raspberrypi:~ $ vcgencmd version
Apr 15 2020 11:43:52 
Copyright (c) 2012 Broadcom
version 82f9bb929ce2186eb1824178c1ae82902ad6275c (clean) (release) (start_db)
pi@raspberrypi:~ $ cat /proc/cpuinfo | grep Revision
Revision    : a01041
pi@raspberrypi:~ $ tvservice -s
state 0xa [HDMI DMT (68) RGB full 16:10], 1920x1200 @ 60.00Hz, progressive
pi@raspberrypi:~ $ apt-cache policy raspberrypi-bootloader
raspberrypi-bootloader:
  Installed: 1.20200601-1
  Candidate: 1.20200601-1
  Version table:
 *** 1.20200601-1 500
        500 http://archive.raspberrypi.org/debian buster/main armhf Packages
        100 /var/lib/dpkg/status
pi@raspberrypi:~ $ apt-cache policy raspberrypi-kernel
raspberrypi-kernel:
  Installed: 1.20200601-1
  Candidate: 1.20200601-1
  Version table:
 *** 1.20200601-1 500
        500 http://archive.raspberrypi.org/debian buster/main armhf Packages
        100 /var/lib/dpkg/status

Using an HDMI capture board that I can load your EDID into, it detects the EDID fine and chooses 1280x1024@60Hz (DMT mode 35).

rpi-updated (5.4.45-v7+ #1321 and e46bba1638cc.. Jun 10 2020 17:52:58), and still working fine in reading the EDID and choosing 1280x1024@60Hz.

Full contents of /boot/config.txt please. Does it work on a recent Raspbian release?

@6by9 Full contents were posted earlier here: https://github.com/raspberrypi/firmware/issues/1413#issuecomment-644281700

I will try to download latest Raspbian (or is it called "Raspberry Pi OS" now?) later today and test with it. Still I don't think it is a kernel or userland issue as the difference between get "rainbow" on boot vs. "blank screen" boils down only to what versions of start_x.elf/fixup_x.dat are in use.

What else to consider: my board's OTP is flashed to boot from USB mass storage. And boot device is USB flash stick. It might be non relevant but still worth mentioning.

Re your EDID tests - from what I see EDID itself seems to be fine/legit. Problem looks to be more like some issue preventing board from fetching EDID from HDMI device when booting up. Thus the fact that you're not having any issues with this EDID is an expected outcome as far as I can tell.

I've tested with:

the latest firmware from apt and rpi-update
on the same Pi hardware as you
with what from the outside would appear to be the same monitor, so it's fetching the EDID in exactly the same manner as your setup.

I'm trying to reproduce your setup and results, but failing. There have been no other reports that I know of that Pi2 is misbehaving, and there would have been if you are correct that this failure started with the firmware from a year ago.

Until we can narrow down why your system is behaving differently there will be a lot of questions along these lines.

OSMC is not our supported OS - that would be Raspberry Pi OS (as you were right to correct me over). config.txt under RPiOS would normally contain a load of comments, hence why I didn't interpret what appeared to be a snippet as the complete thing.

What else to consider: my board's OTP is flashed to boot from USB mass storage. And boot device is USB flash stick. It might be non relevant but still worth mentioning.

You didn't think it worth mentioning that earlier? Does it work off SD card?

It works on my setup with the same firmware that you say fails. That only leaves config.txt, and the bootrom/OTP.

@6by9 I undestand the approach you take and it seems to be the usual and reasonable thing - try to reproduce then fix if reproduced. Also I totally get that my issue probably is a really rare one - people would have reported it many times otherwise in the available timeframe. Thus thanks a lot for trying to take a look at this one, your work is really appreciated. I'm open to any questions and willing to provide you with all info you need and/or test anything if I've got required hardware or capabilities.

Back to the EDID topic I have a hunch that for this case devil might be hiding at PHY/signals level or something like that. Why am I leaning to this theory? Reasoning being that output device is an old abomination I got from China like 6 or 8 years ago which claims to be Samsung SyncMaster E1920NRC with VGA DSUB and HDMI inputs. I hadn't been able to find any references to exactly this model on Samsung site and had only seen some mentions of it on Chinese internet. By the looks of it device seems to be really close to E1920NW but it lacks DVI-D connector and have HDMI instead. This being said I have to state that I hadn't had any problems ever with this monitor connected to any other device. And there were really a lot of other source devices in its history as I use it as a small wall-mounted monitor next to my workbench to test various equipment I'm servicing. Friends tend to bring their PCs, DVDs, set-top-boxes, e.t.c. to me when there are some technical issues with them. Rest of the time I've got RPi-based mediacenter connected to it so I'm able to watch series or something while doing some brain-less stuff on the PC. First time I had encountered any problem with it is now described in this very github issue.

There's another thing I can try here on my end to debug the issue. It so happened that I've got several SoCs laying around including RPi 1B+, another RPi 2B with virgin OTP (i.e. it hadn't been ever flashed to do UMS boot), RPi 3B, Orange Pi PC and several Bannana Pi R2 boards. I think testing behaviour with OPi PC or BPiR2 will be of a little use for us but trying with other RPi boards looks like a really good idea. I'm in process of downloading latest version of RPiOS ATM so hopefully would be able to report new findings back soon.

You didn't think it worth mentioning that earlier? Does it work off SD card?

Sorry, my bad and in two ways. First of all, I hadn't initially treated this one as a relevant for the issue with a reasoning being "code is code from the GPU PoV no matter what was the initial source from whit it got loaded into memory". Secondly, initial setup was done quite a long time ago my memory was messing thing up a bit here.

Re-checked hardware and found out that: 1) OTP bit programming was done on my RPi-3B board instead of RPi-2B one that is affected by the issue. 2) RPi-2B boards I have are rev 1.1 . Thus no UMS boot OTP for them. 3) On the board that is having issues bootcode.bin-only boot mode is used. I will do a recheck now with SD-card only as this one is an obvious suspect.

Marking this one is resolved with resolution set to "human error" :-(. Booting from SD card works with no issues initializing HDMI for my output device.

It looks like there's some other issue going on with bootcode.bin preventing me from booting from my USB stick starting from fw release 1.20180313. Older bootcode.bin from 1.20171029 is able to boot the board from this particular USB stick. I guess HDMI issue I was having happens due to mismatch between this old bootcode.bin and other updated fw binaries.

Looking at recent docs it looks like it is possible to get debug output from bootcode.bin on UART so I'm about to close this issue, spend some time gathering debug output from latest available bootcode.bin (from master branch) and in case this one won't be proven to be some other mistake on my side too I will open up another issue about regression in bootcode.bin UMS boot support.

I think a was too fast closing the issue. HDMI is expected to work in bootcode.bin-only SD card boot mode too, isn't it?

I had resolved my "unable to boot when using bootcode.bin from fw 1.20180313 and higher" issue. Problem turned out to be missing start.elf (which seems to be used as a "bootable marker") in the first partition of the USB stick. Looking at UART debug output and comparing it to successful bootcode.bin-only SD card boot output posted by other people was a key hint.

Getting back to HDMI behavior it is essentially in line with all the information I had posted above in this issue with the "footnote" being that it only applies to bootcode.bin-only SD card boot mode.

I had tried updating bootcode.bin on SD card to the latest available from master branch (and patched it with sed to BOOT_UART=1) but it changed nothing compared to what had been happening with old bootcode.bin from 1.20171029.

Key points:

1) All fw releases coming from 'stable' branch starting from 1.20190620 are not initializing my HDMI device on boot unless I provide edid.dat for it and put hdmi_edid_file=1 to config.txt.

2) FW releases based on current master branch (namely: 1.20200527, 1.20200601+arm64 and master branch itself) do not initialize HDMI device even if I provide EDID override in edid.dat/config.txt.

Here is UART debug bootlog for "works with edid.dat case", fw 1.20200512:

Raspberry Pi Bootcode

Found SD card, config.txt = 0, start.elf = 0, recovery.elf = 0, timeout = 1
Trying USB
Set address 4
Num devices = 1, addr = 4
get_config_descriptor 41 bytes
device class = 9
Hub device found at addr 4, enumerating HUB
Initialise hub
Found 5 ports, multi_tt = 1
Setting interface 0
Enabling PORT POWER on port 1
Enabling PORT POWER on port 2
Enabling PORT POWER on port 3
Enabling PORT POWER on port 4
Enabling PORT POWER on port 5
Waiting for devices to respond to reset
Found device on port 1
Found highspeed device
Set address 5
Num devices = 2, addr = 5
get_config_descriptor 39 bytes
device class = 255
Device found: type = Ethernet adapter, addr = 5
Found device on port 5
Ignoring low speed device
Found device on port 2
Found highspeed device
Set address 6
Num devices = 3, addr = 6
get_config_descriptor 32 bytes
device class = 0
interface_desc[1] = 4
Device found: type = Mass storage, addr = 6
Trying booting from MSD device addr 6
Retrieving the config descriptor
Found ep_in = 00000001, ep_out = 00000002
GetMaxLun returned 0, max_lun = 0
Sending and retrying TEST_UNIT_READY
Sending SCSI_COMMAND_INQUIRY
Sending READ_CAPACITY
init_msd returned 0
USB device configuration set
Initialised mass storage, block size = 512, block count = 30031872
MBR read and decoded successfully
FAT32 partition decoded successfully
start.elf found in first partition on USB MSD, booting
Read File: config.txt, 395 (bytes)

Raspberry Pi Bootcode
Read File: config.txt, 395
Read File: start_x.elf, 3799144 (bytes)
Read File: fixup_x.dat, 9818 (bytes)
MESS:00:00:06.206390:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:06.210788:0: brfs: File read: 395 bytes
MESS:00:00:07.045363:0: brfs: File read: /mfs/sd/edid.dat
MESS:00:00:07.065682:0: brfs: File read: 256 bytes
MESS:00:00:07.754964:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:07.759377:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
MESS:00:00:07.776063:0: gpioman: gpioman_get_pin_num: pin WL_LPO_CLK not defined
MESS:00:00:07.781763:0: gpioman: gpioman_get_pin_num: pin BT_ON not defined
MESS:00:00:07.788443:0: gpioman: gpioman_get_pin_num: pin WL_ON not defined
MESS:00:00:07.819881:0: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined
MESS:00:00:07.827309:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
MESS:00:00:07.833331:0: *** Restart logging
MESS:00:00:07.837218:0: brfs: File read: 395 bytes
MESS:00:00:08.260759:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
MESS:00:00:08.650830:0: brfs: File read: /mfs/sd/bcm2709-rpi-2-b.dtb
MESS:00:00:08.655492:0: Loading 'bcm2709-rpi-2-b.dtb' to 0x100 size 0x62f2
MESS:00:00:08.895287:0: brfs: File read: 25330 bytes
MESS:00:00:09.209036:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:09.214487:0: brfs: File read: 395 bytes
MESS:00:00:09.528194:0: brfs: File read: /mfs/sd/cmdline.txt
MESS:00:00:09.532174:0: Read command line from file 'cmdline.txt':
MESS:00:00:09.538051:0: 'root=UUID=69c114cd-8a17-4cee-bc25-92fdc8332a00 rootfstype=ext4 rootwait osmcdev=rbp2 elevator=deadline'
MESS:00:00:11.989407:0: gpioman: gpioman_get_pin_num: pin EMMC_ENABLE not defined
MESS:00:00:12.131676:0: gpioman: gpioman_get_pin_num: pin WL_ON not defined
MESS:00:00:12.152007:0: brfs: File read: 103 bytes
MESS:00:00:17.146236:0: brfs: File read: /mfs/sd/kernel7.img
MESS:00:00:17.150195:0: Loading 'kernel7.img' to 0x8000 size 0x868768
MESS:00:00:17.156368:0: Device tree loaded to 0x2eff9900 (size 0x66a5)
MESS:00:00:17.163456:0: uart: Set PL011 baud rate to 103448.300000 Hz
MESS:00:00:17.170313:0: uart: Baud rate change done...
MESS:00:00:17.173745:0: uart: Baud rate change done...
MESS:00:00:19.928962:0: vchiq_core: vchiq_init_state: slot_zero = 0xef980000, is_master = 1
MESS:00:00:19.939902:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
MESS:00:00:19.952560:0: TV service:host side not connected, dropping notification 0x00000002, 0x00000002, 0x00000023
MESS:00:00:31.410424:0: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
MESS:00:00:31.719098:0: camsubs: Camera not found
MESS:00:00:31.722122:0: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
MESS:00:00:32.032185:0: camsubs: Camera not found
MESS:00:00:32.035208:0: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
MESS:00:00:32.045262:0: camsubs: Camera not found
MESS:00:00:32.049011:0: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
MESS:00:00:32.059067:0: camsubs: Camera not found
MESS:00:00:32.062817:0: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
MESS:00:00:32.072872:0: camsubs: Camera not found

Same fw 1.20200512 but without edid.dat (HDMI not working):

Raspberry Pi Bootcode

Found SD card, config.txt = 0, start.elf = 0, recovery.elf = 0, timeout = 1
Trying USB
Set address 4
Num devices = 1, addr = 4
get_config_descriptor 41 bytes
device class = 9
Hub device found at addr 4, enumerating HUB
Initialise hub
Found 5 ports, multi_tt = 1
Setting interface 0
Enabling PORT POWER on port 1
Enabling PORT POWER on port 2
Enabling PORT POWER on port 3
Enabling PORT POWER on port 4
Enabling PORT POWER on port 5
Waiting for devices to respond to reset
Found device on port 1
Found highspeed device
Set address 5
Num devices = 2, addr = 5
get_config_descriptor 39 bytes
device class = 255
Device found: type = Ethernet adapter, addr = 5
Found device on port 5
Ignoring low speed device
Found device on port 2
Found highspeed device
Set address 6
Num devices = 3, addr = 6
get_config_descriptor 32 bytes
device class = 0
interface_desc[1] = 4
Device found: type = Mass storage, addr = 6
Trying booting from MSD device addr 6
Retrieving the config descriptor
Found ep_in = 00000001, ep_out = 00000002
GetMaxLun returned 0, max_lun = 0
Sending and retrying TEST_UNIT_READY
Sending SCSI_COMMAND_INQUIRY
Sending READ_CAPACITY
init_msd returned 0
USB device configuration set
Initialised mass storage, block size = 512, block count = 30031872
MBR read and decoded successfully
FAT32 partition decoded successfully
start.elf found in first partition on USB MSD, booting
Read File: config.txt, 396 (bytes)

Raspberry Pi Bootcode
Read File: config.txt, 396
Read File: start_x.elf, 3799144 (bytes)
Read File: fixup_x.dat, 9818 (bytes)
MESS:00:00:04.617711:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:04.622094:0: brfs: File read: 396 bytes
MESS:00:00:05.865872:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:05.870275:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
MESS:00:00:05.886976:0: gpioman: gpioman_get_pin_num: pin WL_LPO_CLK not defined
MESS:00:00:05.892683:0: gpioman: gpioman_get_pin_num: pin BT_ON not defined
MESS:00:00:05.899363:0: gpioman: gpioman_get_pin_num: pin WL_ON not defined
MESS:00:00:05.930806:0: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined
MESS:00:00:05.938240:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
MESS:00:00:05.944261:0: *** Restart logging
MESS:00:00:05.948148:0: brfs: File read: 396 bytes
MESS:00:00:06.380383:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
MESS:00:00:06.387741:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
MESS:00:00:06.778613:0: brfs: File read: /mfs/sd/bcm2709-rpi-2-b.dtb
MESS:00:00:06.783276:0: Loading 'bcm2709-rpi-2-b.dtb' to 0x100 size 0x62f2
MESS:00:00:07.023272:0: brfs: File read: 25330 bytes
MESS:00:00:07.336944:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:07.342391:0: brfs: File read: 396 bytes
MESS:00:00:07.655976:0: brfs: File read: /mfs/sd/cmdline.txt
MESS:00:00:07.659957:0: Read command line from file 'cmdline.txt':
MESS:00:00:07.665834:0: 'root=UUID=69c114cd-8a17-4cee-bc25-92fdc8332a00 rootfstype=ext4 rootwait osmcdev=rbp2 elevator=deadline'
MESS:00:00:10.119917:0: gpioman: gpioman_get_pin_num: pin EMMC_ENABLE not defined
MESS:00:00:10.262584:0: gpioman: gpioman_get_pin_num: pin WL_ON not defined
MESS:00:00:10.282915:0: brfs: File read: 103 bytes
MESS:00:00:15.276395:0: brfs: File read: /mfs/sd/kernel7.img
MESS:00:00:15.280354:0: Loading 'kernel7.img' to 0x8000 size 0x868768
MESS:00:00:15.286526:0: Device tree loaded to 0x2eff9900 (size 0x66a5)
MESS:00:00:15.293615:0: uart: Set PL011 baud rate to 103448.300000 Hz
MESS:00:00:15.300471:0: uart: Baud rate change done...
MESS:00:00:15.303903:0: uart: Baud rate change done...
MESS:00:00:18.017865:0: vchiq_core: vchiq_init_state: slot_zero = 0xef980000, is_master = 1
MESS:00:00:29.315925:0: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
MESS:00:00:29.624587:0: camsubs: Camera not found
MESS:00:00:29.627607:0: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
MESS:00:00:29.937670:0: camsubs: Camera not found
MESS:00:00:29.940695:0: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
MESS:00:00:29.950747:0: camsubs: Camera not found
MESS:00:00:29.954498:0: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
MESS:00:00:29.964552:0: camsubs: Camera not found
MESS:00:00:29.968304:0: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
MESS:00:00:29.978358:0: camsubs: Camera not found

Lastly, UART bootlog for bootcode.bin from master branch and edid.dat override enabled (HDMI not working though):

Raspberry Pi Bootcode

Found SD card, config.txt = 0, start.elf = 0, recovery.elf = 0, timeout = 1
Trying USB
Set address 4
Num devices = 1, addr = 4
get_config_descriptor 41 bytes
device class = 9
Hub device found at addr 4, enumerating HUB
Initialise hub
Found 5 ports, multi_tt = 1
Setting interface 0
Enabling PORT POWER on port 1
Enabling PORT POWER on port 2
Enabling PORT POWER on port 3
Enabling PORT POWER on port 4
Enabling PORT POWER on port 5
Waiting for devices to respond to reset
Found device on port 1
Found highspeed device
Set address 5
Num devices = 2, addr = 5
get_config_descriptor 39 bytes
device class = 255
Device found: type = Ethernet adapter, addr = 5
Found device on port 5
Ignoring low speed device
Found device on port 2
Found highspeed device
Set address 6
Num devices = 3, addr = 6
get_config_descriptor 32 bytes
device class = 0
interface_desc[1] = 4
Device found: type = Mass storage, addr = 6
Trying booting from MSD device addr 6
Retrieving the config descriptor
Found ep_in = 00000001, ep_out = 00000002
GetMaxLun returned 0, max_lun = 0
Sending and retrying TEST_UNIT_READY
Sending SCSI_COMMAND_INQUIRY
Sending READ_CAPACITY
init_msd returned 0
USB device configuration set
Initialised mass storage, block size = 512, block count = 30031872
MBR read and decoded successfully
FAT32 partition decoded successfully
start.elf found in first partition on USB MSD, booting
Read File: config.txt, 395 (bytes)

Raspberry Pi Bootcode
Read File: config.txt, 395
Read File: start_x.elf, 3756516 (bytes)
Read File: fixup_x.dat, 10263 (bytes)

It looks like something had changed in logging behaviour between fw 1.20200512 and latest master as there are no MESS:... lines appearing on serial terminal now. But they seem to be available in vcdbg log after system bootup:

# vcdbg log msg
004249.705: brfs: File read: /mfs/sd/config.txt
004250.359: brfs: File read: 395 bytes
004470.345: brfs: File read: /mfs/sd/edid.dat
004472.674: brfs: File read: 256 bytes
004564.609: brfs: File read: /mfs/sd/config.txt
004565.174: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
005191.863: gpioman: gpioman_get_pin_num: pin WL_LPO_CLK not defined
005191.929: gpioman: gpioman_get_pin_num: pin BT_ON not defined
005191.987: gpioman: gpioman_get_pin_num: pin WL_ON not defined
005216.801: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined
005218.084: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
005218.178: *** Restart logging
005218.240: brfs: File read: 395 bytes
005336.685: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
005336.751: HDMI0: hdmi_pixel_encoding: 162000000

005336.998: vec: vec_middleware_power_on: vec_base: 0x7e806000 rev-id 0x00002708 @ vec: 0x7e806100 @ 0x00000420 enc: 0x7e806060 @ 0x00000220 cgmsae: 0x7e80605c @ 0x00000000
005342.490: dtb_file 'bcm2709-rpi-2-b.dtb'
005421.970: brfs: File read: /mfs/sd/bcm2709-rpi-2-b.dtb
005422.037: Loading 'bcm2709-rpi-2-b.dtb' to 0x100 size 0x62f2
005458.241: brfs: File read: 25330 bytes
006244.714: brfs: File read: /mfs/sd/config.txt
006263.081: brfs: File read: 395 bytes
006289.458: brfs: File read: /mfs/sd/cmdline.txt
006289.539: Read command line from file 'cmdline.txt':
006289.595: 'root=UUID=69c114cd-8a17-4cee-bc25-92fdc8332a00 rootfstype=ext4 rootwait osmcdev=rbp2 elevator=deadline'
008751.394: gpioman: gpioman_get_pin_num: pin EMMC_ENABLE not defined
008888.486: gpioman: gpioman_get_pin_num: pin WL_ON not defined
008903.611: brfs: File read: 103 bytes
012421.299: brfs: File read: /mfs/sd/kernel7.img
012421.359: Loading 'kernel7.img' to 0x8000 size 0x868768
012421.426: Device tree loaded to 0x2eff9900 (size 0x66c6)
014456.004: vchiq_core: vchiq_init_state: slot_zero = 0xef980000, is_master = 1
025810.851: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
026111.620: camsubs: Camera not found
026111.694: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
026412.467: camsubs: Camera not found
026412.547: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
026413.299: camsubs: Camera not found
026413.374: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
026414.135: camsubs: Camera not found
026414.210: camsubs: Looking for camera 0: i2c_port = 0, led gpio = 32, power enable gpio = 41
026414.966: camsubs: Camera not found

P.S. I'm still about to test the same boot scheme with my other RPi SoCs. Will post another update when done.

Progress so far:

1) Issue reproduced with RPi 1B.

2) Issue tracked down to the filesystem of the first partition on the USB. At the moment I've got two images of the boot FS on hands, both are perfectly fine FAT32 file systems, no errors reported either using dosfsck, Win10 check filesystem tool and even using such a legacy thing as MS scandisk.exe from Win98SE installation. If I put one image to the boot partition of the USB stick HDMI work without any issues. If I write another image to the same boot partition - HDMI issue is back.

My current theory is that the FAT32 read implementation in the bootloaders is a simplified one and it can't handle FS reads properly for some perfectly valid but not expected file system parameters.

Here is minfo report for the working FAT32 image:

# minfo -i /dev/sdn1 ::
device information:
===================
filename="/dev/sdn1"
sectors per track: 32
heads: 64
cylinders: 256

mformat command line: mformat -t 256 -h 64 -s 32 ::

bootsector information
======================
banner:"mkfs.fat"
sector size: 512 bytes
cluster size: 1 sectors
reserved (boot) sectors: 32
fats: 2
max available root directory slots: 0
small size: 0 sectors
media descriptor byte: 0xf8
sectors per fat: 0
sectors per track: 32
heads: 64
hidden sectors: 0
big size: 524288 sectors
physical drive id: 0x80
reserved=0x0
dos4=0x29
serial number: 592BC92C
disk label="boot       "
disk type="FAT32   "
Big fatlen=4033
Extended flags=0x0000
FS version=0x0000
rootCluster=2
infoSector location=1
backup boot sector=6

Infosector:
signature=0x41615252
free clusters=411901
last allocated cluster=125048

And here is minfo for image triggering HDMI init failed issue:

# minfo -i /dev/sdm1 ::
device information:
===================
filename="/dev/sdm1"
sectors per track: 63
heads: 32
cylinders: 255

mformat command line: mformat -t 255 -h 32 -s 63 -H 63 ::

bootsector information
======================
banner:"MSWIN4.1"
sector size: 512 bytes
cluster size: 1 sectors
reserved (boot) sectors: 32
fats: 2
max available root directory slots: 0
small size: 0 sectors
media descriptor byte: 0xf8
sectors per fat: 0
sectors per track: 63
heads: 32
hidden sectors: 63
big size: 514017 sectors
physical drive id: 0x80
reserved=0x0
dos4=0x29
serial number: C3DF124E
disk label="           "
disk type="FAT32   "
Big fatlen=3955
Extended flags=0x0000
FS version=0x0000
rootCluster=77610
infoSector location=1
backup boot sector=6

Infosector:
signature=0x41615252
free clusters=401782
last allocated cluster=2

I'll continue my investigation to try to find out what particular specifics are triggering the failure. As for issue itself - technically it is a valid one as (1) things worked fine with older code and stopped working with new one thus it is a classic example of regression and (2) end-user expectation is normal behavior as long as boot FAT32 filesystem is valid and error-free from Windows PoV. But from the real world perspective I'd guess that chances for end-user to ever hit this one are next to none - you'd have more problem reports on forum or here otherwise.

I'm wondering if are there any official requirements/limitations on the partitioning and FAT32 specifics for RPi bootcode? I hadn't seen it but I hadn't specifically looked for it either. If there are official limitations clearly defined on FAT32 support in bootloaders then this issue should be treated as an invalid happening due to end-user violating vendor-defined limitations.

@timg236 might be one for you if a valid FAT partition doesn't boot from usb.

The logs imply that the system is booting but HDMI is not working. The FAT code is common between the two boot modes because both SD and USB appear as block devices.

The ROM, bootcode.bin and start.elf always use the primary FAT table and any error correction is left to the OS. It might be worth using fsck from a Raspberry Pi (via a USB card reader) to check both images in-case fsck applies a different check and then using md5sum to validate that the files are identical. start.elf, fixup.dat, kernel, dtbs Other than that there's no special restrictions for FAT32 so long as the cluster-sizes etc conform to the FAT rules which should always be the case if mkfs was used.

Hi @timg236, I've had to step off for a week from this problem due to RealLife(TM) matters but looks like tonight I've got a couple hours to continue my investigation. My goal is to come up with a step-by-step guide to easily reproduce the problem so you would be able to check what's the deal on your equipment and determine what's going on.

Re fsck thing - as stated earlier I had used all available tools on hands to do the FS check: Windows 10 chkdsk, CentOS 7 fsck.vfat (dosfsck) and even such an oddity as Microsoft scandisk.exe that came with Windows 98 SE. No errors were found for each test case so it seems problem is not FS integrity related.

As for boot files integrity - test method I use right now is:

Take latest RPiOS distro image and mount its boot partition read only (using losetup/kpartx).
Use mformat to create new FS on the USB flash drive's first partition.
Use dosfsck to check that created FS is valid/OK.
Mount created FS and do cp -a /media/RPiOS-boot/* /media/BOOT/.
Do sync && umount /media/BOOT && eject /dev/sdX, then physically eject USB flash drive (so kernel vfs cache is invalidated for this device).
Insert USB flash drive back, mount its first partition again. Then do diff -qr /media/RPiOS-boot/ /media/BOOT/ || echo "FAIL!".
If no error messages reported at previous step - unmount and eject USB flash drive, insert it into RPi and try to boot up.
Check if HDMI was initialized or not, rinse, repeat.

Step 6 ensures boot files integrity so we can move this risk out of the table too.

I'll continue with my investigations for the next hour or two and will report back findings if any.

Oh well, I guess I had found a way to reliably reproduce it on my setup, tried with RPi 2B and RPi 1B (pre B+ version).

Here is step-by-step sequence:

Grab latest lite RPiOS image (I was using 2020-05-27-raspios-buster-lite-armhf.img), put it to the USB flash.

Optionally enable boot code log to serial console (sdn is USB flash drive):

# mount /dev/sdn1 /mnt
# sed -i -e "s/BOOT_UART=0/BOOT_UART=1/" /mnt/bootcode.bin
# umount /mnt

Prepare SD card for bootcode.bin-only boot. I was doing it like this (sdn is USB flash drive, sdl is SD card):

# sfdisk -uS -d /dev/sdn | sfdisk -uS /dev/sdl
# hdparm -z /dev/sdl
# dd if=/dev/sdn1 of=/dev/sdl1 bs=1M
# mount /dev/sdl1 /mnt
# cp /mnt/bootcode.bin /tmp/ && rm -rf /mnt/* && cp /tmp/bootcode.bin /mnt/
# sed -i -e "s/BOOT_UART=0/BOOT_UART=1/" /mnt/bootcode.bin
# sync && umount /mnt && eject /dev/sdl

Put SD card into RPi, connect serial console and verify in serial terminal that network boot attempts are happening:

Raspberry Pi Bootcode

Found SD card, config.txt = 0, start.elf = 0, recovery.elf = 0, timeout = 0
Trying USB
Set address 4
Num devices = 1, addr = 4
get_config_descriptor 41 bytes
device class = 9
Hub device found at addr 4, enumerating HUB
Initialise hub
Found 3 ports, multi_tt = 1
Setting interface 0
Enabling PORT POWER on port 1
Enabling PORT POWER on port 2
Enabling PORT POWER on port 3
Waiting for devices to respond to reset
Found device on port 1
Found highspeed device
Set address 5
Num devices = 2, addr = 5
get_config_descriptor 39 bytes
device class = 255
Device found: type = Ethernet adapter, addr = 5
Trying booting from Ethernet device addr 5
Initialise ethernet with MAC b8:27:eb:d2:28:ba
Wait for Link up
Failed to initialise link
...

Insert USB flash drive into RPi, cycle power, verify that (a) OS is booting from USB flash drive and (b) HDMI is initialized normally:

Raspberry Pi Bootcode

Found SD card, config.txt = 0, start.elf = 0, recovery.elf = 0, timeout = 0
Trying USB
Set address 4
Num devices = 1, addr = 4
get_config_descriptor 41 bytes
device class = 9
Hub device found at addr 4, enumerating HUB
Initialise hub
Found 3 ports, multi_tt = 1
Setting interface 0
Enabling PORT POWER on port 1
Enabling PORT POWER on port 2
Enabling PORT POWER on port 3
Waiting for devices to respond to reset
Found device on port 1
Found highspeed device
Set address 5
Num devices = 2, addr = 5
get_config_descriptor 39 bytes
device class = 255
Device found: type = Ethernet adapter, addr = 5
Found device on port 2
Found highspeed device
Set address 6
Num devices = 3, addr = 6
get_config_descriptor 41 bytes
device class = 9
Hub device found at addr 6, enumerating HUB
Initialise hub
Found 4 ports, multi_tt = 1
Setting interface 0
Enabling PORT POWER on port 1
Enabling PORT POWER on port 2
Enabling PORT POWER on port 3
Enabling PORT POWER on port 4
Waiting for devices to respond to reset
Found device on port 1
Ignoring low speed device
Found device on port 3
Found highspeed device
Set address 7
Num devices = 4, addr = 7
get_config_descriptor 32 bytes
device class = 0
interface_desc[1] = 4
Device found: type = Mass storage, addr = 7
Trying booting from MSD device addr 7
Retrieving the config descriptor
Found ep_in = 00000001, ep_out = 00000002
GetMaxLun returned 0, max_lun = 0
Sending and retrying TEST_UNIT_READY
Sending SCSI_COMMAND_INQUIRY
Sending READ_CAPACITY
init_msd returned 0
USB device configuration set
Initialised mass storage, block size = 512, block count = 30031872
MBR read and decoded successfully
FAT32 partition decoded successfully
start.elf found in first partition on USB MSD, booting
Read File: config.txt, 1784 (bytes)

Raspberry Pi Bootcode
Read File: config.txt, 1784
Read File: start.elf, 2884708 (bytes)
Read File: fixup.dat, 6746 (bytes)
MESS:00:00:06.448516:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:06.453061:0: brfs: File read: 1784 bytes
MESS:00:00:09.611696:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:09.616213:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
MESS:00:00:09.632593:0: gpioman: gpioman_get_pin_num: pin WL_LPO_CLK not defined
MESS:00:00:09.638296:0: gpioman: gpioman_get_pin_num: pin BT_ON not defined
MESS:00:00:09.644975:0: gpioman: gpioman_get_pin_num: pin WL_ON not defined
MESS:00:00:09.673897:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
MESS:00:00:09.679707:0: *** Restart logging
MESS:00:00:09.683593:0: brfs: File read: 1784 bytes
**MESS:00:00:10.711971:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead**
MESS:00:00:11.766734:0: brfs: File read: /mfs/sd/bcm2708-rpi-b.dtb
MESS:00:00:11.771220:0: Loading 'bcm2708-rpi-b.dtb' to 0x100 size 0x5e1f
MESS:00:00:11.889387:0: brfs: File read: 24095 bytes
MESS:00:00:12.936894:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:12.941115:0: dtparam: audio=on
MESS:00:00:12.961850:0: brfs: File read: 1784 bytes
MESS:00:00:13.996161:0: brfs: File read: /mfs/sd/cmdline.txt
MESS:00:00:14.000140:0: Read command line from file 'cmdline.txt':
MESS:00:00:14.006027:0: 'console=serial0,115200 console=tty1 root=PARTUUID=a897d240-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait'
MESS:00:00:15.711160:0: gpioman: gpioman_get_pin_num: pin EMMC_ENABLE not defined
MESS:00:00:15.746567:0: gpioman: gpioman_get_pin_num: pin WL_ON not defined
MESS:00:00:15.759580:0: brfs: File read: 121 bytes
MESS:00:00:23.427319:0: brfs: File read: /mfs/sd/kernel.img
MESS:00:00:23.431199:0: Loading 'kernel.img' to 0x8000 size 0x4eb4b8
MESS:00:00:23.437285:0: Device tree loaded to 0x1bfe9e00 (size 0x61e2)
MESS:00:00:23.444382:0: uart: Set PL011 baud rate to 103448.300000 Hz
MESS:00:00:23.451235:0: uart: Baud rate change done...
MESS:00:00:23.454663:0: uart: Baud rate change done...
MESS:00:00:26.624590:0: vchiq_core: vchiq_init_state: slot_zero = 0x5b580000, is_master = 1
MESS:00:00:26.637150:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
MESS:00:00:26.650133:0: TV service:host side not connected, dropping notification 0x00000002, 0x00000002, 0x00000023
[    0.000000] Booting Linux on physical CPU 0x0

Notice a single hdmi-related line in the pre-kernel bootup log

Power off Rpi, connect USB flash back to linux box, mount boot partition and backup all files and folders somewhere.

Create a new FAT32 filesystem with cluster size equal to 2 (or 4) sectors:

### Using mtools:
# mformat -F -c 2 -i /dev/sdn1 -t 256 -h 64 -s 32 -N "592BC92C" -v"boot       " ::
### Or using dosfstools:
# mkdosfs -a -F 32 -s 2  -i "592BC92C" -n "boot       " /dev/sdn1
### And check that created FS is valid:
# dosfsck -f -y /dev/sdn1

Copy backed up files at pt.6 to the newly created filesystem, perform all steps you find necessary to confirm files integrity.

Put USB flash back to RPi and try to boot. For my setup HDMI won't initialize now:

Raspberry Pi Bootcode

Found SD card, config.txt = 0, start.elf = 0, recovery.elf = 0, timeout = 0
Trying USB
Set address 4
Num devices = 1, addr = 4
get_config_descriptor 41 bytes
device class = 9
Hub device found at addr 4, enumerating HUB
Initialise hub
Found 3 ports, multi_tt = 1
Setting interface 0
Enabling PORT POWER on port 1
Enabling PORT POWER on port 2
Enabling PORT POWER on port 3
Waiting for devices to respond to reset
Found device on port 1
Found highspeed device
Set address 5
Num devices = 2, addr = 5
get_config_descriptor 39 bytes
device class = 255
Device found: type = Ethernet adapter, addr = 5
Found device on port 2
Found highspeed device
Set address 6
Num devices = 3, addr = 6
get_config_descriptor 32 bytes
device class = 0
interface_desc[1] = 4
Device found: type = Mass storage, addr = 6
Trying booting from MSD device addr 6
Retrieving the config descriptor
Found ep_in = 00000001, ep_out = 00000002
GetMaxLun returned 0, max_lun = 0
Sending and retrying TEST_UNIT_READY
Sending SCSI_COMMAND_INQUIRY
Sending READ_CAPACITY
init_msd returned 0
USB device configuration set
Initialised mass storage, block size = 512, block count = 30031872
MBR read and decoded successfully
FAT32 partition decoded successfully
start.elf found in first partition on USB MSD, booting
Read File: config.txt, 1784 (bytes)

Raspberry Pi Bootcode
Read File: config.txt, 1784
Read File: start.elf, 2884708 (bytes)
Read File: fixup.dat, 6746 (bytes)
MESS:00:00:04.601492:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:04.606036:0: brfs: File read: 1784 bytes
MESS:00:00:06.300222:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:06.304739:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
MESS:00:00:06.321162:0: gpioman: gpioman_get_pin_num: pin WL_LPO_CLK not defined
MESS:00:00:06.326866:0: gpioman: gpioman_get_pin_num: pin BT_ON not defined
MESS:00:00:06.333544:0: gpioman: gpioman_get_pin_num: pin WL_ON not defined
MESS:00:00:06.362405:0: gpioman: gpioman_get_pin_num: pin LEDS_PWR_OK not defined
MESS:00:00:06.368214:0: *** Restart logging
MESS:00:00:06.372100:0: brfs: File read: 1784 bytes
**MESS:00:00:06.920246:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead**
**MESS:00:00:06.927605:0: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead**
MESS:00:00:07.494754:0: brfs: File read: /mfs/sd/bcm2708-rpi-b.dtb
MESS:00:00:07.499244:0: Loading 'bcm2708-rpi-b.dtb' to 0x100 size 0x5e1f
MESS:00:00:07.617349:0: brfs: File read: 24095 bytes
MESS:00:00:08.176723:0: brfs: File read: /mfs/sd/config.txt
MESS:00:00:08.180947:0: dtparam: audio=on
MESS:00:00:08.201683:0: brfs: File read: 1784 bytes
MESS:00:00:08.747925:0: brfs: File read: /mfs/sd/cmdline.txt
MESS:00:00:08.751901:0: Read command line from file 'cmdline.txt':
MESS:00:00:08.757788:0: 'console=serial0,115200 console=tty1 root=PARTUUID=a897d240-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait'
MESS:00:00:10.442060:0: gpioman: gpioman_get_pin_num: pin EMMC_ENABLE not defined
MESS:00:00:10.477449:0: gpioman: gpioman_get_pin_num: pin WL_ON not defined
MESS:00:00:10.490478:0: brfs: File read: 121 bytes
MESS:00:00:15.206304:0: brfs: File read: /mfs/sd/kernel.img
MESS:00:00:15.210179:0: Loading 'kernel.img' to 0x8000 size 0x4eb4b8
MESS:00:00:15.216264:0: Device tree loaded to 0x1bfe9e00 (size 0x61de)
MESS:00:00:15.223377:0: uart: Set PL011 baud rate to 103448.300000 Hz
MESS:00:00:15.230218:0: uart: Baud rate change done...
MESS:00:00:15.233650:0: uart: Baud rate change done...
MESS:00:00:18.294485:0: vchiq_core: vchiq_init_state: slot_zero = 0x5b580000, is_master = 1
[    0.000000] Booting Linux on physical CPU 0x0

Notice HDMI-related message in pre-kernel bootup appearing twice consequently

Repeat filesystem creation process but now with cluster size equal to 1 sector:

### Using mtools:
# mformat -F -c 1 -i /dev/sdn1 -t 256 -h 64 -s 32 -N "592BC92C" -v"boot       " ::
### Or using dosfstools:
# mkdosfs -a -F 32 -s 1  -i "592BC92C" -n "boot       " /dev/sdn1

Copy boot files back to newly created FS, verify their integrity and try to boot RPi. This time HDMI is expected to initialize fine (at least it does so on my setup).
Repeat steps 7-11 with other FAT32 cluster sizes. I'm getting non-working HDMI when cluster size is anything other that 512 bytes (i.e. 1 sector). As soon as I create FAT32 filesystem with cluster size set to 2 or 4 sectors it is "lights off" for my output device. Reformat with cluster size equal to 1 sector and things are back to normal.

@timg236 @6by9 Please try to follow step-by-step instructions above and verify if you would be able to reproduce this issue. Thanks once again for looking into this bizarre problem.

@timg236 @6by9 Small update: as an extra testing effort I had tried to format first partition of USB flash drive in Windows 10 using FAT32 FS and "Default cluster size". Windows had chosen cluster size == 2048 bytes (4 sectors) and resulting file system suffers "HDMI not working" problem the same way as when FS is created by mkdosfs or mformat with the same cluster size. Here are filesystem characteristics for FS created by Windows 10:

# minfo -i /dev/sdn1 ::
device information:
===================
filename="/dev/sdn1"
sectors per track: 63
heads: 255
cylinders: 33

mformat command line: mformat -t 33 -h 255 -s 63 -H 8192 ::

bootsector information
======================
banner:"MSDOS5.0"
sector size: 512 bytes
cluster size: 4 sectors
reserved (boot) sectors: 6174
fats: 2
max available root directory slots: 0
small size: 0 sectors
media descriptor byte: 0xf8
sectors per fat: 0
sectors per track: 63
heads: 255
hidden sectors: 8192
big size: 524288 sectors
physical drive id: 0x80
reserved=0x1
dos4=0x29
serial number: E64990E9
disk label="NO NAME    "
disk type="FAT32   "
Big fatlen=1009
Extended flags=0x0000
FS version=0x0000
rootCluster=2
infoSector location=1
backup boot sector=6

Infosector:
signature=0x41615252
free clusters=129023
last allocated cluster=3

Upd.2.: And then I re-formatted in Windows 10 with cluster size enforced to be 512 bytes and - as I was expecting - HDMI got back to normal. TL/DR: cluster size is what matters here rather than FS creation tool.

raspberrypi / firmware

[RPi 2B] start_x.elf possible regression in 1.20190620: no HDMI init on boot when using bootcode.bin-only SD card boot mode #1413