QBox User Posted September 10, 2011 Share Posted September 10, 2011 I updated to 1.9.1 yesterday, from the previous version. A recording completed this morning at 01:05, as scheduled (00:55 end plus 10 minutes 'time after'). The next one should have started (same tuner, but on another channel) about 20 minutes later (Timer data: 'Start="01:28:00" Dur="176" PreEPG="2" PostEPG="14" '). A timer fired at 01:25, then nothing. The last line of the completed log for the recording was '01:05:01 / 01:09:58 (~ 2286.88 MB) Stop' - this was after the recording stopped (file is stamped 'Modified 01:05:01'). The PC was still powered on this morning - no standby as usual. RS web interface would not respond until I stopped and restarted the service, from the "Trayutil", so it seems the Service had partly halted, and something was preventing the PC from going into Standby. Is it possible to say what went wrong? Did the previous version have thread numbers in the log? 10.09.11 01:05:01.441 TRecording Release TBS QBOX DVB-S2 Tuner (3) 10.09.11 01:05:01.441 TRecording Destroy TBS QBOX DVB-S2 Tuner (3) 10.09.11 01:05:01.462 TRecording Destroyed TBS QBOX DVB-S2 Tuner (3) 10.09.11 01:05:01.463 TRecording hamDeleted TBS QBOX DVB-S2 Tuner (3) 10.09.11 01:05:01.741 CreateProcessW 4744 10.09.11 01:05:03.353 ReleaseStandbyblock TRecording 10.09.11 01:05:03.353 SetThreadExecutionState 0x80000000 10.09.11 01:05:03.353 Releasereference TRecording: 0 10.09.11 01:05:03.395 DoUpdate Away -> going Standby 10.09.11 01:05:03.395 SetStandbyblock EvaluateShutdown 10.09.11 01:05:03.395 SetThreadExecutionState 0x80000041 10.09.11 01:05:32.816 DoShutdown Enter 10.09.11 01:05:32.816 Setting next recording: 10/09/2011 01:25:00 10.09.11 01:05:32.817 ThdProc Enter 10.09.11 01:05:32.821 TDevice wsClosed 10.09.11 01:05:32.821 TDevice stop 10.09.11 01:05:34.118 ReleaseStandbyblock DoShutdown 10.09.11 01:05:34.118 SetThreadExecutionState 0x80000000 10.09.11 01:05:34.118 DoShutdown sdStandby 10.09.11 01:05:34.120 DoShutdown Exit 10.09.11 01:25:00.000 ThdProc Timer fired 10.09.11 01:25:00.000 Killtimer close thread 10.09.11 08:33:05.273 Powermessage Coming from Away... 10.09.11 08:45:01.090 StopService start stopping service 10.09.11 08:45:01.224 TDevice stop 10.09.11 08:45:01.269 TDevice stop 10.09.11 08:45:01.594 TUniCastServer Stop Server 10.09.11 08:45:02.722 savesetup save vcr 10.09.11 08:45:02.822 Stop ClearDeviceList 10.09.11 08:45:02.822 Stop Done ClearDeviceList 10.09.11 08:45:03.158 Stop Unload settings 10.09.11 08:45:03.865 Stop Couninitialize 10.09.11 08:45:03.877 Recorderservice Disabled 10.09.11 08:45:03.877 StopService stop service 10.09.11 08:45:03.878 Execute setrunning false 10.09.11 08:45:03.878 Execute release shared 10.09.11 08:45:03.878 Execute Couninitialize 10.09.11 08:45:03.878 thread service ended 10.09.11 08:45:03.878 TUniCastServer Stop Server 10.09.11 08:45:03.935 End App ----------------------------------- 10.09.11 08:45:07.191 Start App ----------------------------------- 10.09.11 08:45:07.194 thread service started - normal service restored after re=start. Link to comment
QBox User Posted September 15, 2011 Author Share Posted September 15, 2011 I've had a further occurrence of this, so will try to post more info in case it helps. The attached svcdebug.log shows the timing of events. A recording today was interrupted by the system going into Standby (sleep, 09:09 in log). I noticed this and brought the system out of Standby. (09:16) Recording re-started and continued until completion. (11:10) Windows did not record any sleep event after this, before the next timer was due at 13:15. Two successive timer tasks were due at 13:15 and 13:25, for daily Freesat EPG tune and weekly EPG Update task for all enabled transponders. A timer fired at 13:12, but nothing happened until I restarted the DVBViewer service at 13:30. The second task then started, and seemed to run normally until a "DoShutdown" at 14:33. I had been monitoring progress through the Status web-page (which shows current transponder), but had stopped before then. I am wondering if the absence of user (mouse) activity caused a normal shutdown even though the task was in progress. This may be what happened also during the earlier recording at 09:16, as I had switched on the monitor shortly before then to check on the recording status. Windows recorded a power event at 14:48 (return from standby), as did DVBViewer log. 5 minutes later, the EPG update task re-started and continued to completion at 17:00. [i think the reason it took so long is that the first task had left the dish out of position (this seems to happen after every update) and subsequent DiSEqC motor position commands failed to find a satellite.] The system did not enter Standby after this. There may be two issues here. The Recording Service fails to start tasks, becoming unresponsive, perhaps after completing an earlier recording. Other Windows tasks seem to override the Service's requests to prevent the system from entering sleep. Both problems are causing problems for use. Can anyone suggest a cause/solution? support.zip Link to comment
majstang Posted September 15, 2011 Share Posted September 15, 2011 You shouldnt use Away Mode, since its not supported on a 64-bit system. My suggestion is to go 32-bit, mainly to avoid all the strange quirks Win7x64 with RS seem to bring. I dont have any sure statistically proof, but it is definite so that the majority the issues posted in the Recording Service section lately (both german and english) seem to be made by folks with Winx64. Link to comment
QBox User Posted September 15, 2011 Author Share Posted September 15, 2011 (edited) I didn't know what Away Mode was until you mentioned it. Would it have affected anything if it's not supported by the OS? As I understand it, recordings should continue in Away Mode. Anyway, I checked my power options and disabled it. Sleep options are now: Allow Away Mode Policy: No (default setting was Yes) Sleep after: 15 minutes Allow Hybrid Sleep: On Hibernate after: Never Allow Wake Timers: Enable I'll check the BIOS settings on next re-boot. The other power setting that might affect things is Multimedia settings/When sharing media/Settings: Prevent idling to sleep. How would that affect RS? Wouldn't it only apply when a remote client was connected? Edited September 15, 2011 by QBox User Link to comment
majstang Posted September 17, 2011 Share Posted September 17, 2011 Would it have affected anything if it's not supported by the OS? The other power setting that might affect things is Multimedia settings/When sharing media/Settings: Prevent idling to sleep. How would that affect RS? Wouldn't it only apply when a remote client was connected? Hard questions really! Im not sure in fact how the lack of away mode support on 64-bit systems affect RS. I was hoping you could report about your experiences after disabling it. Here's my Win7 32-bit energy settings which seem to work fine, since my system is pretty much rock stable: Allow Away Mode Policy: No (default setting was Yes) Sleep after: Never Allow Hybrid Sleep: Off Hibernate after: Never Allow Wake Timers: Enable Multimedia settings/When sharing media/Settings: Prevent idling to sleep. Link to comment
QBox User Posted September 19, 2011 Author Share Posted September 19, 2011 So, you leave your PC ON all the time - never goes into standby? Surely it shouldn't be necessary to prohibit sleep mode to achieve stable operation? I might have to try it, though, as my tuner 3 driver has problems which seem to be also related to sleep cycling. I had another occurrence this week-end which tends to support my suspicion that the RS request to prevent sleep is overridden by system activity. A blue-screen event (due to bad driver on tuner 3) delayed the start of a timed recording (on tuner 1). When the system re-started, so did the recording, but it ended only 17 minutes later (about 22:26). The system sleep time is 15 minutes. The system woke from sleep again at 01:10, ready for a new recording. RS thinks it's been recording all this time and closes the log with a recording duration of just over 3 hours (actual duration 16m58s). The new recording doesn't happen as tuner 3 hasn't recovered from the crash. When the system goes to sleep, why doesn't RS say "hey, wait, I'm in the middle of a recording"? It manages to restart a recording when it's interrupted, but it fails to tell the system to stay awake. I notice the latest RS version (1.9.2) has this: # Fix: System: After canceling the Standby/Hibernate message of the a timer the PC didn't go into Standby/Hibernate if triggered by a following timer. and wonder if there's any relation to my issues. Here's the relevant bits from the log. Note that the line "No shutdown allowed next recording: " appears twice after waking for the new recording, but not at all on the re-start. Can I suggest that the RS re-start should send the "No shutdown" command if it detects a timer in progress? 18.09.11 21:56:44.587 Resume Reset Timer signaled 18.09.11 21:56:44.587 Reset start <<crash here>> 18.09.11 22:09:18.546 Start App ----------------------------------- 18.09.11 22:09:18.562 thread service started 18.09.11 22:09:19.373 StartService start timer 18.09.11 22:09:19.373 StartService create plugin list 18.09.11 22:09:22.883 StartService loadchannellist 18.09.11 22:09:22.946 TDVBDevice.InitDevice IT9135 BDA Filter (1) 18.09.11 22:09:22.946 TDVBDevice.InitDevice IT9135 BDA Filter (2) 18.09.11 22:09:22.961 TDVBDevice.InitDevice TBS QBOX DVB-S2 Tuner (3) 18.09.11 22:09:22.961 Device Check present 18.09.11 22:09:23.055 CheckDevicespresent start 18.09.11 22:09:23.055 CheckDevicespresent end 18.09.11 22:09:23.086 Start Searches load 18.09.11 22:09:23.102 Start Tasks load 18.09.11 22:09:23.148 Start VCR load 18.09.11 22:09:24.334 Start EPG load 18.09.11 22:09:24.334 loadsetup load vcr 18.09.11 22:09:28.655 TDevice startup 18.09.11 22:09:28.655 TDevice wsBound 18.09.11 22:09:28.655 TDevice wsListening 18.09.11 22:09:28.655 TDevice wsConnected 18.09.11 22:09:28.655 TDevice start: 127.0.0.1 18.09.11 22:09:28.671 StartService load setup 18.09.11 22:09:28.671 Recorderservice Enabled 18.09.11 22:09:30.664 Opendevice bvUnknown 18.09.11 22:09:30.664 TRecording Allocate IT9135 BDA Filter (1) 18.09.11 22:09:30.664 StartRecording IT9135 BDA Filter (1) 18.09.11 22:09:31.837 StartRecording: BBC TWO Scot 18.09.11 22:09:32.180 SetStandbyblock TRecording 18.09.11 22:09:32.204 SetThreadExecutionState 0x80000041 18.09.11 22:09:32.204 AddReference TRecording: 1 18.09.11 22:26:31.315 Standby PBT_APMSUSPEND 18.09.11 22:26:31.315 Setting next recording: 19/09/2011 01:10:00 18.09.11 22:26:31.323 TDevice wsClosed 18.09.11 22:26:31.323 TDevice stop 18.09.11 22:26:31.326 ThdProc Enter 19.09.11 01:10:01.505 ThdProc Timer fired 19.09.11 01:10:01.507 Killtimer close thread 19.09.11 01:10:01.522 Time changed 19.09.11 01:10:02.119 Resume PBT_APMRESUMEAUTOMATIC 19.09.11 01:10:04.493 Resume Processing... 19.09.11 01:10:04.494 No shutdown allowed next recording: 19/09/2011 01:13:00 19.09.11 01:10:04.494 SetStandbyblock PBT_APMRESUMESUSPEND 19.09.11 01:10:04.494 SetThreadExecutionState 0x80000041 19.09.11 01:10:04.494 Resume ES_SYSTEM_REQUIRED 19.09.11 01:10:04.494 fwakeup 0 19.09.11 01:10:04.494 Device Check present 19.09.11 01:10:04.497 CheckDevicespresent start 19.09.11 01:10:04.497 CheckDevicespresent end 19.09.11 01:10:04.497 fwakeup do 19.09.11 01:10:04.497 NextEPGUpdate 29/12/1899 19.09.11 01:10:04.499 TDevice startup 19.09.11 01:10:04.502 TDevice wsBound 19.09.11 01:10:04.502 TDevice wsListening 19.09.11 01:10:04.502 TDevice wsConnected 19.09.11 01:10:04.502 TDevice start: 127.0.0.1 19.09.11 01:10:06.814 D:\TV Recordings\DVBViewer\Recording Service\2011-09-18_22-09-32_BBC TWO Scot_Sportscene.ts Discontinuities: 0 - Total size: 466.64 MB - Device:IT9135 BDA Filter (1) 19.09.11 01:10:08.434 TRecording Release IT9135 BDA Filter (1) 19.09.11 01:10:08.434 TRecording Destroy IT9135 BDA Filter (1) 19.09.11 01:10:52.289 TRecording Destroyed IT9135 BDA Filter (1) 19.09.11 01:10:52.289 TRecording hamDeleted IT9135 BDA Filter (1) 19.09.11 01:10:52.445 CreateProcessW 1116 19.09.11 01:10:52.757 No shutdown allowed next recording: 19/09/2011 01:13:00 19.09.11 01:10:52.757 Releasereference TRecording: -1 19.09.11 01:10:52.803 Resume Reset Timer signaled 19.09.11 01:10:52.803 Reset start 19.09.11 01:13:00.951 StartRecording No hardware. 19.09.11 01:13:01.965 StartRecording No hardware. Link to comment
Recommended Posts