Hi,

I have a Philips Tivo runing Tivo V2.5 and TivoWebPlus 1.3. It's configured for NZ Telstra Digital.

Last night I added two Season Passes - one for House (20:30 - 21:30 on TV3) and another for Boston Legal (21:30 -22:30 also on TV3). The record light came on at 20:25 as it should, but was still on after 23:00 - long after it should have finished. At this point the Tivo would not respond to the remote control, or TivoWebPlus. I did manage to Telnet in and reboot after which everything behaved as normal except neither show was listed in the Now Playing list. Perhaps rebooting was a mistake.

My questions are:
1) is it possible that all or part of these programs did record and are sitting in a file on the disk somewhere, but didn't get added to the list due to me rebooting? If so is there anyway to recover them?

2) any clues why this would have happened in the first place? I've grabbed the log files from yesterday and there do seem to be curious things about the time everything went pear shaped. I've pasted some snippets below which hopefully might mean more to someone than they do to me.

Any help or suggestions greatly appreciated.

Cheers,
Pete.



Here's the Endpad log just before I restarted:

Tuesday 23:25:16 : Rise and shine!
Tuesday 23:25:16 : Processing current recording(s):
Tuesday 23:25:16 : * House on [3 TV3] until 21:30 (Season Pass)
Tuesday 23:25:16 : Scheduled recording lasts throughout requested padding
Tuesday 23:25:16 : Tuner 1 has 0 seconds available
Tuesday 23:25:16 : Tuner in use; no padding available
Tuesday 23:25:16 : Can't add end padding due to conflict
Tuesday 23:25:16 : Processing next recording(s):
Tuesday 23:25:16 : * Boston Legal on [3 TV3] from 21:30 to 22:30 (Season Pass)
Tuesday 23:25:16 : Active recording lasts throughout requested padding
Tuesday 23:25:16 : Tuner 1 has 0 seconds available
Tuesday 23:25:16 : Tuner in use; no padding available
Tuesday 23:25:16 : Can't add start padding due to conflict
Tuesday 23:25:16 : Next end padding setting due 22:23
Tuesday 23:25:16 : Next wake up will be 23:25
Tuesday 23:25:16 : Back to sleep...
Tuesday 23:25:16 : Checking every minute for kill signal..
Tuesday 23:25:47 :


Here's all the entries from the TV log between starting to record and when I restarted:

