U4: UI startup crash - no framebuffer available

[Grumpy_Geoff]

Caught the U4 this morning with 'Booting...' on the front panel and no further progression.

There were over 400 debug and crash logs present from that time period. Checking some of them shows the last entry as - [gFBDC] no framebuffer available.
The UI would attempt startup & crash, start & crash again, start & crash again a third time - then get put in the sin bin for 5 minutes, then rinse and repeat.

Snippet from /var/log/messages -

Code: Select all

Mar 13 01:06:47 beyonwizu4 daemon.info avahi-daemon[660]: Server startup complete. Host name is beyonwizu4.local. Local service cookie is 3415837395.
Mar 13 01:06:47 beyonwizu4 user.notice kernel: random: crng init done
Mar 13 01:06:47 beyonwizu4 daemon.info avahi-daemon[660]: Service "FTP file server on beyonwizu4" (/services/ftp.service) successfully established.
Mar 13 01:06:47 beyonwizu4 daemon.info avahi-daemon[660]: Service "beyonwizu4" (/services/ssh.service) successfully established.
Mar 13 01:06:47 beyonwizu4 daemon.info avahi-daemon[660]: Service "beyonwizu4" (/services/sftp-ssh.service) successfully established.
Mar 13 01:06:49 beyonwizu4 daemon.info init: Id "gui" respawning too fast: disabled for 5 minutes
Mar 13 01:06:49 beyonwizu4 daemon.info init: no more processes left in this runlevel
Mar 13 01:11:52 beyonwizu4 daemon.info init: Id "gui" respawning too fast: disabled for 5 minutes
Mar 13 01:16:55 beyonwizu4 daemon.info init: Id "gui" respawning too fast: disabled for 5 minutes

This isn't the first time I've seen this.

I issued a reboot command from command line and the system correctly restarted.

The first crash log -

Code: Select all

Enigma2 Crashlog

Crashdate = Wed Mar 13 01:06:47 2019

box_type=beyonwizu4
version=17.5
build=20190207
date=20190207175345
creator=Beyonwiz
url=http://www.beyonwiz.com.au
Compiled = Feb  6 2019
Skin = Full-Metal-Wizard/skin.xml
Component = enigma2

Kernel CMDline = root=/dev/mmcblk0p4 rootfstype=ext4 rootflags=data=journal rootwait rw coherent_pool=2M vmalloc=804m bmem=696m@312m bmem=620m@2436m
Nim Sockets = 


{708}<    21.480> [eInit] + (1) Background File Eraser
{708}<    21.480> [eInit] + (5) Tuxtxt
{708}<    21.480> [eInit] + (8) graphics acceleration manager
{708}<    21.480> [bcm] /dev/fb0 No such file or directory
{708}<    21.480> [eInit] + (9) Font Render Class
{708}<    21.480> [Font] initializing lib...
{708}<    21.480> [Font] loading fonts...
{708}<    21.480> [Font] Intializing font cache, using max. 4MB...
{708}<    21.480> [eInit] + (9) gLCD
{708}<    21.480> [eFbLCD] /dev/fb1: No such file or directory
{708}<    21.480> [eFbLCD] framebuffer /dev/fb1 not available
{708}<    21.480> [eDboxLCD] No oled0 or lcd0 device found!
{708}<    21.480> [eLCD] (132x64x8) buffer 0x41e600 8448 bytes, stride 132
{708}<    21.480> [gLCDDC] resolution: 132x64x8 stride=132
{708}<    21.480> [eInit] + (9) GFBDC
{708}<    21.480> [fb] /dev/fb0 No such file or directory
{708}<    21.480> [fb] framebuffer /dev/fb0 not available
{708}<    21.480> [gFBDC] no framebuffer available

I suspected a USB tuner issue, but it appears to initialise correctly, from dmesg command -

Code: Select all

usb 4-1.4: dvb_usb_v2: found a 'Realtek RTL2832U reference design' in warm state
usb 4-1.4: dvb_usb_v2: will pass the complete MPEG2 transport stream to the software demuxer
DVB: registering new adapter (Realtek RTL2832U reference design)
i2c i2c-0: Added multiplexed i2c bus 1
rtl2832 0-0010: Realtek RTL2832 successfully attached
usb 4-1.4: DVB: registering adapter 1 frontend 0 (Realtek RTL2832 (DVB-T))...
r820t 1-001a: creating new instance
r820t 1-001a: Rafael Micro r820t successfully identified
Registered IR keymap rc-empty
input: Realtek RTL2832U reference design as /devices/platform/rdb/f0470500.ehci_v2/usb4/4-1/4-1.4/rc/rc0/input0
rc rc0: Realtek RTL2832U reference design as /devices/platform/rdb/f0470500.ehci_v2/usb4/4-1/4-1.4/rc/rc0
usb 4-1.4: dvb_usb_v2: schedule remote query interval to 200 msecs
usb 4-1.4: dvb_usb_v2: 'Realtek RTL2832U reference design' successfully initialized and connected
usbcore: registered new interface driver dvb_usb_rtl28xxu
EXT4-fs (mmcblk0p4): re-mounted. Opts: nodelalloc,data=journal
unimac-mdio-0:01: Broadcom BCM7439 (2) PHY revision: 0x10, patch: 1
bcmgenet f0b00000.ethernet: configuring instance for internal PHY
IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
bcmgenet f0b00000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
random: crng init done

