Beta [Real-time scheduling] schedule without rebooting

Status
Not open for further replies.
4ndy said:
I had a runaway recording overnight. Bram Stoker's Dracula on Film4. What diagnostics should I post?
Click to expand...
Any details on the sequence of events leading up to this would be useful. I know that's a bit vague but I'm searching for a way of making this happen at will so I can work out what is going on. I have RTS enabled on my main PVR but that powers down quite often between recordings and watching things which resets the schedule. Presumably your box hadn't been shut down in a while?

I should have more time to look at this next week.
 
Last edited:
I don't use the logs usually, so you will need to advise me where best to look when I get home please.

From memory, we were definately watching Strictly Come Dancing on chase play when the film started if that helps. Nothing else out of the ordinary.

Though when I looked at the log on RS next morning to see what programmes had been skipped as a consequence Bram Stokers Dracula was not listed as recorded.

Sent from my SM-G930F using Tapatalk
 
I used RTS to schedule series recording of Go 8-Bit, but only after the first programme had started. The SUI wouldn't have accepted it, but RTS was happy enough - and then I found that the first programme had started recording immediately (and the next programme is queued).
 
Black Hole said:
I used RTS to schedule series recording of Go 8-Bit, but only after the first programme had started. The SUI wouldn't have accepted it, but RTS was happy enough - and then I found that the first programme had started recording immediately (and the next programme is queued).
Click to expand...
Sometimes it seems to start recording in progress programmes and sometimes it doesn't. I think but am not certain that runaway recordings may be associated with recordings starting midway so it would be worth keeping on eye on those recordings.

See https://hummy.tv/forum/threads/real...ithout-rebooting-beta.7322/page-5#post-100219 though that was with an earlier version of the package
 
Last edited:
MymsMan said:
Sometimes it seems to start recording in progress programmes and sometimes it doesn't. I think but am not certain that runaway recordings may be associated with recordings starting midway so it would be worth keeping on eye on those recordings.
Click to expand...
That's interesting and gives me something to try for the next version.. I already have one waiting which fixes a couple of small memory leaks so I'll make some more changes around this area. I want to improve logging too so that I can write a diagnostic to easily display the sequence of events in time order..
 
af123 said:
That's interesting and gives me something to try for the next version.. I already have one waiting which fixes a couple of small memory leaks so I'll make some more changes around this area. I want to improve logging too so that I can write a diagnostic to easily display the sequence of events in time order..
Click to expand...
I haven't experienced experienced any runaway recordings with the latest version of the packages even when recordings start in mid-programme or whilst another recording is in progress so good news (except when trying to reproduce an obscure bug!)
 
Updated packages are on their way up to the repository now - nugget 0.96 in particular as far as this thread is concerned.

Once you've upgraded (and rebooted), log files created by rsvsync will now be persistent rather than being deleted on reboot and a new diagnostic (rts.logs) will pull together log entries from several logs and display them in date order. This should make it easier to investigate any problems that people see.

As before, please test and let me know of any problems or unexpected results you see, thanks!
 
af123 said:
Once you've upgraded (and rebooted), log files created by rsvsync will now be persistent rather than being deleted on reboot and a new diagnostic (rts.logs) will pull together log entries from several logs and display them in date order. This should make it easier to investigate any problems that people see.
Click to expand...
I use autoupdate so the new packages were installed overnight. Using RS this morning I scheduled two entries which worked perfectly however no rts.log appeared. Did a restart but still not there.
Have I missed something ?
 
peterworks said:
I use autoupdate so the new packages were installed overnight. Using RS this morning I scheduled two entries which worked perfectly however no rts.log appeared. Did a restart but still not there.
Have I missed something ?
Click to expand...
rts.log is a diagnostic that you run from the diagnostics page. It should show up in the drop-down list too.
It collates recent-ish entries from activity.log, nugget.log, rsvsync.log and redring.log, sorts them by date then displays them together. It makes it easier to see what happened in which order.
 
af123 said:
rts.log is a diagnostic that you run from the diagnostics page. It should show up in the drop-down list too.
It collates recent-ish entries from activity.log, nugget.log, rsvsync.log and redring.log, sorts them by date then displays them together. It makes it easier to see what happened in which order.
Click to expand...
Thanks - must read posts more closely next time. I assume the output is on the fly and is not saved anywhere
 
