[confirm] Problems with AverTV Duo Hybrid A188 (1 Viewer)

[DJBlu]

Patch is here

 

[Sebastiii]

Right now didn't notice regression

 

[mm1352000]

*bump*
Has the patch solved the problem, or do we need to keep looking?

 

[doskabouter]

For me, it's too soon to say. Usually the problem takes a couple of days to manifest itself.

 

[Raptor75]

Unfortunately it does not work on v.1.2.3. Is it worth upgrading to 1.3.0 alpha to try it out?

 

[mm1352000]

Hello Raptor75

First, thanks for testing.
No, it is not worth upgrading. If the solution doesn't work for MP 1.2.3 then it won't work for MP 1.3a either.
Back to the drawing board for us...

mm

 

[Raptor75]

Ok, thanks for the effort. Shall I post you my logs if that can help?

 

[mm1352000]

Wouldn't hurt just so we can double-check that the same issue is rearing its ugly head...

 

[Raptor75]

I don't get it, this looks like it was working, but then that's it. 06:49:36 is where I forced the restart. No logs for TsWriter for that time period, only right after the restart.

2012-10-06 06:44:01.070090 [(14)]: TCP connect took : 1
2012-10-06 06:45:45.030037 [(22)]: TCP connect took : 1
2012-10-06 06:46:12.377601 [(39)]: Controller: StartTimeShifting Fashion TV 5150
2012-10-06 06:46:12.378601 [(39)]: user:epg remove
2012-10-06 06:46:12.378601 [(39)]: Controller: find free card for channel Fashion TV
2012-10-06 06:46:12.378601 [(39)]: Controller: find card for channel Fashion TV
2012-10-06 06:46:12.379601 [(39)]: Controller:  got 1 tuning details for Fashion TV
2012-10-06 06:46:12.380601 [(39)]: Controller:  channel #1 DVBS:tv:RRSat Fashion TV Freq:10815000 ONID:318 TSID:11500 SID:17315 PMT:0x3F7 FTA:True LCN:5150 SymbolRate:27500 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:Level1AB band:Universal Pilot:NotSet RollOff:NotSet
2012-10-06 06:46:12.380601 [(39)]: Controller:    card:2 type:RadioWebStream cannot tune to channel
2012-10-06 06:46:12.381601 [(39)]: Controller:    card:3 type:DvbS can tune to channel
2012-10-06 06:46:12.381601 [(39)]: Controller:    card:3 type:DvbS users: 0
2012-10-06 06:46:12.382601 [(39)]: Controller:    card:4 type:DvbS can tune to channel
2012-10-06 06:46:12.382601 [(39)]: Controller:    card:4 type:DvbS users: 0
2012-10-06 06:46:12.382601 [(39)]: Controller: found 2 card(s) for channel
2012-10-06 06:46:12.383601 [(39)]: AdvancedCardAllocation.GetAvailableCardsForChannel took 4 msec
2012-10-06 06:46:12.383601 [(39)]: Controller:    card:3 type:DvbS is available
2012-10-06 06:46:12.383601 [(39)]: Controller:    card:4 type:DvbS is available
2012-10-06 06:46:12.383601 [(39)]: Controller: found 2 free card(s)
2012-10-06 06:46:12.384601 [(39)]: AdvancedCardAllocation.GetFreeCardsForChannel took 5 msec
2012-10-06 06:46:12.384601 [(39)]: Controller: try max 2 of 2 cards for timeshifting
2012-10-06 06:46:12.385601 [(39)]: TVServerXBMC: OnTvServerEvent: StartZapChannel
2012-10-06 06:46:12.386601 [(39)]: card: CardTune 3 Fashion TV webstreamingservice-aMPdroid.100778231.ts:3:-1
2012-10-06 06:46:12.387601 [(39)]: card: Tune 3 to Fashion TV
2012-10-06 06:46:12.387601 [(39)]: card: user: webstreamingservice-aMPdroid.100778231.ts:3:-1 tune DVBS:tv:RRSat Fashion TV Freq:10815000 ONID:318 TSID:11500 SID:17315 PMT:0x3F7 FTA:True LCN:5150 SymbolRate:27500 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:Level1AB band:Universal Pilot:NotSet RollOff:NotSet
2012-10-06 06:46:12.392602 [(39)]: TimeShifter.OnBeforeTune: resetting audio/video events
2012-10-06 06:46:12.392602 [(39)]: dvbs: Tune:DVBS:tv:RRSat Fashion TV Freq:10815000 ONID:318 TSID:11500 SID:17315 PMT:0x3F7 FTA:True LCN:5150 SymbolRate:27500 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:Level1AB band:Universal Pilot:NotSet RollOff:NotSet
2012-10-06 06:46:12.392602 [(39)]: dvbs:  Tune:DVBS:tv:RRSat Fashion TV Freq:10815000 ONID:318 TSID:11500 SID:17315 PMT:0x3F7 FTA:True LCN:5150 SymbolRate:27500 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:Level1AB band:Universal Pilot:NotSet RollOff:NotSet
2012-10-06 06:46:12.392602 [(39)]: dvb:GetNewSubChannel:0 #1
2012-10-06 06:48:30.481500 [SetupTv(1)]: ---- SetupTv v1.2.3.0 is starting up on Windows 7 ( Service Pack 1 ) [6.1.7601.65536]
2012-10-06 06:48:30.483500 [SetupTv(1)]: Build: 1.2.3.0
2012-10-06 06:48:30.487500 [SetupTv(1)]: ---- check connection with database ----
2012-10-06 06:48:30.650510 [SetupTv(1)]: SetupDatabaseForm: Added dependency for TvService - MySQL
2012-10-06 06:48:30.653510 [SetupTv(1)]: ---- check if database needs to be updated/created ----
2012-10-06 06:48:30.660510 [SetupTv(1)]: ---- upgrade database schema ----
2012-10-06 06:48:30.661510 [SetupTv(1)]: ---- check if tvservice is running ----
2012-10-06 06:48:30.817519 [SetupTv(1)]: RemoteControl: RegisterChannel first called in Domain SetupTv.exe for thread SetupTv with id 1
2012-10-06 06:48:36.226829 [(33)]: Controller: epg stop
2012-10-06 06:48:36.234829 [SetupTv(1)]: Weekend Updated to : Saturday/Sunday
2012-10-06 06:48:39.178997 [(33)]: Controller: epg stop
2012-10-06 06:48:39.183998 [(33)]: Controller: epg start
2012-10-06 06:48:48.386524 [(26)]: Controller: epg stop
2012-10-06 06:48:48.488530 [SetupTv(1)]: TCP connect took : 2
2012-10-06 06:48:48.489530 [(33)]: Controller: epg stop
2012-10-06 06:48:48.637538 [(5)]: Filter listview for
2012-10-06 06:48:51.580707 [(5)]: Finished filtering 1039 items for
2012-10-06 06:49:16.562136 [TVService(6)]: TV Service: stopping
2012-10-06 06:49:16.564136 [TVService(6)]: TV service StopRemoting
2012-10-06 06:49:16.565136 [TVService(6)]: Remoting stopped
2012-10-06 06:49:16.567136 [TVService(6)]: Controller: DeInit.
2012-10-06 06:49:16.568136 [TVService(6)]: Controller: HeartBeat monitor stopped...
2012-10-06 06:49:16.579137 [TVService(6)]: Controller: stop streamer...
2012-10-06 06:49:16.580137 [TVService(6)]: RTSP: stop streamer
2012-10-06 06:49:16.583137 [TVService(6)]: RTSP: stop all streams (1)
2012-10-06 06:49:16.584137 [TVService(6)]: RTSP: remove stream B6625365
2012-10-06 06:49:16.586137 [TVService(6)]: Controller: streamer stopped...
2012-10-06 06:49:16.587137 [TVService(6)]: Controller: stop scheduler...
2012-10-06 06:49:16.588137 [TVService(6)]: Scheduler: stopped
2012-10-06 06:49:16.591137 [TVService(6)]: Scheduler: thread stopped.
2012-10-06 06:49:16.604138 [TVService(6)]: Controller: scheduler stopped...
2012-10-06 06:49:16.605138 [TVService(6)]: Controller: stop epg grabber...
2012-10-06 06:49:16.607138 [TVService(6)]: Controller: epg stopped...
2012-10-06 06:49:16.609138 [TVService(6)]: Controller: dispose card:RadioWebStream Card (builtin)
2012-10-06 06:49:16.610138 [TVService(6)]: RadioWebStream:Dispose()
2012-10-06 06:49:16.612138 [TVService(6)]: Controller: dispose card:TBS 6981 BDA DVBS/S2 A Tuner/Demod
2012-10-06 06:49:16.615139 [TVService(6)]: dvb:Decompose
2012-10-06 06:49:16.617139 [TVService(6)]: tvcard:FreeAllSubChannels
2012-10-06 06:49:16.618139 [TVService(6)]:  stop
2012-10-06 06:49:25.231631 [RTSP Streaming thread(17)]: RTSP: Streamer stopped
2012-10-06 06:49:36.701287 [(4)]: Setting up EventWaitHandle with name: Global\MPTVServiceInitializedEvent
2012-10-06 06:49:36.979303 [(6)]: TV service: Starting
2012-10-06 06:49:36.981303 [TVService(6)]: TVService v1.2.3.0 is starting up on Windows 7 ( Service Pack 1 ) [6.1.7601.65536]
2012-10-06 06:49:36.982304 [TVService(6)]: Build: 1.2.3.0
2012-10-06 06:49:36.984304 [TVService(6)]: Controller: Initializing TVServer
2012-10-06 06:49:36.985304 [TVService(6)]: Controller: 1 init attempt
2012-10-06 06:49:36.985304 [PowerEventThread(9)]: TV service PowerEventThread message loop is running

I'm posting the rest as attachments.

Thanks.

 

[mm1352000]

Hello again

The way I identify this problem is by looking at the lines in the tv.log that look like this:

...dvb:GetNewSubChannel...

That is when the TV Server is calling out to TsWriter to make a space to timeshift or record an additional channel. TV Server will wait forever for TsWriter to respond and say "okay, go ahead and tune the channel"... but TsWriter just never responds. This is why it is called "deadlock".

If you look at the last successful tune, it was "Rohde & Schwarz TEST" by the EPG grabber.
This is why I am saying it is an issue with the EPG grabber causing TsWriter to loose control. This in tern causes the whole TV Server to deadlock.

mm