Any thoughts?

[prl]

The UI would attempt startup & crash, start & crash again, start & crash again a third time - then get put in the sin bin for 5 minutes, then rinse and repeat.

That's what init does for processes that it runs that have the respawn tag in /etc/inittab, like enigma2.sh (inittab entry: gui:3:respawn:/usr/bin/enigma2.sh). That much is working as it should.

I suspected a USB tuner issue, but it appears to initialise correctly, from dmesg command

The frame buffer is at the opposite end of the receive/render chain from the tuner. It's the device that contains the video image buffers and the associated accelerator hardware. From there it's just combining the video buffer and the GUI overlay, video serialisation from the memory and encoding (+DAC when needed) to the sockets on the rear.

[Grumpy_Geoff]

...

I suspected a USB tuner issue, but it appears to initialise correctly, from dmesg command

The frame buffer is at the opposite end of the receive/render chain from the tuner. It's the device that contains the video image buffers and the associated accelerator hardware. From there it's just combining the video buffer and the GUI overlay, video serialisation from the memory and encoding (+DAC when needed) to the sockets on the rear.

Sure, but whenever I've seen the frame buffer issues, I've always found a suspect USB device attached (dead/dieing USB tuner, possibly unhealthy external HDD). Could be a coincidence though.

It appears something gobbled up all of the memory, because on a "good" start I see reported for the frame buffer -

Code: Select all

{743}<    23.336> [fb] /dev/fb0: 24300k video mem
{743}<    23.342> [fb] double buffering available!
{743}<    23.420> [gFBDC] resolution: 1920x1080x32 stride=7680, 8100kB available for acceleration surfaces.

whereas in the errored startup there was nowt -

Code: Select all

{729}<    21.657> [fb] /dev/fb0 No such file or directory
{729}<    21.657> [fb] framebuffer /dev/fb0 not available
{729}<    21.657> [gFBDC] no framebuffer available

[prl]

As far as I can tell, the U4 frame buffer isn't a USB device.

[Grumpy_Geoff]

As far as I can tell, the U4 frame buffer isn't a USB device.

Sure, but I mean a dodgy USB device may have an impact. A driver issue?

[peteru]

I assume that this was a problem where the U4 was shut down and scheduled to boot at some point.

It looks like the DVB driver failed to load for some reason. A GUI restart is not sufficient to recover. A full reboot should bring the driver back to life. As to the reason? Who knows! Could be anything. Running out of resources, such as memory (or even hardware pipelines, such as demuxers) is the most common problem, but certainly not the only one. Systematic testing would be needed to establish whether there is any correlation to connecting a particular USB device. It is certainly possible. If the USB driver loads first and fragments the memory enough, then the DVB driver might fail to get a large contiguous chunk of RAM and fail to load.

[Grumpy_Geoff]

Thanks.

Yep, the U4 was in deep standby and was booting for a scheduled timer recording of the Paris-Nice cycling.

The GUI continued to attempt to restart at 3 times every 5 minutes until I got to the box and rebooted it 5.5 hours later once I looked at the various logs and dmesg.

I don't have any USB devices attached apart from the USB tuner. It is possible that the USB tuner wasn't "properly" attached as it was overhanging the back of the TV cabinet, although it appeared to be detected and initialised according to the messages log. I've since repositioned it, and the U4 has been operating normally. I've had the USB tuner set as the default and it's worked fine too.

[Grumpy_Geoff]

I had this exact same situation again last night. A boot from deep standby, followed by the UI crashing, and then the system attempted to restart the UI which crashes, and on we go. The GUI crashed 1,780 times before I noticed it this morning.

The same error in the crash log as in the OP in this topic -

Code: Select all

{750}<    22.632> [fb] /dev/fb0 No such file or directory
{750}<    22.632> [fb] framebuffer /dev/fb0 not available
{750}<    22.632> [gFBDC] no framebuffer available

I issued a reboot command using telnet and all was fine after the reboot.