I have just experienced my first run-on recording for a while :(
I ran the rts.logs diag but it generated 2400 lines of output dating back to Aug 23 so I cut it down to today for posting.
Code: 
[RR] Mon Sep 12 00:04:56 2016: Standby ring dim detected.
[RR] Mon Sep 12 00:04:56 2016:   Setting LED level.
[RR] Mon Sep 12 00:04:56 2016:   Setting LED level.
[RR] Mon Sep 12 00:04:56 2016: Standby ring dim detected.
[RR] Mon Sep 12 00:04:56 2016: Ring trying to go amber.
[RR] Mon Sep 12 00:04:56 2016:   Changing to dim blue.
[RR] Mon Sep 12 00:04:56 2016: Standby VFD dim detected, overriding.
[RR] Mon Sep 12 00:04:58 2016:   Setting LED level.
[RR] Mon Sep 12 00:04:58 2016: Standby ring dim detected.
Mon Sep 12 04:17:09 2016: Opening /var/lib/humaxtv/rsvp.db
Mon Sep 12 04:17:09 2016: Restoring any favourites.
Mon Sep 12 04:17:09 2016: Ignoring: no such table: fav (no such table: fav)
Mon Sep 12 04:17:09 2016: Final schedule entries: 61
Mon Sep 12 04:17:09 2016: Slots:
Mon Sep 12 04:17:09 2016: rsvsync starting.
12/09/2016 04:17:41 - System booted (Scheduled event).
[RR] Mon Sep 12 04:20:00 2016: Persistent log starting, v2.17
[RR] Mon Sep 12 04:20:00 2016: Ring going blue, full boot.
[RR] Mon Sep 12 04:40:02 2016:   Setting LED level.
[RR] Mon Sep 12 04:40:02 2016: Standby ring dim detected.
[RR] Mon Sep 12 04:40:02 2016:   Setting LED level.
[RR] Mon Sep 12 04:40:02 2016:   Changing to dim blue.
[RR] Mon Sep 12 04:40:02 2016: Ring trying to go amber.
[RR] Mon Sep 12 04:40:02 2016: Standby ring dim detected.
[RR] Mon Sep 12 04:40:02 2016: Standby VFD dim detected, overriding.
[RR] Mon Sep 12 04:40:04 2016:   Setting LED level.
[RR] Mon Sep 12 04:40:04 2016: Standby ring dim detected.
Mon Sep 12 09:42:09 2016: Opening /var/lib/humaxtv/rsvp.db
Mon Sep 12 09:42:09 2016: rsvsync starting.
Mon Sep 12 09:42:09 2016: Slots:
Mon Sep 12 09:42:09 2016: Ignoring: no such table: fav (no such table: fav)
Mon Sep 12 09:42:09 2016: Restoring any favourites.
Mon Sep 12 09:42:09 2016: Final schedule entries: 61
12/09/2016 09:42:38 - System booted (Scheduled event).
[RR] Mon Sep 12 09:59:20 2016: Persistent log starting, v2.17
[RR] Mon Sep 12 09:59:20 2016: Ring going blue, full boot.
[RR] Mon Sep 12 10:00:08 2016:    Recording 1
[RR] Mon Sep 12 10:00:08 2016: Ring going red.
[RR] Mon Sep 12 10:00:08 2016: REC icon on.
[RR] Mon Sep 12 10:00:08 2016: Recording start 34:'/mnt/hd2/My Video/Deal Or No Deal/Deal Or No Deal_20160912_1000.nts'
[RR] Mon Sep 12 10:45:02 2016: REC icon off.
[RR] Mon Sep 12 10:45:03 2016: Recording end 34.
12/09/2016 10:45:08 - Recorded: Deal Or No Deal/Deal Or No Deal (44 minutes - Challenge)
[RR] Mon Sep 12 10:45:21 2016: Recording start 47:'/mnt/hd2/My Video/Deal Or No Deal/Deal Or No Deal_20160912_1045.nts'
[RR] Mon Sep 12 10:45:21 2016:    Recording 1
[RR] Mon Sep 12 10:45:22 2016: REC icon on.
[RR] Mon Sep 12 10:45:22 2016: Ring going red.
[RR] Mon Sep 12 11:30:02 2016: REC icon off.
[RR] Mon Sep 12 11:30:03 2016: Recording end 47.
12/09/2016 11:30:09 - Recorded: Deal Or No Deal/Deal Or No Deal (44 minutes - Challenge)
[RR] Mon Sep 12 14:14:32 2016:    Recording 1
[RR] Mon Sep 12 14:14:32 2016: Recording start 30:'/mnt/hd2/My Video/Think Tank/Think Tank_20160912_1414.nts'
[RR] Mon Sep 12 14:14:32 2016: REC icon on.
[RR] Mon Sep 12 14:14:32 2016: Ring going red.
[RR] Mon Sep 12 14:59:26 2016: Recording end 30.
[RR] Mon Sep 12 14:59:26 2016: REC icon off.
12/09/2016 14:59:32 - Recorded: Think Tank/Think Tank (44 minutes - BBC ONE South)
[RR] Mon Sep 12 16:59:41 2016: REC icon on.
[RR] Mon Sep 12 16:59:41 2016: Recording start 25:'/mnt/hd2/My Video/The Chase/New_ The Chase_20160912_1659.nts'
[RR] Mon Sep 12 16:59:41 2016: Ring going red.
[RR] Mon Sep 12 16:59:41 2016:    Recording 1
[RR] Mon Sep 12 17:15:06 2016:    Recording 2
[RR] Mon Sep 12 17:15:06 2016:    Changing to purple.
[RR] Mon Sep 12 17:15:06 2016: Recording start 47:'/mnt/hd2/My Video/Pointless/Pointless_20160912_1715.nts'
[RR] Mon Sep 12 17:59:26 2016:    Changing to red.
[RR] Mon Sep 12 17:59:26 2016: Recording end 25.
12/09/2016 17:59:32 - Recorded: The Chase/New: The Chase (59 minutes - ITV)
[RR] Mon Sep 12 17:59:55 2016: REC icon off.
[RR] Mon Sep 12 17:59:55 2016: Recording end 47.
12/09/2016 18:00:01 - Recorded: Pointless/Pointless (44 minutes - BBC ONE South)
[RR] Mon Sep 12 18:00:58 2016: Recording start 31:'/mnt/hd2/My Video/Debatable/Debatable_20160912_1800.nts'
[RR] Mon Sep 12 18:00:58 2016:    Recording 1
[RR] Mon Sep 12 18:00:59 2016: REC icon on.
[RR] Mon Sep 12 18:00:59 2016: Ring going red.
[RR] Mon Sep 12 18:29:28 2016:    Changing to purple.
[RR] Mon Sep 12 18:29:28 2016:    Recording 2
[RR] Mon Sep 12 18:29:28 2016: Recording start 25:'/mnt/hd2/My Video/South Today/South Today_20160912_1829.nts'
[RR] Mon Sep 12 18:30:52 2016: Recording end 31.
[RR] Mon Sep 12 18:30:52 2016:    Changing to red.
[RR] Mon Sep 12 18:30:54 2016:    Recording 2
[RR] Mon Sep 12 18:30:54 2016: Recording start 33:'/mnt/hd2/My Video/Make Me an Egghead/Make Me an Egghead_20160912_1830.nts'
[RR] Mon Sep 12 18:30:54 2016:    Changing to purple.
12/09/2016 18:30:58 - Recorded: Debatable/Debatable (29 minutes - BBC TWO)
[RR] Mon Sep 12 18:58:31 2016: Recording end 25.
[RR] Mon Sep 12 18:58:31 2016:    Changing to red.
12/09/2016 18:58:37 - Recorded: South Today/South Today (29 minutes - BBC ONE South)
[RR] Mon Sep 12 19:00:45 2016: Recording end 33.
[RR] Mon Sep 12 19:00:45 2016: REC icon off.
12/09/2016 19:00:52 - Recorded: Make Me an Egghead/Make Me an Egghead (29 minutes - BBC TWO)
[RR] Mon Sep 12 20:01:18 2016: REC icon on.
[RR] Mon Sep 12 20:01:18 2016: Ring going red.
[RR] Mon Sep 12 20:01:18 2016: Recording start 32:'/mnt/hd2/My Video/University Challenge/University Challenge_20160912_2001.nts'
[RR] Mon Sep 12 20:01:18 2016:    Recording 1
[RR] Mon Sep 12 20:31:38 2016: REC icon off.
[RR] Mon Sep 12 20:31:38 2016: Recording end 32.
[RR] Mon Sep 12 20:31:38 2016:    Recording 1
[RR] Mon Sep 12 20:31:38 2016: Ring going red.
[RR] Mon Sep 12 20:31:38 2016: REC icon on.
[RR] Mon Sep 12 20:31:38 2016: Recording start 31:'/mnt/hd2/My Video/Only Connect/Only Connect_20160912_2031.nts'
12/09/2016 20:31:44 - Recorded: University Challenge/University Challenge (30 minutes - BBC TWO)
[RR] Mon Sep 12 21:01:46 2016: Recording end 31.
[RR] Mon Sep 12 21:01:46 2016: REC icon off.
[RR] Mon Sep 12 21:01:48 2016: REC icon on.
[RR] Mon Sep 12 21:01:48 2016: Ring going red.
[RR] Mon Sep 12 21:01:48 2016:    Recording 1
[RR] Mon Sep 12 21:01:48 2016: Recording start 31:'/mnt/hd2/My Video/Ripper Street/Ripper Street_20160912_2101.nts'
12/09/2016 21:01:52 - Recorded: Only Connect/Only Connect (30 minutes - BBC TWO)
[RR] Mon Sep 12 22:00:02 2016:    Recording 2
[RR] Mon Sep 12 22:00:02 2016: Recording start 32:'/mnt/hd2/My Video/BBC News at Ten/BBC News at Ten_20160912_2200.nts'
[RR] Mon Sep 12 22:00:02 2016:    Changing to purple.
[RR] Mon Sep 12 22:01:51 2016: Play icon on.
[RR] Mon Sep 12 22:02:21 2016: Recording end 31.
[RR] Mon Sep 12 22:02:21 2016:    Changing to red.
12/09/2016 22:02:27 - Recorded: Ripper Street/Ripper Street (60 minutes - BBC TWO)
[nugget]: Mon Sep 12 22:19:06 2016: Last Error: 5 (ff)
[nugget]: Mon Sep 12 22:19:06 2016: Magic: 0xa029a697 (open)
Mon Sep 12 22:19:06 2016: Slots: +41
Mon Sep 12 22:19:06 2016: Schedule saved.
Mon Sep 12 22:19:06 2016: Opening /var/lib/humaxtv/rsvp.db
Mon Sep 12 22:19:06 2016: Moving pending entry 0 to spare slot 41
12/09/2016 22:19:06 - Scheduled The Jonathan Ross Show @ 1473716700
Mon Sep 12 22:19:06 2016: Final schedule entries: 62
Mon Sep 12 22:19:06 2016: Loading schedule information to HumaxTV binary.
[nugget]: Mon Sep 12 22:19:06 2016: Schedule load failed.
[nugget]: Mon Sep 12 22:19:06 2016: Deferred thread starting for '62:+41' (attempt 1)
Mon Sep 12 22:19:06 2016: Real-time mode.
Mon Sep 12 22:19:06 2016: Nugget is available.
[nugget]: Mon Sep 12 22:19:06 2016: Persistent log starting, v0.96
[nugget]: Mon Sep 12 22:19:06 2016: schedule save starting.
[nugget]: Mon Sep 12 22:19:06 2016: schedule save complete.
[nugget]: Mon Sep 12 22:19:06 2016: Re-loading schedule database (62).
[nugget]: Mon Sep 12 22:19:06 2016: schedule.stash 22 = 2
[nugget]: Mon Sep 12 22:19:06 2016: schedule.stash 21 = 1
[nugget]: Mon Sep 12 22:19:06 2016: Closing database.
[nugget]: Mon Sep 12 22:19:06 2016: Flags: 0x100800
[nugget]: Mon Sep 12 22:19:06 2016: Closing db handle due to error.
[nugget]: Mon Sep 12 22:19:06 2016: Schedule failed to reload, deferring.
Mon Sep 12 22:19:06 2016: rsvsync starting.
[nugget]: Mon Sep 12 22:19:11 2016: Re-loading schedule database (62).
[nugget]: Mon Sep 12 22:19:11 2016: schedule reload complete (62).
[nugget]: Mon Sep 12 22:19:11 2016: schedule.restore 22 = 2
[nugget]: Mon Sep 12 22:19:11 2016: schedule.restore 21 = 1
[nugget]: Mon Sep 12 22:19:11 2016: slots(62, +41)
[nugget]: Mon Sep 12 22:19:11 2016: Processing slot +41 (41)
[nugget]: Mon Sep 12 22:19:11 2016:   The Jonathan Ross Show
[nugget]: Mon Sep 12 22:19:11 2016:    @ 1473716700 (Mon Sep 12 22:45:00 2016)
[nugget]: Mon Sep 12 22:19:11 2016:   CRID: 2/[WWW.ITV.COM/225465359]
[nugget]: Mon Sep 12 22:19:11 2016:  [0] 262240,1473716700,1473720300,11518
[nugget]: Mon Sep 12 22:19:11 2016:   Recorded:
[nugget]: Mon Sep 12 22:19:11 2016:   Last Event: 0
[nugget]: Mon Sep 12 22:19:11 2016:   Events: 1WWW.ITV.COM/224664605|1WWW.ITV.COM/225539288|
[nugget]: Mon Sep 12 22:19:11 2016:  Wake 1473715800 - Mon Sep 12 22:30:00 2016
[nugget]: Mon Sep 12 22:19:11 2016:       Mon Sep 12 22:45:00 2016 +60m
[nugget]: Mon Sep 12 22:19:11 2016:  [1] 262240,1474321500,1474325400,11522
[nugget]: Mon Sep 12 22:19:11 2016:       Mon Sep 19 22:45:00 2016 +65m
[nugget]: Mon Sep 12 22:19:11 2016: Deferred thread exiting.
[nugget]: Mon Sep 12 22:19:11 2016: Ready 1473715770 - Mon Sep 12 22:29:30 2016
[nugget]: Mon Sep 12 22:19:11 2016: Adding timer(1473715770)
[nugget]: Mon Sep 12 22:19:11 2016:     - Mon Sep 12 22:29:30 2016
[RR] Mon Sep 12 22:45:37 2016:    Recording 2
[RR] Mon Sep 12 22:45:37 2016: Recording start 33:'/mnt/hd2/My Video/The Jonathan Ross Show/The Jonathan Ross Show_20160912_2245.nts'
[RR] Mon Sep 12 22:45:37 2016:    Changing to purple.
[RR] Mon Sep 12 22:46:02 2016: Play icon off.
[RR] Mon Sep 12 22:50:05 2016: Play icon on.
[RR] Mon Sep 12 23:34:58 2016: Play icon off.
[RR] Mon Sep 12 23:35:53 2016: Play icon on.
[RR] Mon Sep 12 23:37:20 2016: Play icon off.
[RR] Mon Sep 12 23:37:33 2016: Recording end 32.
[RR] Mon Sep 12 23:37:33 2016:    Changing to red.
[RR] Mon Sep 12 23:37:34 2016: Recording start 48:'/mnt/hd2/My Video/Have I Got a Bit More Old News for You/Have I Got a Bit More Old News for You_20160912_2337.nts'
[RR] Mon Sep 12 23:37:34 2016:    Recording 2
[RR] Mon Sep 12 23:37:34 2016:    Changing to purple.
12/09/2016 23:37:39 - Recorded: BBC News at Ten/BBC News at Ten (97 minutes - BBC ONE South)
[RR] Mon Sep 12 23:49:16 2016: Recording end 33.
[RR] Mon Sep 12 23:49:16 2016:    Changing to red.
12/09/2016 23:49:27 - Recorded: The Jonathan Ross Show/The Jonathan Ross Show (63 minutes - ITV)

I was watching BBC News whilst it was recording when I scheduled Jonathan Ross to record via web-if.
Jonathan Ross recorded normally and terminated correctly but the News continued to record for 97 minutes.
I got onscreen recording conflicts messages for South Today and Have I News for you on BBC1, when I stopped the News recording the HIGNFY recording then started and finished normally.

I had earlier used RS to skip next Sundays Countryfile but that still shows as queued on the RS server and has not been moved to the Humax yet (the Humax has been seen by RS recently)

Hope this helps
 
MymsMan said:
Hope this helps
Click to expand...
Thanks for the comprehensive report - exactly the level of detail I need to try and find this bug.

[nugget]: Mon Sep 12 22:19:06 2016: schedule.stash 21 = 1
Click to expand...

This is interesting. It means that whatever is in schedule slot 21 was either in the ready state (30 second lead-in) or was actively watching for an AR signal. HIGNFY presumably.
 
af123 said:
Thanks for the comprehensive report - exactly the level of detail I need to try and find this bug.



This is interesting. It means that whatever is in schedule slot 21 was either in the ready state (30 second lead-in) or was actively watching for an AR signal. HIGNFY presumably.
Click to expand...
HIGNFY wasn't until 23:35 last night, but the local news, South Today, was due to start at 22:30 and occupies slot 21 so was waiting for AR

From the timer list:
Code: 
21     South Today     3     0/0 (idle)     1473802200     AR     1473801270 - Tue Sep 13 22:14:30 BST 2016     45555 (12:39:15)
 
af123 said:
and didn't record? At least, I can't see it in the log.
Click to expand...

As I mentioned earlier
I got onscreen recording conflicts messages for South Today and Have I News for you on BBC1, when I stopped the News recording the HIGNFY recording then started and finished normally.
Click to expand...
I have a failed 'due to higher priority recording' hmt for South Today but it is recorded as part of the runon recording.

BTW the Humax did not shutdown fully last night, I think I remembered to hit the power button on the remote but without any logging during normal shutdown it is difficult to tell when/if the box was switched off, so my skip episode request is still stuck on the RS queue.
 
MymsMan said:
BTW the Humax did not shutdown fully last night, I think I remembered to hit the power button on the remote but without any logging during normal shutdown it is difficult to tell when/if the box was switched off, so my skip episode request is still stuck on the RS queue.
Click to expand...
I tried shutting the machine down again and it is stuck in half awake state.

It is not clear whether the half-awake state is the result of the run on recording, part of the cause for the run on recording or an unrelated coincidence
 
I have not had a runaway recording recently but when I did it left the unit in a state where it would not fully shut down and remained in the half awake state. If you don't want to use the rear power switch, booting into maintenance mode and back allowed it to shut down: a normal reboot was not enough.
 
I had a runaway recording last night with "Sexy Beast" on Film 4 @ 22:48. The recording was still in progress when I switched on the TV this afternoon.
The only thing different than all previous recordings was that;

1. The on-box Media- Video page was open the whole time during the recording. Was watching TV using the TV's tuner as I had two recordings on the go at one point.
2. On exiting the media list, the channel was on BBC RB 1. I use the POC Package and normally the channel wakes on BBC 1

Runaway.png

Rts.log

Code: 
13/09/2016 21:01:43 - Recorded: New_ Deadliest Pests Down Under/New: Deadliest Pests Down Under (28 minutes - Dave)
13/09/2016 23:06:02 - Recorded: Inside Man/Inside Man (61 minutes - ITV4)
Tue Sep 13 23:57:03 2016: Real-time mode.
Tue Sep 13 23:57:03 2016: rsvsync starting.
[nugget]: Tue Sep 13 23:57:03 2016: Magic: 0xa029a697 (open)
[nugget]: Tue Sep 13 23:57:03 2016: Schedule failed to reload, deferring.
[nugget]: Tue Sep 13 23:57:03 2016: Deferred thread starting for '23:+16' (attempt 1)
[nugget]: Tue Sep 13 23:57:03 2016: Flags: 0x100800
[nugget]: Tue Sep 13 23:57:03 2016: Closing db handle due to error.
[nugget]: Tue Sep 13 23:57:03 2016: schedule save starting.
[nugget]: Tue Sep 13 23:57:03 2016: schedule save complete.
[nugget]: Tue Sep 13 23:57:03 2016: Re-loading schedule database (23).
[nugget]: Tue Sep 13 23:57:03 2016: schedule.stash 23 = 2
Tue Sep 13 23:57:03 2016: Nugget is available.
Tue Sep 13 23:57:03 2016: Schedule saved.
Tue Sep 13 23:57:03 2016: Opening /var/lib/humaxtv/rsvp.db
Tue Sep 13 23:57:03 2016: Moving pending entry 0 to spare slot 16
Tue Sep 13 23:57:03 2016: Slots: +16
Tue Sep 13 23:57:03 2016: Final schedule entries: 23
Tue Sep 13 23:57:03 2016: Loading schedule information to HumaxTV binary.
[nugget]: Tue Sep 13 23:57:03 2016: Schedule load failed.
[nugget]: Tue Sep 13 23:57:03 2016: Last Error: 5 (ff)
[nugget]: Tue Sep 13 23:57:03 2016: schedule.stash 24 = 2
[nugget]: Tue Sep 13 23:57:03 2016: Closing database.
13/09/2016 23:57:03 - Scheduled Harry Brown @ 1473973500
[nugget]: Tue Sep 13 23:57:08 2016: Re-loading schedule database (23).
[nugget]: Tue Sep 13 23:57:08 2016: schedule reload complete (23).
[nugget]: Tue Sep 13 23:57:08 2016: schedule.restore 24 = 2
[nugget]: Tue Sep 13 23:57:08 2016: slots(23, +16)
[nugget]: Tue Sep 13 23:57:08 2016: Processing slot +16 (16)
[nugget]: Tue Sep 13 23:57:08 2016: schedule.restore 23 = 2
[nugget]: Tue Sep 13 23:57:08 2016:   Events: 1WWW.FIVE.TV/V5UEX#1|1WWW.FIVE.TV/V5UEX#1|
[nugget]: Tue Sep 13 23:57:08 2016:  [0] 196639,1473973500,1473977100,11151
[nugget]: Tue Sep 13 23:57:08 2016:       Thu Sep 15 22:05:00 2016 +60m
[nugget]: Tue Sep 13 23:57:08 2016:  Wake 1473972600 - Thu Sep 15 21:50:00 2016
[nugget]: Tue Sep 13 23:57:08 2016: Ready 1473972570 - Thu Sep 15 21:49:30 2016
[nugget]: Tue Sep 13 23:57:08 2016: Adding timer(1473972570)
[nugget]: Tue Sep 13 23:57:08 2016:     - Thu Sep 15 21:49:30 2016
[nugget]: Tue Sep 13 23:57:08 2016: Deferred thread exiting.
[nugget]: Tue Sep 13 23:57:08 2016:   Harry Brown
[nugget]: Tue Sep 13 23:57:08 2016:    @ 1473973500 (Thu Sep 15 22:05:00 2016)
[nugget]: Tue Sep 13 23:57:08 2016:   CRID: 1/[WWW.FIVE.TV/V5UEX]
[nugget]: Tue Sep 13 23:57:08 2016:   Recorded:
[nugget]: Tue Sep 13 23:57:08 2016:   Last Event: 0
14/09/2016 00:34:25 - Recorded: Inside Man/Inside Man (87 minutes - ITV4)
14/09/2016 00:57:34 - Recorded: Drugs Map of Britain/Drugs Map of Britain (17 minutes - BBC ONE Scot)
14/09/2016 11:45:45 - Recorded: Dom on the Spot/Dom on the Spot (44 minutes - BBC ONE Scot)
14/09/2016 12:45:13 - Recorded: /Sexy Beast (836 minutes - Film4)


>>> Ending diagnostic rts.logs
 
Last edited:
Hi Folks

Have had some oddities with manual reservations today. I have a couple of reminders set up so the Humax will wake up and talk to the Remote Schedule server during the day. I decided to delete one (from Web-If) and re-create it so I could change the 'Event Title'. Now every time I try to re-create the event from Web-If it says "Duplicate Reservation" even if I change the time from 11:20-11:40 to 11:15-11:45. I can create the event from the Humax interface, i.e. Guide-Yellow-New Reservation.
 
Had a further run-away recording of chain reaction this evening on Movie Mix, start 21:00 - 23:10. I manually stopped the recording at 00:29 Hrs.
Like my previous post, I had 2 recordings on the go when the over-run occured. It may have no bearing but the second film (Wrong Turn on 5Star) was a split recording, (22:40 - 23:40 / 23:45 - 00:20).

Code: 
23/09/2016 19:30:03 - Recorded: /Make Me an Egghead (44 minutes - BBC TWO Scot)
23/09/2016 20:29:36 - Recorded: EastEnders/EastEnders (29 minutes - BBC ONE Scot)
23/09/2016 22:00:03 - Recorded: /New: Ink Master (31 minutes - truTV)
23/09/2016 22:27:13 - Scheduled New: Ink Master @ 1475265600
[nugget]: Fri Sep 23 22:27:13 2016: Persistent log starting, v0.96
[nugget]: Fri Sep 23 22:27:13 2016: schedule save complete.
[nugget]: Fri Sep 23 22:27:13 2016: Re-loading schedule database (27).
[nugget]: Fri Sep 23 22:27:13 2016: schedule.stash 13 = 2
[nugget]: Fri Sep 23 22:27:13 2016: schedule save starting.
[nugget]: Fri Sep 23 22:27:13 2016: schedule.stash 26 = 1
[nugget]: Fri Sep 23 22:27:13 2016: Closing database.
[nugget]: Fri Sep 23 22:27:13 2016: Schedule load failed.
Fri Sep 23 22:27:13 2016: Loading schedule information to HumaxTV binary.
Fri Sep 23 22:27:13 2016: rsvsync starting.
Fri Sep 23 22:27:13 2016: Real-time mode.
Fri Sep 23 22:27:13 2016: Nugget is available.
Fri Sep 23 22:27:13 2016: Schedule saved.
Fri Sep 23 22:27:13 2016: Opening /var/lib/humaxtv/rsvp.db
Fri Sep 23 22:27:13 2016: Moving pending entry 0 to spare slot 19
Fri Sep 23 22:27:13 2016: Slots: +19
Fri Sep 23 22:27:13 2016: Final schedule entries: 27
[nugget]: Fri Sep 23 22:27:13 2016: Last Error: 5 (ff)
[nugget]: Fri Sep 23 22:27:13 2016: Magic: 0xa029a697 (open)
[nugget]: Fri Sep 23 22:27:13 2016: Flags: 0x100800
[nugget]: Fri Sep 23 22:27:13 2016: Closing db handle due to error.
[nugget]: Fri Sep 23 22:27:13 2016: Schedule failed to reload, deferring.
[nugget]: Fri Sep 23 22:27:13 2016: Deferred thread starting for '27:+19' (attempt 1)
[nugget]: Fri Sep 23 22:27:18 2016:   New: Ink Master
[nugget]: Fri Sep 23 22:27:18 2016:    @ 1475265600 (Fri Sep 30 21:00:00 2016)
[nugget]: Fri Sep 23 22:27:18 2016: Deferred thread exiting.
[nugget]: Fri Sep 23 22:27:18 2016: Processing slot +19 (19)
[nugget]: Fri Sep 23 22:27:18 2016:  Wake 1475264700 - Fri Sep 30 20:45:00 2016
[nugget]: Fri Sep 23 22:27:18 2016: Ready 1475264670 - Fri Sep 30 20:44:30 2016
[nugget]: Fri Sep 23 22:27:18 2016: Adding timer(1475264670)
[nugget]: Fri Sep 23 22:27:18 2016:     - Fri Sep 30 20:44:30 2016
[nugget]: Fri Sep 23 22:27:18 2016: slots(27, +19)
[nugget]: Fri Sep 23 22:27:18 2016:   Last Event: 50517
[nugget]: Fri Sep 23 22:27:18 2016:   Events: 1WWW.TURNER.COM/407011|
[nugget]: Fri Sep 23 22:27:18 2016:   CRID: 2/[WWW.TURNER.COM/27458]
[nugget]: Fri Sep 23 22:27:18 2016:   Recorded:
[nugget]: Fri Sep 23 22:27:18 2016: Re-loading schedule database (27).
[nugget]: Fri Sep 23 22:27:18 2016: schedule reload complete (27).
[nugget]: Fri Sep 23 22:27:18 2016:  [0] 327782,1475265600,1475269200,50747
[nugget]: Fri Sep 23 22:27:18 2016:       Fri Sep 30 21:00:00 2016 +60m
[nugget]: Fri Sep 23 22:27:18 2016: schedule.restore 13 = 2
[nugget]: Fri Sep 23 22:27:18 2016: schedule.restore 26 = 1
[nugget]: Fri Sep 23 22:30:06 2016: schedule save complete.
[nugget]: Fri Sep 23 22:30:06 2016: Re-loading schedule database (28).
[nugget]: Fri Sep 23 22:30:06 2016: schedule save starting.
Fri Sep 23 22:30:06 2016: rsvsync starting.
Fri Sep 23 22:30:06 2016: Real-time mode.
Fri Sep 23 22:30:06 2016: Nugget is available.
[nugget]: Fri Sep 23 22:30:06 2016: schedule.stash 13 = 2
[nugget]: Fri Sep 23 22:30:06 2016: schedule.stash 26 = 1
[nugget]: Fri Sep 23 22:30:06 2016: Closing database.
[nugget]: Fri Sep 23 22:30:06 2016: Schedule load failed.
[nugget]: Fri Sep 23 22:30:06 2016: Last Error: 5 (ff)
[nugget]: Fri Sep 23 22:30:06 2016: Magic: 0xa029a697 (open)
[nugget]: Fri Sep 23 22:30:06 2016: Flags: 0x100800
[nugget]: Fri Sep 23 22:30:06 2016: Closing db handle due to error.
[nugget]: Fri Sep 23 22:30:06 2016: Schedule failed to reload, deferring.
23/09/2016 22:30:06 - Scheduled New: Ink Master Redemption @ 1475269200
[nugget]: Fri Sep 23 22:30:06 2016: Deferred thread starting for '28:+22' (attempt 1)
Fri Sep 23 22:30:06 2016: Moving pending entry 0 to spare slot 22
Fri Sep 23 22:30:06 2016: Slots: +22
Fri Sep 23 22:30:06 2016: Schedule saved.
Fri Sep 23 22:30:06 2016: Opening /var/lib/humaxtv/rsvp.db
Fri Sep 23 22:30:06 2016: Final schedule entries: 28
Fri Sep 23 22:30:06 2016: Loading schedule information to HumaxTV binary.
[nugget]: Fri Sep 23 22:30:11 2016: Re-loading schedule database (28).
[nugget]: Fri Sep 23 22:30:12 2016: schedule reload complete (28).
[nugget]: Fri Sep 23 22:30:12 2016: Cannot set EPG, missing CRID.
[nugget]: Fri Sep 23 22:30:12 2016:  Wake 1475268300 - Fri Sep 30 21:45:00 2016
[nugget]: Fri Sep 23 22:30:12 2016: Ready 1475268270 - Fri Sep 30 21:44:30 2016
[nugget]: Fri Sep 23 22:30:12 2016: Adding timer(1475268270)
[nugget]: Fri Sep 23 22:30:12 2016:     - Fri Sep 30 21:44:30 2016
[nugget]: Fri Sep 23 22:30:12 2016: Deferred thread exiting.
[nugget]: Fri Sep 23 22:30:12 2016: Processing slot +22 (22)
[nugget]: Fri Sep 23 22:30:12 2016: schedule.restore 13 = 2
[nugget]: Fri Sep 23 22:30:12 2016: schedule.restore 26 = 1
[nugget]: Fri Sep 23 22:30:12 2016: slots(28, +22)
[nugget]: Fri Sep 23 22:30:12 2016:   New: Ink Master Redemption
[nugget]: Fri Sep 23 22:30:12 2016:    @ 1475269200 (Fri Sep 30 22:00:00 2016)
[nugget]: Fri Sep 23 22:30:31 2016: schedule save starting.
Fri Sep 23 22:30:31 2016: rsvsync starting.
Fri Sep 23 22:30:31 2016: Real-time mode.
Fri Sep 23 22:30:31 2016: Nugget is available.
Fri Sep 23 22:30:31 2016: Schedule saved.
23/09/2016 22:30:31 - Scheduled Ink Master Redemption @ 1474932600
Fri Sep 23 22:30:31 2016: Moving pending entry 0 to spare slot 23
[nugget]: Fri Sep 23 22:30:31 2016: schedule save complete.
Fri Sep 23 22:30:31 2016: Opening /var/lib/humaxtv/rsvp.db
Fri Sep 23 22:30:32 2016: Loading schedule information to HumaxTV binary.
[nugget]: Fri Sep 23 22:30:32 2016: Re-loading schedule database (29).
[nugget]: Fri Sep 23 22:30:32 2016: schedule.stash 26 = 1
[nugget]: Fri Sep 23 22:30:32 2016: Closing database.
[nugget]: Fri Sep 23 22:30:32 2016: Schedule load failed.
[nugget]: Fri Sep 23 22:30:32 2016: schedule.stash 13 = 2
[nugget]: Fri Sep 23 22:30:32 2016: Magic: 0xa029a697 (open)
[nugget]: Fri Sep 23 22:30:32 2016: Flags: 0x100800
[nugget]: Fri Sep 23 22:30:32 2016: Closing db handle due to error.
[nugget]: Fri Sep 23 22:30:32 2016: Last Error: 5 (ff)
Fri Sep 23 22:30:32 2016: Final schedule entries: 29
Fri Sep 23 22:30:32 2016: Slots: +23
[nugget]: Fri Sep 23 22:30:32 2016: Schedule failed to reload, deferring.
[nugget]: Fri Sep 23 22:30:32 2016: Deferred thread starting for '29:+23' (attempt 1)
[nugget]: Fri Sep 23 22:30:37 2016: slots(29, +23)
[nugget]: Fri Sep 23 22:30:37 2016: Processing slot +23 (23)
[nugget]: Fri Sep 23 22:30:37 2016: Cannot set EPG, missing CRID.
[nugget]: Fri Sep 23 22:30:37 2016:  Wake 1474931700 - Tue Sep 27 00:15:00 2016
[nugget]: Fri Sep 23 22:30:37 2016:   Ink Master Redemption
[nugget]: Fri Sep 23 22:30:37 2016:    @ 1474932600 (Tue Sep 27 00:30:00 2016)
[nugget]: Fri Sep 23 22:30:37 2016:     - Tue Sep 27 00:14:30 2016
[nugget]: Fri Sep 23 22:30:37 2016: Deferred thread exiting.
[nugget]: Fri Sep 23 22:30:37 2016: Ready 1474931670 - Tue Sep 27 00:14:30 2016
[nugget]: Fri Sep 23 22:30:37 2016: Adding timer(1474931670)
[nugget]: Fri Sep 23 22:30:37 2016: Re-loading schedule database (29).
[nugget]: Fri Sep 23 22:30:37 2016: schedule reload complete (29).
[nugget]: Fri Sep 23 22:30:37 2016: schedule.restore 13 = 2
[nugget]: Fri Sep 23 22:30:37 2016: schedule.restore 26 = 1
23/09/2016 23:41:21 - Recorded: /Wrong Turn (57 minutes - 5STAR)
24/09/2016 00:23:34 - Recorded: /Wrong Turn (39 minutes - 5STAR)
24/09/2016 00:29:11 - Recorded: /Chain Reaction (208 minutes - Movie Mix)

[Update]

I stopped "Chain Reaction" recording yesterday evening after it over ran its recording end time. I noticed this afternoon that "Chain Reaction" has popped back into the on-box schedule and currently showing in a recording state. This is not listed in the Webif Schedule and no recording is shown in the on-box Media page.
I have "The Dog Whisperer" actively recording and its almost like the start of this new recording has triggered the old entry for "Chain Reaction" to be pulled into the schedule window.

Chain Reaction.jpg
 
Last edited:
Status
Not open for further replies.
Back
Top