PDA

View Full Version : [Mut@nt] HD51 OpenViX 5.1.032 will not return to standby/deep standby after recording



Mickkie
31-07-18, 13:06
Hi All,

I'm not sure if this is a regression bug, because I also experienced this with 5.1.027. The box will wake up from deep standby to perform a recording. It will stay up, rather than going to standby during the recording and unfortunately will continue to stay up spinning its disk for ever after. The normal behaviour is to return to standby during the recording, and deep standby thereafter if it woke up from a deep standby.

I did a in-situ system update which started this problem and then re-flashed with a USB stick just in case, but the same symptoms remain.

Then I tried to return to a 5.1.030 backup image, but unfortunately this failed completely. :(

Is there a workaround to this problem?

ccs
31-07-18, 13:10
Does this help.....

https://www.world-of-satellite.com/showthread.php?48033-Unable-to-go-into-deep-standby-after-a-recording&p=382929&viewfull=1#post382929

Mickkie
31-07-18, 14:42
Thanks css,

No, the "Stop timeshift while recording?" was disabled anyway. However, I reflashed via USB and then I did NOT restore any settings from a back up. Of course I had to rescan channels and set afresh a lot of my settings and a couple of timers. The good news is that on an one-off timer the box woken up from Deep Standby, then went to Standby as it should do and it is presently recording. I'll wait to see what it does after the recording is finished, but would like to remain optimistic. :)

Perhaps there was a lot of cruft accumulated over multiple updates in situ and some settings we clashing.

Mickkie
31-07-18, 17:36
OK, the device returned to Deep Standby after it finished recording. Therefore something in my previous settings must have caused the problem.

Is there a way to restore my timers without using a previous backup? I suspect if I restore from backed up settings I will merely bring back the problem along with my timers and settings.

ccs
31-07-18, 18:53
You can extract timers.xml from a previous settings backup, stop enigma with the telnet command init 4, copy timers.xml to /etc/enigma2/ , and restart enigma with init 3.

Mickkie
02-08-18, 19:42
Thanks css, very useful tip!

However, I'm at a loss as to what is happening with this box. When I test it to see if it wakes up, goes to Standby, records and shuts down, it behaves as it should. When I turn my back and leave it to record its auto-timers as it used to, it wakes up and stays on continuously! Is it worth capturing and posting a log in case it shows what is the cause of this problem?

ccs
02-08-18, 19:52
Is this the same problem you reported here.....

https://www.world-of-satellite.com/showthread.php?59500-OpenViX-5-1-027-will-not-return-to-Deep-Standby-affter-recording&p=470374&viewfull=1#post470374

My ET10K is waking up from deep standby and recording in standby all the time at the moment, and shuts down to deep standby if after event is set to do that.

The only time it mis-behaved waking up a couple of months ago was when the time in deep standby was longer than usual (probably about 20 hours)

cactikid
02-08-18, 19:56
Just a query if its an internal/external hdd or a usb passport?

Mickkie
02-08-18, 21:16
Is this the same problem you reported here.....

https://www.world-of-satellite.com/showthread.php?59500-OpenViX-5-1-027-will-not-return-to-Deep-Standby-affter-recording&p=470374&viewfull=1#post470374
Yes, it is the same problem.

Mickkie
02-08-18, 21:22
I have an 1TB internal spinning drive for recordings, timeshift and logs. I also have an external USB stick I bought from WoS at the same time I bought the box. Interestingly, I tried to fsck the USB fs with the GUI and it complained of an error. So I unmounted it manually and run fsck.vfat on it. fsck reported an error (probably it was not unmounted cleanly last time). Anyway, I thought the error was because of this, allowed the fsck command to remove a dirty bit from the previous unlean unmounting and following a quick test during which the box behaved correctly, I was hoping the error was fixed. It wasn't going to be that easy. Earlier this eve it played up again. So I'm at a loss as to what is causing all this. As I said, happy to post logs the next time it plays up, in case someone can spot what's amiss.

cactikid
02-08-18, 21:57
i presume hdd to go into standby after 5 mins?

ccs
02-08-18, 22:01
i presume hdd to go into standby after 5 mins?
hdd "standby"/spin down won't effect when/if the box goes into standby/deep standby.

Mickkie
02-08-18, 23:22
In any case, HDD standby is set to 2 minutes:

config.usage.hdd_standby=120

Mickkie
03-08-18, 12:04
I left the Mut@nt on Standby last night. Then things went really weird this morning ... An autotimer was recorded twice over. :confused:

The second instance of the recording started 1 minute later. Both recordings were complete. Following these recordings the Mut@ant went into Standby again.

Then another autotimer a couple of hours later also recorded a program twice. Again the two recordings were 1 minute apart from each other.

Mickkie
03-08-18, 19:29
I started afresh. Reflashed with the 5.1.032 image, skipped the wizard and manually configured settings, scanned for services, scanned autobouquets, added a few favourites using the web GUI and a couple of autotimers. Then placed it in Deep Standby and waited ... it failed to go back into standby upon waking up for a recording. Comparing with earlier logs of when it was behaving correctly, the difference seems to take place after the timers are checked for conflicts. In the correctly working instance I can see this:

< 32.724> [Timer] Record RecordTimerEntry(name=Newsnight, begin=Fri Aug 10 22:29:00 2018, serviceref=1:0:19:4440:4084:233A:EEEE0000:0:0:0:, justplay=0, isAutoTimer=1)
< 32.737> [TimerSanityCheck] conflict not found!
< 32.737> [Timer] Record RecordTimerEntry(name=Weather for the Week Ahead, begin=Sat Aug 11 00:44:00 2018, serviceref=1:0:19:4484:4084:233A:EEEE0000:0:0:0:, justplay=0, isAutoTimer=1)
< 32.741> [Navigation] RECTIMER: wakeup to standby detected. <==
< 32.742> [ABM-main][AutoBouquetsMakerautostart] AutoStart Enabled
< 32.743> [ABM-main][AutoAutoBouquetsMakerTimer] Schedule Disabled at Fri 03 Aug 2018 11:24:31 BST
< 32.743> [CrossEPG_Auto] AutoStart Enabled
< 32.745> [CrossEPG_Auto] Schedule Disabled at Fri 03 Aug 2018 11:24:31 BST
< 32.746> [EPGImport] autostart (0) occured at 1533291871.88
< 32.746> [EPGImport] WakeUpTime now set to -1 (now=1533291871)
< 32.746> [ImageManager] AutoStart Enabled
< 32.746> [ImageManager] Backup Schedule Disabled at (now=Fri 03 Aug 2018 11:24:31 BST)
< 32.746> [BackupManager] AutoStart Enabled
< 32.746> [BackupManager] Backup Schedule Disabled at (now=Fri 03 Aug 2018 11:24:31 BST)

The above line is missing in the incorrectly behaving occurrence:

< 29.829> [Timer] Record RecordTimerEntry(name=Channel 4 News, begin=Thu Aug 9 18:57:00 2018, servi
ceref=1:0:19:4500:4084:233A:EEEE0000:0:0:0:, justplay=0, isAutoTimer=1)
< 29.831> [TimerSanityCheck] conflict not found!
< 29.832> [Timer] Record RecordTimerEntry(name=Channel 4 News, begin=Fri Aug 10 18:57:00 2018, serviceref=1:0:19:4500:4084:233A:EEEE0000:0:0:0:, justplay=0, isAutoTimer=1)
< 29.835> [ABM-main][AutoBouquetsMakerautostart] AutoStart Enabled
< 29.835> [ABM-main][AutoAutoBouquetsMakerTimer] Schedule Disabled at Fri 03 Aug 2018 18:44:57 BST
< 29.835> [CrossEPG_Auto] AutoStart Enabled
< 29.836> [CrossEPG_Auto] Schedule Disabled at Fri 03 Aug 2018 18:44:57 BST
< 29.836> [EPGImport] autostart (0) occured at 1533318297.12
< 29.836> [EPGImport] WakeUpTime now set to -1 (now=1533318297)
< 29.836> [ImageManager] AutoStart Enabled
< 29.836> [ImageManager] Backup Schedule Disabled at (now=Fri 03 Aug 2018 18:44:57 BST)
< 29.836> [BackupManager] AutoStart Enabled
< 29.836> [BackupManager] Backup Schedule Disabled at (now=Fri 03 Aug 2018 18:44:57 BST)

Other than this difference I can't see anything else standing out between the two log files.

twol
03-08-18, 20:10
I know 0 about timers, but just wondered if you were using NTP or transponder to establish the system time (not that it should make a difference I guess)

Mickkie
04-08-18, 09:43
I know 0 about timers, but just wondered if you were using NTP or transponder to establish the system time (not that it should make a difference I guess)Thanks twol,
The missing log entry "[Navigation] RECTIMER: wakeup to standby detected." is pointing to the mechanism or processes running when the box wakes up from standby. So, something must be amiss with RECTIMER or whatever leads up to it. I have left the system time to sync with the transponder, but can try out an NTP server and see if this makes any difference.

twol
04-08-18, 11:04
Thanks twol,
The missing log entry "[Navigation] RECTIMER: wakeup to standby detected." is pointing to the mechanism or processes running when the box wakes up from standby. So, something must be amiss with RECTIMER or whatever leads up to it. I have left the system time to sync with the transponder, but can try out an NTP server and see if this makes any difference.
Some time ago there were significant changes made to E2 (which Birdman helped to actually work) to resolve system time and thats why I was curious about your use (NTP would avoid any issues in this code)

Mickkie
04-08-18, 18:43
I changed the time setting to sync with NTP and soon discovered that while in Deep Standby the system clock ... stops! So recordings are missed altogether. As soon as I restart the box manually the clock starts again but it won't jump to present time. Consequently, the clock is lagging by how long I left it in Deep Standby. More about this below, but first let me share a recent finding pertinent to the problem at hand:

While experimenting I discovered this behaviour which may be of importance. If I set a timer which is due to start soon, say within the next 10 minutes and place the box in Deep Standby, I get a warning that recordings are imminent. I proceed and place the box in Deep Standby regardless. Well, when it wakes up in a few minutes following such a warning, the box behaves as expected and the "[Navigation] RECTIMER: wakeup to standby detected." is present in the logs. If I set up a timer sometime longer in the future whereby I do not receive a warning when I place it in Deep Standby, the box misbehaves as per my original report.

Regarding the NTP problem, I thought initially the ntp server may be busy so I tried my local router's ntp server using its IP address, then tried 0.pool.ntp.org, 3.uk.pool.ntp.org and all failed to make the box keep up with, or adjust to present time. I haven't noticed such problems when using the transponder to set the system clock. The logs show E2 is obtaining the time from the network NTP server, but it is not drifting to adjust it forward:

< 1854.770> [Console] command: /usr/bin/ntpdate-sync
< 1854.770> [eConsoleAppContainer] Starting /bin/sh
< 1862.919> [Console] finished: /usr/bin/ntpdate-sync
< 1862.920> [NetworkTime] setting E2 time: 1533395566.92
[snip ...]

< 3662.921> [Console] command: /usr/bin/ntpdate-sync
< 3662.921> [eConsoleAppContainer] Starting /bin/sh
< 3671.057> [Console] finished: /usr/bin/ntpdate-sync
< 3671.058> [NetworkTime] setting E2 time: 1533397375.06

but Mut@nt's syslog reports:

Aug 4 18:24:40 mutant51 daemon.err ntpdate[3979]: no server suitable for synchronization found
Aug 4 18:25:16 mutant51 daemon.err ntpdate[4005]: no server suitable for synchronization found
Aug 4 18:26:53 mutant51 daemon.err ntpdate[4064]: no server suitable for synchronization found

despite the fact my router (10.10.10.1) reports synchronisation packets are received from and returned to the Mut@nt (10.10.10.9):

18:30:18: receive: at 5982693 10.10.10.1<-10.10.10.9 VRF: -DEFAULT- flags 1 restrict 000
18:30:18: MRU: interval 101 headway 8 limit 64
18:30:18: receive: at 5982693 10.10.10.1<-10.10.10.9 mode 3/client:AM_FXMIT len 48 org 0000000000.00000000 xmt 0xdf1060c0.2a4c5fc4 NOMAC
18:30:18: sendpkt(38, dst=10.10.10.9, src=10.10.10.1, ttl=0, len=48)
18:30:18: fast_xmit: at 5982693 10.10.10.1->10.10.10.9 mode 4 len 48
18:30:20: receive: at 5982695 10.10.10.1<-10.10.10.9 VRF: -DEFAULT- flags 1 restrict 000
18:30:20: MRU: interval 2 headway 12 limit 64
18:30:20: receive: at 5982695 10.10.10.1<-10.10.10.9 mode 3/client:AM_FXMIT len 48 org 0000000000.00000000 xmt 0xdf1060c2.2a4a9e7d NOMAC
18:30:20: sendpkt(38, dst=10.10.10.9, src=10.10.10.1, ttl=0, len=48)
18:30:20: fast_xmit: at 5982695 10.10.10.1->10.10.10.9 mode 4 len 48
18:30:22: receive: at 5982697 10.10.10.1<-10.10.10.9 VRF: -DEFAULT- flags 1 restrict 000
18:30:22: MRU: interval 2 headway 16 limit 64
18:30:22: receive: at 5982697 10.10.10.1<-10.10.10.9 mode 3/client:AM_FXMIT len 48 org 0000000000.00000000 xmt 0xdf1060c4.2a4a5f16 NOMAC
18:30:22: sendpkt(38, dst=10.10.10.9, src=10.10.10.1, ttl=0, len=48)
18:30:22: fast_xmit: at 5982697 10.10.10.1->10.10.10.9 mode 4 len 48
18:30:24: receive: at 5982699 10.10.10.1<-10.10.10.9 VRF: -DEFAULT- flags 1 restrict 000
18:30:24: MRU: interval 2 headway 20 limit 64
18:30:24: receive: at 5982699 10.10.10.1<-10.10.10.9 mode 3/client:AM_FXMIT len 48 org 0000000000.00000000 xmt 0xdf1060c6.2a4abffe NOMAC
18:30:24: sendpkt(38, dst=10.10.10.9, src=10.10.10.1, ttl=0, len=48)
18:30:24: fast_xmit: at 5982699 10.10.10.1->10.10.10.9 mode 4 len 48

Is this another bug, or is there something missing from my settings?

ccs
04-08-18, 19:08
I'd use transponder time, that's all I've ever used with freeview, and I haven't seen any issues you are now describing.

Mickkie
05-08-18, 13:11
I'd use transponder time, that's all I've ever used with freeview, and I haven't seen any issues you are now describing.
Thanks css, yes, I've returned the setting to transponder since NTP doesn't seem to play well in the current incarnation of the firmware.

Regarding the buggy behaviour I've reported here with waking up from Deep Standby for a recording, not going back into Standby while recording, and not returning to Deep Standby after the recording is finished, I'm curious if other Mut@ant users have not suffered from such symptoms.

Could it be something in my particular hardware causing the problem? I don't know what tests are performed to produce "RECTIMER: wakeup to standby detected" and why these only work when the box was placed in Deep Standby recently. Could it be that these tests and RECTIMER work if the disk is still spinning from the previous cycle, but fail if a potentially sluggish disk has to start spinning from a standstill? Would a 'sleep 2s' instruction to give a chance to the disk to catch up fix my problem?

ccs
05-08-18, 13:55
It won't be anything to do with the disc.

When the box wakes up from deep standby, if there's a recording due within 6 minutes, it assumes it has woken up for a timer recording, rather than you switching it on with the power button.

When you shutdown, it remembers how long to wait before the next timer is due, not the time when it's due.

There is no real time clock running in deep standby.

On some boxes, the wakeup time isn't very accurate, the longer the wait time the more inaccurate it becomes.

There is a startup delay before autotimer runs after a reboot, mine is set to 3 minutes, if you have it set to run immediately it may cause problems.

Mickkie
07-08-18, 18:33
There is a startup delay before autotimer runs after a reboot, mine is set to 3 minutes, if you have it set to run immediately it may cause problems.
I've got mine set to 3 minutes too and changed timeshift to 5 seconds in case it makes a difference. Nothing I've tried works so far. :(

Mickkie
05-09-18, 10:55
Just a thought: Could it be something HDMI CEC related is causing this? Is HDMI CEC enabled on your Mut@nt? Mine is disabled, but I think it always had been.

birdman
05-09-18, 11:29
Could it be something in my particular hardware causing the problem? I don't know what tests are performed to produce "RECTIMER: wakeup to standby detected" and why these only work when the box was placed in Deep Standby recently.ccs has explained the coding logic. If your front-panel clock is running fast* the box will wake up "too early". My MBtwin does this, so it stays on after a recording if there is a gap of more than a few hours since the box shutdown.

*you do not want it to run slow....

Joe_90
05-09-18, 12:17
@Mickkie - I have a Mutant HD51 also and have had ongoing time issues since the implementation of the "fake" HWclock coding back in December last year. Prior to that, I had been using my local NTP server for time setting without an issue. I don't use my Mutant much for timer recording (it's located in a bedroom), but I do have it set to wake from deep standby every afternoon at 5pm to run Autoboquetsmaker and CrossEPG and then shut down again. The time setting changes caused all sorts of issues where the box thought the system time was in the past (due to the fake hwclock setting) and didn't seem to set the correct time from NTP quickly enough, even though the server is on the LAN. @birdman and I thought it was due to my WiFi connection being slow and did all sorts of tweaks to the code and I tested various scenarios at the time. I never did resolve it satisfactorily, except by disabling the fake hwclock. The result is that the logs often are timestamped 1/1/1970, but at least the box gets the correct time after about 25-30 seconds and the various timer checks wait until the date/time is updated from 1/1/1970, so recordings and other power timers work as expected.
Maybe the default setting on a new image flash is to use the fake hwclock? I don't know at this stage as I have disabled it and I generally just run software updates rather than fresh image flashes.
As @ccs has indicated, there is no actual real-time clock in the Mutant. Similar to most of the boxes, the front panel is just given a countdown timer to the next wake-up event, so it just "ticks" away so many seconds and restarts. I found the Mutant front panel timer to be very accurate, though. It will wake up on time even days later. My MBTwin used to run fast (like @birdman's) but I got a firmware update which fixed the tick speed, but unfortunately messed up the display and caused other issues, because it was for another, slightly different, front panel.

Mickkie
12-10-18, 17:35
@Mickkie - I have a Mutant HD51 also and have had ongoing time issues since the implementation of the "fake" HWclock coding back in December last year. Prior to that, I had been using my local NTP server for time setting without an issue.I bought my Mut@nt HD51 before the HWclock coding change and it worked fine then. Some changes, which assume they had to do with this "fake" HWclock coding have caused this problem. I don't know/understand what was changed or why it was changed in the code, but clearly it has broken some of the desired functionality of this box. Is it possible (and advisable) to reverse this change?