May 22 20:24:06 (none) Recorder[199]: Adding check schedule task
May 22 20:24:06 (none) Recorder[199]: CheckSchedule: creating action for: rec 2861521
May 22 20:24:06 (none) Recorder[199]: Creating normal action
May 22 20:24:06 (none) Recorder[199]: CheckSchedule: next creation at 13655:77346 : rec 2861524
May 22 20:24:06 (none) Recorder[199]: InitialAction rec 2861521
May 22 20:24:06 (none) Recorder[199]: Item 2861521: estimate kb per second: 227
May 22 20:24:07 (none) Recorder[199]: RequestTuner rec 2861521
May 22 20:24:07 (none) TvVideoPolicy[199]: RecordingTunerRequest on 481
May 22 20:24:07 (none) TvVideoPolicy[199]: RecordingTunerRequest conflict on 481
May 22 20:24:49 (none) Recorder[199]: Allocate rec 2861521
May 22 20:24:49 (none) Recorder[199]: Allocating new recording file. Size 524288
May 22 20:24:49 (none) Recorder[199]: Live cache size 1671168
May 22 20:24:49 (none) Recorder[199]: Recording Id 2861521 size 0
May 22 20:24:49 (none) Recorder[199]: User recording 231336320 free 5298560
May 22 20:24:49 (none) Recorder[199]: TivoClip total 10000000 free 9948800
May 22 20:24:49 (none) Recorder[199]: Allocated stream Id 2861534, size 524288
May 22 20:24:49 (none) Recorder[199]: Allocate success! Adding START task
May 22 20:24:49 (none) Recorder[199]: Adding check schedule task
May 22 20:24:50 (none) Recorder[199]: Got EVT_VIDEO_SESSION 3
May 22 20:24:50 (none) Recorder[199]: AquiredTunerLock event received
May 22 20:24:50 (none) VideoGuts[198]: RecordingTunerResult ALLOWED 481
May 22 20:24:58 (none) Recorder[199]: Start rec 2861521
May 22 20:24:58 (none) VideoGuts[199]: StartRecording 481
May 22 20:24:58 (none) InputState[199]: StartRecording 0
May 22 20:24:58 (none) TmkMediaswitch::Trace[197]: using CBR, bitRate=1630000, maxBitrate=1630000
May 22 20:24:58 (none) OutputState[199]: PlayLive 0
May 22 20:24:58 (none) TmkTransform::Trace[197]: ClipCache 0x30014ed4 Secondary Reset
May 22 20:24:58 (none) Recorder[199]: found showing 2837795/200 (program 2851105)
May 22 20:24:58 (none) ClipCache[193]: 0x30014ed4 in Entry(), thread 193
May 22 21:07:23 (none) TmkTransform::Trace[197]: ClipCache 0x3000cf00 Secondary Reset
May 22 21:07:23 (none) ClipCache[194]: 0x3000cf00 in Entry(), thread 194
May 22 21:24:36 (none) TmkTransform::Trace[197]: ClipCache 0x30004d24 Secondary Reset
May 22 21:24:36 (none) ClipCache[193]: 0x30004d24 in Entry(), thread 193
May 22 21:41:49 (none) TmkTransform::Trace[197]: ClipCache 0x30012078 Secondary Reset
May 22 21:41:49 (none) ClipCache[194]: 0x30012078 in Entry(), thread 194
May 22 21:59:02 (none) TmkTransform::Trace[197]: ClipCache 0x30013ee8 Secondary Reset
May 22 21:59:02 (none) ClipCache[193]: 0x30013ee8 in Entry(), thread 193
May 22 22:16:15 (none) TmkTransform::Trace[197]: ClipCache 0x30011108 Secondary Reset
May 22 22:16:15 (none) ClipCache[194]: 0x30011108 in Entry(), thread 194
May 22 22:33:28 (none) TmkTransform::Trace[197]: ClipCache 0x300046b0 Secondary Reset
May 22 22:33:28 (none) ClipCache[193]: 0x300046b0 in Entry(), thread 193
May 22 22:50:41 (none) TmkTransform::Trace[197]: ClipCache 0x3000fe8c Secondary Reset
May 22 22:50:41 (none) ClipCache[194]: 0x3000fe8c in Entry(), thread 194
May 22 23:07:54 (none) TmkTransform::Trace[197]: ClipCache 0x30013860 Secondary Reset
May 22 23:07:54 (none) ClipCache[193]: 0x30013860 in Entry(), thread 193
May 22 23:24:59 (none) EvtSwitcher[84]: EventSwitcher is starting up
May 22 23:24:59 (none) EvtService[84]: Service Test has NULL executable name!
May 22 23:25:00 (none) MfsDaemon[85]: MFS Daemon started, id is 85
May 22 23:25:00 (none) MfsDaemon[85]: Initializing MFS
May 22 23:25:00 (none) NmCache[85]: Cache at 0x0x7fee4f0c, array of 100 entries at 0x0x7fee4f90
May 22 23:25:01 (none) MfsDaemon[85]: The MfsDaemon is starting up
May 22 23:25:01 (none) EvtSwitcher[84]: Tmk client 1 (pid=82) has attached
May 22 23:25:01 (none) EvtSwitcher[84]: Invalid service attempted to attach?
May 22 23:25:01 (none) EvtSwitcher[84]: Group 82 was not an MFS group
May 22 23:25:01 (none) EvtSwitcher[84]: Client 1 (pid=82) being removed
May 22 23:25:01 (none) EvtSwitcher[84]: Tmk client 2 (pid=85) has attached
May 22 23:25:01 (none) EvtSwitcher[84]: Invalid service attempted to attach?
May 22 23:25:01 (none) EvtSwitcher[84]: Client 2 (pid=85), thread 85 has activated MFS
May 22 23:25:05 (none) EvtSwitcher[84]: Tmk client 3 (pid=116) has attached
May 22 23:25:05 (none) EvtSwitcher[84]: Invalid service attempted to attach?
May 22 23:25:05 (none) EvtSwitcher[84]: Client 3 (pid=116), thread 116 has activated MFS
May 22 23:25:05 (none) DbUpgrader[116]: majorVersionNum:5
May 22 23:25:05 (none) DbUpgrader[116]: minorVersionNum:72
May 22 23:25:05 (none) DbUpgrader[116]: converted majorVersionNum:5
May 22 23:25:05 (none) DbUpgrader[116]: converted minorVersionNum:72
May 22 23:25:05 (none) DbUpgrader[116]: Existing version: 5.72