GRAPHS not rebuilt after retrun from Hibernation (1 Viewer)

[SciDoctor]

Tested on SVN 15745 but present in at least last weeks releleases.

On return from hibernation the graphs fail to rebuild with this error .

05/09/2007 08:29:05 10 Exception :TvLibrary.TvException: Unable to start graph
at TvLibrary.Implementations.DVB.TvCardDvbBase.RunGraph(Int32 subChannel)
at TvLibrary.Implementations.DVB.TvCardDVBT.Tune(Int32 subChannelId, IChannel channel)
05/09/2007 08:29:05 10 Exception :Unable to start graph
05/09/2007 08:29:05 10 site :Void RunGraph(Int32)
05/09/2007 08:29:05 10 source :TVLibrary
05/09/2007 08:29:05 10 stacktrace: at TvLibrary.Implementations.DVB.TvCardDvbBase.RunGraph(Int32 subChannel)
at TvLibrary.Implementations.DVB.TvCardDVBT.Tune(Int32 subChannelId, IChannel channel)
05/09/2007 08:29:05 10 Exception :TvLibrary.TvException: Unable to start graph
at TvLibrary.Implementations.DVB.TvCardDVBT.Tune(Int32 subChannelId, IChannel channel)
at TvService.CardTuner.Tune(User& user, IChannel channel, Int32 idChannel)
05/09/2007 08:29:05 10 Exception :Unable to start graph
05/09/2007 08:29:05 10 site :Void RunGraph(Int32)
05/09/2007 08:29:05 10 source :TVLibrary
05/09/2007 08:29:05 10 stacktrace: at TvLibrary.Implementations.DVB.TvCardDVBT.Tune(Int32 subChannelId, IChannel channel)
at TvService.CardTuner.Tune(User& user, IChannel channel, Int32 idChannel)
05/09/2007 08:29:22 E Exception :TvLibrary.TvException: Unable to start graph
at TvLibrary.Implementations.DVB.TvCardDvbBase.RunGraph(Int32 subChannel)
at TvLibrary.Implementations.DVB.TvCardDVBT.Tune(Int32 subChannelId, IChannel channel)
05/09/2007 08:29:22 E Exception :Unable to start graph
05/09/2007 08:29:22 E site :Void RunGraph(Int32)
05/09/2007 08:29:22 E source :TVLibrary
05/09/2007 08:29:22 E stacktrace: at TvLibrary.Implementations.DVB.TvCardDvbBase.RunGraph(Int32 subChannel)
at TvLibrary.Implementations.DVB.TvCardDVBT.Tune(Int32 subChannelId, IChannel channel)
05/09/2007 08:29:22 E Exception :TvLibrary.TvException: Unable to start graph
at TvLibrary.Implementations.DVB.TvCardDVBT.Tune(Int32 subChannelId, IChannel channel)
at TvService.CardTuner.Tune(User& user, IChannel channel, Int32 idChannel)
05/09/2007 08:29:22 E Exception :Unable to start graph
05/09/2007 08:29:22 E site :Void RunGraph(Int32)
05/09/2007 08:29:22 E source :TVLibrary
05/09/2007 08:29:22 E stacktrace: at TvLibrary.Implementations.DVB.TvCardDVBT.Tune(Int32 subChannelId, IChannel channel)
at TvService.CardTuner.Tune(User& user, IChannel channel, Int

BUT the cards are reinitialised as the EPG grab works fine.

05/09/2007 08:38:46 E EPG: grabber initialized for 6 transponders..
05/09/2007 08:38:47 14 epg:Grab for card:#1 transponder #0 index:0/6 last:04/09/2007 21:07:03 type:4 freq:778000 mod:0 sr:0 bw:8 pol:0
05/09/2007 08:38:47 14 grab epg card:#1 transponder: #0 ch:BBC ONE
05/09/2007 08:38:48 14 Epg: card:1 start grab DVBT:tv:BBC BBC ONE Freq:778000 ONID:9018 TSID:4097 SID:4161 PMT:1041 FTA:True LCN:10000 BandWidth:8
05/09/2007 08:52:18 9 dvb:mhw ready MHW 0 titles found
05/09/2007 08:52:18 9 dvb:dvb ready.EPG 75 channels
05/09/2007 08:52:20 9 Epg: card:1 received epg for 75 channels
05/09/2007 08:52:20 10 Epg: card:1 Remove old programs from database
05/09/2007 08:52:20 10 Epg: card:1 Updating database with new programs
05/09/2007 08:52:20 10 Epg: card:1 :1 BBC ONE lastUpdate:04/09/2007 21:07:03
05/09/2007 08:52:28 10 Epg: card:1 :2 BBC TWO lastUpdate:04/09/2007 21:09:16
05/09/2007 08:52:36 10 Epg: card:1 :3 BBC THREE lastUpdate:04/09/2007 21:07:08
05/09/2007 08:52:41 10 Epg: card:1 :4 BBC NEWS 24 lastUpdate:04/09/2007 21:07:11
05/09/2007 08:52:48 10 Epg: card:1 :5 BBCi lastUpdate:04/09/2007 21:07:11
05/09/2007 08:52:49 10 Epg: card:1 :6 CBBC Channel lastUpdate:04/09/2007 21:07:14


TV-Server Version: Latest SVN
MediaPortal Version: Latest SVN
MediaPortal Skin: Blue 2 WIDE
Windows Version: W2Ksp4
CPU Type: Dual P3 1GHZ
HDD: 80GB and 2TB
Memory: 1GB ddr
Motherboard: Gigabyte 6BXD
Motherboard Chipset: 440BX intel
Motherboard Bios:
Video Card: ATI 9500pro AGP2x
Video Card Driver: Cat 7.4
Sound Card: Xitel USB
Sound Card AC3: USB to Meridian DSP
Sound Card Driver:
1. TV Card: Nebula DVB-T pci
1. TV Card Type:
1. TV Card Driver:
2. TV Card: Nebula DVB-t USB
2. TV Card Type:
2. TV Card Driver:
3. TV Card: Nebula DVB-t USB
3. TV Card Type:
3. TV Card Driver:
4. TV Card: Nebula DVB-t USB
4. TV Card Type:
4. TV Card Driver:
MPEG2 Video Codec: Cyberlink ATI
MPEG2 Audio Codec: Cyberlink ATI
Satelite/CableTV Provider:
HTPC Case:
Cooling:
Power Supply: Tagan 530 EC
Remote: ATI RW 1
TV: Dell 2707wfp
TV - HTPC Connection: dvi-d

 

[SciDoctor]

Still a problem with the latest SVN. Logs rom SVN 15854.

13/09/2007 19:35:27 6 Exception :TvLibrary.TvException: Unable to start graph
at TvLibrary.Implementations.DVB.TvCardDvbBase.RunGraph(Int32 subChannel)
at TvLibrary.Implementations.DVB.TvCardDVBT.Tune(Int32 subChannelId, IChannel channel)
13/09/2007 19:35:27 6 Exception :Unable to start graph
13/09/2007 19:35:27 6 site :Void RunGraph(Int32)
13/09/2007 19:35:27 6 source :TVLibrary
13/09/2007 19:35:27 6 stacktrace: at TvLibrary.Implementations.DVB.TvCardDvbBase.RunGraph(Int32 subChannel)
at TvLibrary.Implementations.DVB.TvCardDVBT.Tune(Int32 subChannelId, IChannel channel)

When returning from hibernation the graphs fail to rebuild and the server can't tune channels for timeshfting or recroding.

EPG grab isn't affected though.


TV-Server Version: Latest SVN
MediaPortal Version: Latest SVN
MediaPortal Skin: Blue 2 WIDE
Windows Version: W2Ksp4
CPU Type: Dual P3 1GHZ
HDD: 80GB and 2TB
Memory: 1GB ddr
Motherboard: Gigabyte 6BXD
Motherboard Chipset: 440BX intel
Motherboard Bios:
Video Card: ATI 9500pro AGP2x
Video Card Driver: Cat 7.4
Sound Card: Xitel USB
Sound Card AC3: USB to Meridian DSP
Sound Card Driver:
1. TV Card: Nebula DVB-T pci
1. TV Card Type:
1. TV Card Driver:
2. TV Card: Nebula DVB-t USB
2. TV Card Type:
2. TV Card Driver:
3. TV Card: Nebula DVB-t USB
3. TV Card Type:
3. TV Card Driver:
4. TV Card: Nebula DVB-t USB
4. TV Card Type:
4. TV Card Driver:
MPEG2 Video Codec: Cyberlink ATI
MPEG2 Audio Codec: Cyberlink ATI
Satelite/CableTV Provider:
HTPC Case:
Cooling:
Power Supply: Tagan 530 EC
Remote: ATI RW 1
TV: Dell 2707wfp
TV - HTPC Connection: dvi-d

 

[SciDoctor]

Still a problem with SVN 15972.

As you can see from the logs the TVSERVER will still record fine but timeshifting fails with the 'graph failure'

 

[gibman]

Did this just happen lately or has it been around for a while ?

Can u try and revert back Tv engine to an older vers.

/Gibman

 

[SciDoctor]

Been happening for a while now.

All RC2 and SVN'

I'll try and find the RC1 SVN where it started.

Another odity was that the PS ignored the 'EPG grab overide and hibernated while a grab was occuring. then picked up again when the PC awoke for a timer again.SVN 15970. Previously the client has waited for the EPG grab to finish before Hibernating.

21/09/2007 04:00:50 10 Epg: card:1 :8 ITV3 lastUpdate:21/09/2007 01:46:31
21/09/2007 04:00:54 10 Epg: card:1 :9 ITV2 lastUpdate:21/09/2007 01:46:34
21/09/2007 04:01:00 10 Epg: card:1 :10 ITV4 lastUpdate:21/09/2007 01:46:36
21/09/2007 09:55:26 10 Epg: card:1 :11 CITV lastUpdate:21/09/2007 01:46:39
21/09/2007 09:55:30 10 Epg: card:1 :12 Channel 4 lastUpdate:21/09/2007 01:46:43
21/09/2007 09:55:36 10 Epg: card:1 :13 More 4 lastUpdate:21/09/2007 01:46:45
21/09/2007 09:55:40 10 Epg: card:1 :14 E4 lastUpdate:21/09/2007 01:46:49

 

[SciDoctor]

Found some time for testing this morning.

Used latest SVN

Allowed the Server to PS hibernate and then come back for a schedule, also tried to timeshift aswell.

Also allowed the server to run for a long period even after initial failure, LOGS attached

Same problems BUT it may not be a GRAPH build problem but a tuner allocation to USER problem and DVB-T EPG grab clash.

This may be because I have four DVB-T tuners available. Tuners 1,2,3,5 priorities 1,4,3,2 respectively.

Reading through the logs.

Coming back form HIBERNATION the TVSERVER starts the EPG grab on Tuner 1 priority 1, user epg add.

Now because a schedule is imminent the server stops the EPG grab.

This is where the problem starts.

EPG grab isn't flagged correctly to 'stop' on all the correct available tuners as tuners 1,3,5 all grab the EPG in the next twenty minutes, THEY SHOULDN't as a schedule is trying to start.Also the 'user' isn't reset/set correctly.

Every atempt to start a schedule and/or timeshift is forced correctly to what is the highest available priority tuner (card 2), unfortunately it is being set to 'user epg remove' and fails everytime.
Also card 2 is now complely broken until the TVserver is restarted but as it is still the highest priority available card all attempts to use this card fail.

Only when all EPG grabs have completed/stopped (there where THREE seperate being actioned!!! there should have been NONE) does the TVSERVER now have access to other cards for scheduling.

Now the only time the 'user' is set correctly to 'schedule....' is when an alternte card (not the blocked/broken card 2) is clear of EPG duty and is already set to a transponder that the schedule requires,


So if you follow my debug the porblem is the DVB-EPG grab when being stopped for a schedule isn't correctly clearing the 'user' and stopping ALL available cards. This is happening at return from hibernation .

Also I found it odd that 'set transponder' overides 'card priority'

 

[SciDoctor]

When the 'dvb:RunGraph returns:0x800700AA' error occurs wouldn't it be sensible for the TVSERVER to try another free card instead of constantly retrying the same card ?

I will also retest with DVB-T EPG grab turned off and see if this makes a differennce when retuning fro hibernation .

 

[SciDoctor]

Test completed.

With the DVB-EPG grab turned off there are none of the above problems and the schedule starts correctly.

USER correctly set to sheduler.

So the bug is with the DVB-EPG and how it handles multiple cards, stopping a grab when a schedule is about to occur and setting/resetting the 'user' correctly.

It would seem that the DVB-EPG grabber is setting the wrong cards to 'EPG REMOVE' when a schedule is about to occur? and there are multiple available cards.

 

[gibman]

Could it be that the users (either real ones or EPG users) arent being removed correctly when TVservice hibernates or going into standby ?

Are the card(s) being registered as idle just riiiight b4 going into a powerstate ?

Also could u try and make sure that "forced shutdown" is disabled on power scheduler ?
What does it say now ?

/Gibman

 

[SciDoctor]

Second update.

Failed again when returning from Hibernation after successfully completing the last schedule from above post.

'dvb:RunGraph returns:0x800700AA' is the error again?

Logs attached.

'gibman' not to sure on that, when reading through the logs can't see this

6/09/2007 13:45:02 11 card: StopRecording for card:2
26/09/2007 13:45:02 11 subch:0 StopRecord()
26/09/2007 13:45:02 11 card: remove user:scheduler704 sub:0
26/09/2007 13:45:02 11 user:scheduler704 remove
26/09/2007 13:45:02 11 card: free subchannel sub:0
26/09/2007 13:45:02 11 dvb:FreeSubChannel:1 #0
26/09/2007 13:45:02 11 subch:0 Decompose()
26/09/2007 13:45:02 11 dvb:FreeAllSubChannels:
26/09/2007 13:45:02 11 dvbtopGraph
26/09/2007 13:45:03 11 dvb:FreeAllSubChannels:
26/09/2007 13:45:35 6 PowerScheduler.NextWakeupTime: inspecting handler:GenericWakeupHandler time:31/12/9999 23:59:59
26/09/2007 13:45:36 6 PowerScheduler.NextWakeupTime: inspecting handlercheduledRecordingsHandler time:26/09/2007 13:59:00
26/09/2007 13:45:36 6 PowerScheduler.NextWakeupTime: inspecting handlerowerSchedulerClientPlugin time:31/12/9999 23:59:59
26/09/2007 13:45:36 6 PowerScheduler.NextWakeupTime: inspecting handlerowerSchedulerClientPlugin time:31/12/9999 23:59:59
26/09/2007 13:45:36 6 PowerScheduler: new next wakeup time 26/09/2007 13:59:00 found by ScheduledRecordingsHandler
26/09/2007 13:45:36 6 PowerScheduler: System changed from busy state to idle state
26/09/2007 13:45:36 6 PowerScheduler: System is unattended and idle - initiate suspend/hibernate
26/09/2007 13:45:36 6 PowerScheduler: Manual system suspend requested by
26/09/2007 13:45:36 6 PowerScheduler: Entering shutdown Hibernate ; forced: True -- kick off shutdown thread
26/09/2007 13:45:36 D PowerScheduler: Shutdown thread is running: Hibernate, force: True
26/09/2007 13:45:36 D PowerScheduler: Informing handlers about UserShutdownNow
26/09/2007 13:45:37 D PowerScheduler.NextWakeupTime: inspecting handler:GenericWakeupHandler time:31/12/9999 23:59:59
26/09/2007 13:45:37 D PowerScheduler.NextWakeupTime: inspecting handlercheduledRecordingsHandler time:26/09/2007 13:59:00
26/09/2007 13:45:37 D PowerScheduler.NextWakeupTime: inspecting handlerowerSchedulerClientPlugin time:31/12/9999 23:59:59
26/09/2007 13:45:38 D PowerScheduler.NextWakeupTime: inspecting handlerowerSchedulerClientPlugin time:31/12/9999 23:59:59
26/09/2007 13:45:38 D PowerScheduler: Shutdown is allowed True ; forced: True
26/09/2007 13:45:38 D PowerScheduler.NextWakeupTime: inspecting handler:GenericWakeupHandler time:31/12/9999 23:59:59
26/09/2007 13:45:38 D PowerScheduler.NextWakeupTime: inspecting handlercheduledRecordingsHandler time:26/09/2007 13:59:00
26/09/2007 13:45:38 D PowerScheduler.NextWakeupTime: inspecting handlerowerSchedulerClientPlugin time:31/12/9999 23:59:59
26/09/2007 13:45:38 D PowerScheduler.NextWakeupTime: inspecting handlerowerSchedulerClientPlugin time:31/12/9999 23:59:59
26/09/2007 13:45:39 D PowerScheduler.NextWakeupTime: inspecting handler:GenericWakeupHandler time:31/12/9999 23:59:59
26/09/2007 13:45:39 D PowerScheduler.NextWakeupTime: inspecting handlercheduledRecordingsHandler time:26/09/2007 13:59:00
26/09/2007 13:45:39 D PowerScheduler.NextWakeupTime: inspecting handlerowerSchedulerClientPlugin time:31/12/9999 23:59:59
26/09/2007 13:45:39 D PowerScheduler.NextWakeupTime: inspecting handlerowerSchedulerClientPlugin time:31/12/9999 23:59:59
26/09/2007 13:45:39 D PowerScheduler: Set wakeup timer to wakeup system in 8.33411458333333 minutes
26/09/2007 13:45:39 D PowerScheduler: Entering shutdown Hibernate ; forced: True
26/09/2007 13:45:39 5 WindowsController: Performing ExitWindows Hibernate, force: True
26/09/2007 13:45:40 11 PowerScheduler: User input detected at 26/09/2007 13:25:40
26/09/2007 13:55:17 E PowerScheduler: OnResume
26/09/2007 13:55:25 6 PowerScheduler.NextWakeupTime: inspecting handler:GenericWakeupHandler time:31/12/9999 23:59:59
26/09/2007 13:55:26 6 PowerScheduler.NextWakeupTime: inspecting handlercheduledRecordingsHandler time:26/09/2007 13:59:00
26/09/2007 13:55:26 6 PowerScheduler.NextWakeupTime: inspecting handlerowerSchedulerClientPlugin time:31/12/9999 23:59:59
26/09/2007 13:55:26 6 PowerScheduler.NextWakeupTime: inspecting handlerowerSchedulerClientPlugin time:31/12/9999 23:59:59
26/09/2007 13:55:26 6 PowerScheduler.DisAllowShutdown: some event is almost due
26/09/2007 13:55:26 6 PowerScheduler: System changed from idle state to busy state
26/09/2007 13:55:33 7 26/09/2007 13:55:33 7 OnPowerEvent: PowerStatus: ResumeAutomatic
26/09/2007 13:55:33 7 PowerScheduler: System has resumed automatically from standby
26/09/2007 13:55:34 7 TV service PowerEventThread 30
26/09/2007 13:55:34 7 26/09/2007 13:55:34 7 OnPowerEvent: PowerStatus: ResumeSuspend
26/09/2007 13:55:34 7 PowerScheduler: System has resumed from standby
26/09/2007 13:55:34 5 WindowsController: ExitWindows performed, result: True