Is it possible to have the system altered to detect this "no framebuffer" situation and issue either a reboot command or the UI equivalent (whatever it does on a user-driven 'Reboot' from the Power / Restart menu, or after a settings restore)?


Cheers,
Geoff

[adoxa]

This should reboot should it occur again.

The patch:

Code: Select all

diff --git a/lib/gdi/gfbdc.cpp b/lib/gdi/gfbdc.cpp
index 3f41f8bd7a..015edf74a2 100644
--- a/lib/gdi/gfbdc.cpp
+++ b/lib/gdi/gfbdc.cpp
@@ -23,7 +23,12 @@ gFBDC::gFBDC()
 	fb=new fbClass;
 
 	if (!fb->Available())
-		eFatal("[gFBDC] no framebuffer available");
+	{
+		eLog(lvlFatal, "[gFBDC] no framebuffer available, rebooting");
+		extern void quitMainloop(int);
+		quitMainloop(2);
+		return;
+	}
 
 	int xres;
 	int yres;

[Grumpy_Geoff]

This should reboot should it occur again.

Thanks.
Running the binary now. I may not know for a while, could be hours to months (occurred in Jan, Mar, now Jun).

[Grumpy_Geoff]

Hi adoxa,

I've been running this "no framebuffer fix" executable of yours for a week without issue, but today there were 8 x crashes.
I've since backed out that change by restoring from the back up, just in case the cause was that "fix" executable.

All crashes have a common crash output -

Code: Select all

{743}<   596.148> Backtrace:
{743}<   596.148> /usr/bin/enigma2(n/a) [0x988dc]
{743}<   596.148> /lib/libc.so.6(__default_rt_sa_restorer) [0xb603cc60]
{743}<   596.148> /usr/bin/enigma2(n/a) [0x131450]
{743}<   596.149> /usr/bin/enigma2(n/a) [0xad93c]
{743}<   596.149> /usr/bin/enigma2(n/a) [0xacba4]
{743}<   596.149> /usr/bin/enigma2(n/a) [0xac1d8]
{743}<   596.149> /usr/bin/enigma2(n/a) [0xab7ac]
{743}<   596.149> /usr/bin/enigma2(n/a) [0xb66fc]
{743}<   596.149> /usr/bin/enigma2(n/a) [0xb5ce8]
{743}<   596.149> /usr/bin/enigma2(n/a) [0xb6118]
{743}<   596.149> /usr/bin/enigma2(n/a) [0xb62c4]
{743}<   596.149> /usr/bin/enigma2(n/a) [0x2f3408]
{743}<   596.150> -------FATAL SIGNAL (4)

Does that /lib/libc.so.6(__default_rt_sa_restorer) [0xb603cc60] line give a clue?

I can zip up the crash logs if you want to have a look at them.


Cheers,
Geoff

[adoxa]

There might be a mismatch somewhere between the binary (built from the latest code) and the older Python code. I'm not too bothered atm, as a better way to test this is through the pre-start script. Create or edit /usr/bin/enigma2_pre_start.sh, adding test -c /dev/fb0 || /sbin/reboot.

[Grumpy_Geoff]

There might be a mismatch somewhere between the binary (built from the latest code) and the older Python code. I'm not too bothered atm, as a better way to test this is through the pre-start script. Create or edit /usr/bin/enigma2_pre_start.sh, adding test -c /dev/fb0 || /sbin/reboot.

Thanks.
My next step alternative to the binary was to stick a grep in the pre-start script looking for '[gFBDC] no framebuffer available' in the debug log, but I'll do it your way as it doesn't depend on debug logging.

[prl]

All crashes have a common crash output -

Code: Select all

...
{743}<   596.150> -------FATAL SIGNAL (4)

Signal 4 is SIGILL Illegal Instruction. A common cause for that is someone writing rubbish into a subroutine return address on the stack, e.g. through a write to an array on the stack beyond the array's actual bounds. A bad return address can also happen indirectly if someone clobbers the link back to a prior stack frame by a similar sort of write.

[sub3R]

Just to add to this topic. I have recently experienced the same issue on one of our U4s & it appears that gtwundke has also previously. See my topic U4 wouldn’t boot up - f/w 19.3 20200405 under ‘Beyonwiz T2/T3/T4/U4 > Public Beta (Enter at your own Risk)’.

[Grumpy_Geoff]

Looking now I see the check did its job for me yesterday -

Code: Select all

In pre-start: 03/01/70 12:13:46
*** no framebuffer available (/dev/fb0).  Rebooting
In pre-start: 01/01/70 08:00:31
    Invoking AutoVisit.sh
In pre-start: 01/01/70 20:29:28
    Invoking AutoVisit.sh
In pre-start: 18/04/20 13:25:54
    Invoking AutoVisit.sh