[Mut@nt] HD51 Online Upgrade Crash (log attached)

[Spoof]

Logs attached (don't know why but the dmesg log is time-stamped 12 minutes earlier than the other two, if that helps).


If it's of any use, I did a test - loaded 6.006 and declined the option to restore my settings. I then set up one satellite and scanned one transponder and the boot time was 59.5 seconds.

 

[Joe_90]

Logs attached (don't know why but the dmesg log is time-stamped 12 minutes earlier than the other two, if that helps).


If it's of any use, I did a test - loaded 6.006 and declined the option to restore my settings. I then set up one satellite and scanned one transponder and the boot time was 59.5 seconds.

Do these logs refer to your test without restoring your settings? They have the same 106 second delay before enigma starts.

If the logs are from a previous test after you have done your settings, then it's presumably something in your settings file that is causing the issue (although I'd expect anything in the settings to show up in the enigma log).

Maybe restore the settings and attach the contents of etc/enigma2/settings - block out any sensitive user/password details etc.

Is it possible that you are running some script prior to enigma start that is doing a backup or trying to access a network resource that is not responding or similar?

 

[birdman]

Logs attached (don't know why but the dmesg log is time-stamped 12 minutes earlier than the other two, if that helps).

The timestamps in the messages file are odd.

Jan 14 10:39:20 mutant51 kern.info kernel: [ 13.660545] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Jan 14 10:39:20 mutant51 cron.info crond[2105]: (CRON) STARTUP (1.5.7)
Jan 14 10:39:20 mutant51 cron.info crond[2105]: (CRON) INFO (Syslog will be used instead of sendmail.)
Jan 14 10:39:20 mutant51 cron.info crond[2105]: (CRON) INFO (RANDOM_DELAY will be scaled with factor 4% if used.)
Jan 14 10:39:20 mutant51 kern.err kernel: [ 105.285293] blk_update_request: I/O error, dev mmcblk0rpmb, sector 0

So the wall clock doesn't doesn't advance between the first and last entry, but the since-boot-time one has advanced by ~92s!?!
That I/O error looks suspicious.

 

[Joe_90]

@birdman - see my post #20 regarding the I/O error. I get it on my mutant also - it's a 4GB mmc. I've got the error message to go away running fsck in the past, but it seems to return. Doesn't seem to cause any practical issues in my setup, though.
It's all very odd - time lost before enigma starts logging. I can only think something is waiting or delayed during linux boot - disk or network delay?

 

[twol]

MMC I/O error ------ As far as I remember its the way the mmc is loaded up, think the image is bigger than the slot size (or the other way around - cannot remember too long ago) ... hence the notrunc when its built

https://github.com/oe-alliance/oe-alliance-core/blob/5.0/meta-brands/meta-gfutures/classes/hdemmc_image_multi.bbclass

 

[birdman]

@birdman - see my post #20 regarding the I/O error. I get it on my mutant also - it's a 4GB mmc. I've got the error message to go away running fsck in the past, but it seems to return.

OK. So just an unfortunate position in in the log.

So we just need to explain the 92s counted by the kernel clock (and which seem to be real as the user is reporting a pause) that do not show up on the wall clock, and the wall clock appears to be correct after those missing 92s as ntp runs at 10:39:33 (message log) with only a 0.0008s adjustment needed.

 

[birdman]

So we just need to explain the 92s counted by the kernel clock

OK. I can do that.
The message log isn't actually written at all until those blk_update_request entries arrive. At that point the entire (in memory) kernel log buffer gets dumped into the messages log with the current timestamp.
So the 92s delay does come between the network coming up and those I/O error reports. So what goes on then?

 

[birdman]

Could you post your /etc/fstab file? (with any passwords removed...)

The S15mountnfs.sh actually seems to run mount -a (== mount everything) so this might contain a network mount that produces a pause(?).

 

[Joe_90]

I think you're on the right lines as there is definitely something happening in the early start-up stages. As regards the "messages" file, I was always surprised as to the local time timestamps in it as they all seem to be the same. It would make sense if the (in memory) data all got written to the message file at one point with the current timestamp.

 

[birdman]

It would make sense if the (in memory) data all got written to the message file at one point with the current timestamp.

I think syslog does it at start-up.

 

[Spoof]

Do these logs refer to your test without restoring your settings?

The logs are after I restore the settings.

 

[Spoof]

Could you post your /etc/fstab file?

/dev/mmcblk0p1 /boot auto defaults 1 1
rootfs / auto defaults 1 1
proc /proc proc defaults 0 0
devpts /dev/pts devpts mode=0620,gid=5 0 0
usbdevfs /proc/bus/usb usbdevfs noauto 0 0
tmpfs /var/volatile tmpfs defaults 0 0
/dev/mmcblk0p10 none swap defaults 0 0

 

[Joe_90]

The logs are after I restore the settings.

See post #28. Can you post your /etc/enigma2/settings file, please. Remove any user/password info if present.

 

[Spoof]

Settings attached.

 

[birdman]

See post #28. Can you post your /etc/enigma2/settings file, please. Remove any user/password info if present.

Although we know the issue occurs before enigma2 starts up, so it's unlikely anything in its settings file is causing a problem.

Could you:

• take a copy of your /etc/init.d/rc file (to reinstate later)
• put the attached file (unzipped) in as /etc/init.d/rc
• reboot the box
• take a copy of the /tmp/debug-startup.log that is produced and post it here
• reinstate the original /etc/init.d/rc file
• reboot the box

The log file will give the times at which each start-up file stops running, so should indicate which one is taking up the time.

View attachment rc.zip

Note that the rc file is an essential part of the system start-up so if the copy is in some way incorrect your system won't start, so you may wish to do a backup before you put it in place.
I have tested it on my own system.

 

[Spoof]

take a copy of the /tmp/debug-startup.log that is produced and post it here

1st log is a warm boot log ("Standby & Restart > Reboot")

2nd log is a cold reboot.

I noticed the box seems to boot OK form a warm reboot and the 2nd log suggests (I think!) the wait at boot time is for networking to come up.
For your info., I have a mini router plugged in (powered) by the USB port of the receiver, and this takes abut 90 seconds to boot itself.

 

[Spoof]

Some further testing (cold boot times):

Networking off - 30 seconds to clear channel.
dhcp enabled - 50 seconds before starting... changes to spinning Vix, 60 seconds to clear channel.
dhcp off (forced IP / my normal settings) 102 seconds before starting... changes to spinning Vix, 114 to clear channel

 

[Huevos]

Which multiboot slot is the image loaded in? ... and which slot the 5.4 image?

 

[Spoof]

I never set up multiboot, but when I flash from the image manager, I only ever use slot 1.

 

[Huevos]

Can you completely disconnect it from the network. Remove the router so there is no WiFi. Then see if it boots.