[confirm] DVB-S stops working after a while - More User have that problem (1 Viewer)

[mm1352000]

From the logs...
[collapse]
[2013-12-30 15:32:36,865] [Log ] [DVB EPG timer] [INFO ] - dvbs: TuneVBS:tv:ORF ORF III Freq:12663000 ONID:1 TSID:1115 SID:13101 PMT:0x44D FTA:False LCN:10000 SymbolRate:22000 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
...
[2013-12-30 15:32:40,985] [Log ] [8 ] [DEBUG] - TechnoTrend: OnDisplayMenu/List; 5 items; wLength: 105; pStringArray: 149462291
[2013-12-30 15:32:40,990] [Log ] [8 ] [DEBUG] - TechnoTrend: 0: Cryptoworks
[2013-12-30 15:32:40,994] [Log ] [8 ] [DEBUG] - TechnoTrend: 1:
[2013-12-30 15:32:40,998] [Log ] [8 ] [DEBUG] - TechnoTrend: 2:
[2013-12-30 15:32:41,006] [Log ] [8 ] [DEBUG] - TechnoTrend: 3: Keine Authorisation zum Sehen des Programms.
[2013-12-30 15:32:41,011] [Log ] [8 ] [DEBUG] - TechnoTrend: 4: Bitte kontaktieren Sie den Kundenservice.
[2013-12-30 15:33:08,983] [EPG ] [3 ] [INFO ] - EpgCard: allow grabbing for 30,0147168 seconds on card 4
[2013-12-30 15:33:23,065] [Log ] [8 ] [DEBUG] - TechnoTrend: OnDisplayMenu() exception: System.Net.Sockets.SocketException (0x80004005): Ein Verbindungsversuch ist fehlgeschlagen, da die Gegenstelle nach einer bestimmten Zeitspanne nicht richtig reagiert hat, oder die hergestellte Verbindung war fehlerhaft, da der verbundene Host nicht reagiert hat 53.2.172.238:57235
...
[2013-12-30 15:51:48,174] [Log ] [DVB EPG timer] [DEBUG] - WaitForPMT: Timed out waiting for PMT after 10,0045723 seconds. Increase the PMT timeout value?[/collapse]

So it looks like ORF III again.

Just found in a telehone call with technisat out, that there is a small difference in the way ORF x and ORF III is crypted.

Where ORF x is only cyrpted by Cyroptoworks standard D05 and D95. ORF III uses D05, D95 and D98. Perhaps that helps???

This is interesting... but it doesn't really mean anything for TV Server. When we ask for a channel to be decrypted, we only pass the service ID to the TT API (ie. nothing with the CAS ID). In all cases for ORF III we see:

[2013-12-30 15:32:38,008] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: slot 0 changed
[2013-12-30 15:32:38,012] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: CI statuslotModuleOk
[2013-12-30 15:32:38,016] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: CI text :TechniCrypt B2C
[2013-12-30 15:32:38,020] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: ca system id :D05
[2013-12-30 15:32:38,023] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: DescrambleMultiple1)
[2013-12-30 15:32:38,027] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: DescrambleMultiple: serviceId:13101
[2013-12-30 15:32:38,031] [Log ] [DVB EPG timer] [DEBUG] - $ OnCaChange slot:255 reply:E status:0
[2013-12-30 15:32:38,035] [Log ] [DVB EPG timer] [DEBUG] - $ CI: SetProgram OK
[2013-12-30 15:32:38,817] [Log ] [DVB EPG timer] [DEBUG] - $ OnCaChange slot:255 reply:E status:0
[2013-12-30 15:32:38,821] [Log ] [DVB EPG timer] [DEBUG] - $ CI: SetProgram OK
[2013-12-30 15:32:38,826] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: services decodeduccess 1
[2013-12-30 15:32:38,830] [Log ] [DVB EPG timer] [INFO ] - TechnoTrend IsCamReady(): IsCamPresent:True, IsCamReady:True

So there is the D05... but I can't see any difference between successful and failed decryption.
Maybe that would be interesting for TechnoTrend to know... but to me this seems like a problem with the CAM.

mm

 

[ramu]

Hi mm,

here are new logs for You...

ramu

 

[mm1352000]

Hello again ramu

These logs are similar... but not exactly the same. I see two cases where ORF III caused the CAM messages... but it seems like TV Server was able to continue to use the CAM without problem (!!!):

2014-01-07 09:47:26
[collapse]
[2014-01-07 09:47:26,345] [EPG ] [DVB EPG timer] [INFO ] - Grab for card:#4 transponder #35/36 channel: ORF III
[2014-01-07 09:47:26,349] [EPG ] [DVB EPG timer] [INFO ] - EpgCard: grab epg on card: #4 transponder: #34 ch:ORF III
[2014-01-07 09:47:26,359] [Log ] [DVB EPG timer] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=926, tuningdetails=DVBS:tv:ORF ORF III Freq:12663000 ONID:1 TSID:1115 SID:13101 PMT:0x44D FTA:False LCN:10000 SymbolRate:22000 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
[2014-01-07 09:47:26,362] [Log ] [DVB EPG timer] [INFO ] - card: Tune on card 4 to subchannel ORF III
[2014-01-07 09:47:26,366] [Log ] [DVB EPG timer] [DEBUG] - card: user: epg:4:-1 tune DVBS:tv:ORF ORF III Freq:12663000 ONID:1 TSID:1115 SID:13101 PMT:0x44D FTA:False LCN:10000 SymbolRate:22000 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
[2014-01-07 09:47:26,375] [Log ] [DVB EPG timer] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2014-01-07 09:47:26,378] [Log ] [DVB EPG timer] [INFO ] - dvbs: TuneVBS:tv:ORF ORF III Freq:12663000 ONID:1 TSID:1115 SID:13101 PMT:0x44D FTA:False LCN:10000 SymbolRate:22000 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
[2014-01-07 09:47:26,381] [Log ] [DVB EPG timer] [INFO ] - dvbs: TuneVBS:tv:ORF ORF III Freq:12663000 ONID:1 TSID:1115 SID:13101 PMT:0x44D FTA:False LCN:10000 SymbolRate:22000 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
[2014-01-07 09:47:26,385] [Log ] [DVB EPG timer] [INFO ] - dvb:GetNewSubChannel:0 #0
[2014-01-07 09:47:26,389] [Log ] [DVB EPG timer] [INFO ] - TvDvbChannel ctor new subchIndex:0
[2014-01-07 09:47:26,392] [Log ] [DVB EPG timer] [INFO ] - card: AddTuneEvent card: 4 / subch: 0
[2014-01-07 09:47:26,395] [Log ] [DVB EPG timer] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2014-01-07 09:47:26,398] [Log ] [DVB EPG timer] [INFO ] - Technotrend DVB-S2 modulation set to:ModNotSet
[2014-01-07 09:47:26,401] [Log ] [DVB EPG timer] [INFO ] - Technotrend DVB-S2 Pilot set to:NotSet
[2014-01-07 09:47:26,404] [Log ] [DVB EPG timer] [INFO ] - Technotrend DVB-S2 RollOff set to:NotSet
[2014-01-07 09:47:26,406] [Log ] [DVB EPG timer] [INFO ] - Technotrend DVB-S2 fec set to:Rate5_6
[2014-01-07 09:47:26,409] [Log ] [DVB EPG timer] [INFO ] - dvbs:channel modulation is set to ModNotSet
[2014-01-07 09:47:26,412] [Log ] [DVB EPG timer] [INFO ] - dvbs:channel FECRate is set to Rate5_6
[2014-01-07 09:47:26,415] [Log ] [DVB EPG timer] [INFO ] - TechnoTrend SendDiseqcCommand() diseqc:None, antenna:0 frequency:12663000, polarisation:LinearH hiband:True
[2014-01-07 09:47:26,678] [Log ] [DVB EPG timer] [INFO ] - TechnoTrend: Diseqc Command Send
[2014-01-07 09:47:26,782] [Log ] [DVB EPG timer] [INFO ] - dvbubmiting tunerequest Channel:ORF III subChannel:0
[2014-01-07 09:47:26,785] [Log ] [DVB EPG timer] [INFO ] - dvb:using existing subchannel:0
[2014-01-07 09:47:26,789] [Log ] [DVB EPG timer] [INFO ] - dvbubmit tunerequest size:1 new:0
[2014-01-07 09:47:26,792] [Log ] [DVB EPG timer] [INFO ] - subch:0 OnBeforeTune
[2014-01-07 09:47:26,796] [Log ] [DVB EPG timer] [INFO ] - dvbubmit tunerequest calling put_TuneRequest
[2014-01-07 09:47:26,800] [Log ] [DVB EPG timer] [INFO ] - dvbubmit tunerequest done calling put_TuneRequest
[2014-01-07 09:47:26,803] [Log ] [DVB EPG timer] [INFO ] - subch:0 OnAfterTune
[2014-01-07 09:47:26,807] [Log ] [DVB EPG timer] [INFO ] - RunGraph
[2014-01-07 09:47:26,810] [Log ] [DVB EPG timer] [INFO ] - subch:0 OnGraphStart
[2014-01-07 09:47:26,813] [Log ] [DVB EPG timer] [INFO ] - dvb: RunGraph
[2014-01-07 09:47:27,338] [Log ] [DVB EPG timer] [INFO ] - dvb: LockInOnSignal ok
[2014-01-07 09:47:27,341] [Log ] [DVB EPG timer] [INFO ] - subch:0 OnGraphStarted
[2014-01-07 09:47:27,344] [Log ] [DVB EPG timer] [INFO ] - subch:0 SetupPmtGrabberid 44D sid:332D
[2014-01-07 09:47:27,348] [Log ] [DVB EPG timer] [INFO ] - subch:0 set pmt grabber pmt:44D sid:332D
[2014-01-07 09:47:27,352] [Log ] [DVB EPG timer] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2014-01-07 09:47:27,355] [Log ] [DVB EPG timer] [DEBUG] - WaitForPMT: Waiting for PMT 44D
[2014-01-07 09:47:27,740] [Log ] [23 ] [INFO ] - subch:0 OnPMTReceived() pmt:44D ran:True dynamic:False
[2014-01-07 09:47:27,743] [Log ] [DVB EPG timer] [DEBUG] - WaitForPMT: Found PMT after 0,3880222 seconds.
[2014-01-07 09:47:27,747] [Log ] [DVB EPG timer] [INFO ] - subch:0 SendPmt:332D 332D FFFFFFFF 0
[2014-01-07 09:47:27,750] [Log ] [DVB EPG timer] [INFO ] - Decode pmt
[2014-01-07 09:47:27,753] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 d 95 e0 dc
[2014-01-07 09:47:27,756] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 6 48 e0 6e
[2014-01-07 09:47:27,759] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 d 5 e0 d2
[2014-01-07 09:47:27,763] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 9 c4 e1 e0
[2014-01-07 09:47:27,766] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 17 2 e1 36
[2014-01-07 09:47:27,769] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 18 33 e1 9a
[2014-01-07 09:47:27,772] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 9 8c e1 ea
[2014-01-07 09:47:27,775] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 d 98 e0 dd
[2014-01-07 09:47:27,778] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 6 50 e0 6f
[2014-01-07 09:47:27,781] [Log ] [DVB EPG timer] [INFO ] - Set descriptor data with length 3
[2014-01-07 09:47:27,783] [Log ] [DVB EPG timer] [INFO ] - Set descriptor data with length 3
[2014-01-07 09:47:27,787] [Log ] [DVB EPG timer] [INFO ] - PROBLEM : descriptor lengths dont match 6 9
[2014-01-07 09:47:27,790] [Log ] [DVB EPG timer] [INFO ] - Set descriptor data with length 7
[2014-01-07 09:47:27,793] [Log ] [DVB EPG timer] [INFO ] - PROBLEM : descriptor lengths dont match 3 10
[2014-01-07 09:47:27,796] [Log ] [DVB EPG timer] [INFO ] - Set descriptor data with length 3
[2014-01-07 09:47:27,799] [Log ] [DVB EPG timer] [INFO ] - subch:0 SendPMT version:0 len:131 13101
[2014-01-07 09:47:27,802] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: slot 0 changed
[2014-01-07 09:47:27,805] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: CI statuslotModuleOk
[2014-01-07 09:47:27,808] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: CI text :TechniCrypt B2C
[2014-01-07 09:47:27,811] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: ca system id 05
[2014-01-07 09:47:27,814] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: DescrambleMultiple1)
[2014-01-07 09:47:27,818] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: DescrambleMultiple: serviceId:13101
[2014-01-07 09:47:27,821] [Log ] [DVB EPG timer] [DEBUG] - $ OnCaChange slot:255 reply:E status:0
[2014-01-07 09:47:27,824] [Log ] [DVB EPG timer] [DEBUG] - $ CI: SetProgram OK
[2014-01-07 09:47:28,217] [Log ] [DVB EPG timer] [DEBUG] - $ OnCaChange slot:255 reply:E status:0
[2014-01-07 09:47:28,221] [Log ] [DVB EPG timer] [DEBUG] - $ CI: SetProgram OK
[2014-01-07 09:47:28,225] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: services decodeduccess 1
[2014-01-07 09:47:28,229] [Log ] [DVB EPG timer] [INFO ] - TechnoTrend IsCamReady(): IsCamPresent:True, IsCamReady:True
[2014-01-07 09:47:28,232] [Log ] [DVB EPG timer] [INFO ] - subch:0 cam flags:True
[2014-01-07 09:47:28,235] [Log ] [DVB EPG timer] [INFO ] - subch:0 SetMpegPidMapping
[2014-01-07 09:47:28,238] [Log ] [DVB EPG timer] [INFO ] - subch:0 pid:3F2 pcr
[2014-01-07 09:47:28,241] [Log ] [DVB EPG timer] [INFO ] - subch:0 pid:44D pmt
[2014-01-07 09:47:28,244] [Log ] [DVB EPG timer] [INFO ] - subch:0 pid:3F2 video type:MPEG-2
[2014-01-07 09:47:28,247] [Log ] [DVB EPG timer] [INFO ] - subch:0 map pid:3F2 video type:MPEG-2
[2014-01-07 09:47:28,250] [Log ] [DVB EPG timer] [INFO ] - subch:0 pid:3F3 audio lang:ger type:MPEG-2
[2014-01-07 09:47:28,253] [Log ] [DVB EPG timer] [INFO ] - subch:0 map pid:3F3 audio lang:ger type:MPEG-2
[2014-01-07 09:47:28,256] [Log ] [DVB EPG timer] [INFO ] - subch:0 pid:3F5 teletext type:6
[2014-01-07 09:47:28,259] [Log ] [DVB EPG timer] [INFO ] - subch:0 map pid:3F5 teletext type:6
[2014-01-07 09:47:28,262] [Log ] [DVB EPG timer] [INFO ] - subch:0 pid:3F7 type:6
[2014-01-07 09:47:28,265] [Log ] [DVB EPG timer] [DEBUG] - OnPMTReceived: MDAPI disabled. Possible reasons are _mdplugs=null or provider not listed
[2014-01-07 09:47:28,268] [Log ] [DVB EPG timer] [INFO ] - subch:0 stop tif
[2014-01-07 09:47:28,271] [Log ] [DVB EPG timer] [DEBUG] - WaitForPmt: PMT handling took 0,5240299 seconds.
[2014-01-07 09:47:28,299] [Log ] [DVB EPG timer] [DEBUG] - card: Tuner locked: True
[2014-01-07 09:47:28,302] [Log ] [DVB EPG timer] [INFO ] - **************************************************
[2014-01-07 09:47:28,306] [Log ] [DVB EPG timer] [INFO ] - ***** SIGNAL LEVEL: 73, SIGNAL QUALITY: 100 *****
[2014-01-07 09:47:28,309] [Log ] [DVB EPG timer] [INFO ] - **************************************************
[2014-01-07 09:47:28,312] [Log ] [DVB EPG timer] [DEBUG] - card: tuned user: epg subchannel: 0
[2014-01-07 09:47:28,315] [Log ] [DVB EPG timer] [INFO ] - user:epg add
[2014-01-07 09:47:28,317] [Log ] [DVB EPG timer] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=926, tuningdetails=DVBS:tv:ORF ORF III Freq:12663000 ONID:1 TSID:1115 SID:13101 PMT:0x44D FTA:False LCN:10000 SymbolRate:22000 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
[2014-01-07 09:47:28,320] [Log ] [DVB EPG timer] [INFO ] - card: SignalTuneEvent card: 4 / subch: 0
[2014-01-07 09:47:28,323] [Log ] [DVB EPG timer] [INFO ] - Controller: GrabEpg on card ID == 4
[2014-01-07 09:47:28,326] [EPG ] [DVB EPG timer] [INFO ] - EpgGrabbing: Start
[2014-01-07 09:47:28,331] [Log ] [DVB EPG timer] [INFO ] - dvb:grab epg...
[2014-01-07 09:47:28,335] [EPG ] [DVB EPG timer] [INFO ] - EpgCard: card: 4 starting to grab DVBS:tv:ORF ORF III Freq:12663000 ONID:1 TSID:1115 SID:13101 PMT:0x44D FTA:False LCN:10000 SymbolRate:22000 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
[2014-01-07 09:47:30,151] [Log ] [24 ] [DEBUG] - TechnoTrend: OnDisplayMenu/List; 5 items; wLength: 105; pStringArray: 176392267
[2014-01-07 09:47:30,154] [Log ] [24 ] [DEBUG] - TechnoTrend: 0: Cryptoworks
[2014-01-07 09:47:30,157] [Log ] [24 ] [DEBUG] - TechnoTrend: 1:
[2014-01-07 09:47:30,160] [Log ] [24 ] [DEBUG] - TechnoTrend: 2:
[2014-01-07 09:47:30,164] [Log ] [24 ] [DEBUG] - TechnoTrend: 3: Keine Authorisation zum Sehen des Programms.
[2014-01-07 09:47:30,167] [Log ] [24 ] [DEBUG] - TechnoTrend: 4: Bitte kontaktieren Sie den Kundenservice.
[2014-01-07 09:47:58,345] [EPG ] [30 ] [INFO ] - EpgCard: allow grabbing for 30,0077164 seconds on card 4
[2014-01-07 09:48:12,171] [Log ] [24 ] [DEBUG] - TechnoTrend: OnDisplayMenu() exception: System.Net.Sockets.SocketException (0x80004005): Ein Verbindungsversuch ist fehlgeschlagen, da die Gegenstelle nach einer bestimmten Zeitspanne nicht richtig reagiert hat, oder die hergestellte Verbindung war fehlerhaft, da der verbundene Host nicht reagiert hat 53.2.172.238:62239

Server stack trace:
bei System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
bei System.Net.Sockets.Socket.Connect(EndPoint remoteEP)
bei System.Runtime.Remoting.Channels.RemoteConnection.CreateNewSocket(EndPoint ipEndPoint)
bei System.Runtime.Remoting.Channels.RemoteConnection.CreateNewSocket()
bei System.Runtime.Remoting.Channels.RemoteConnection.GetSocket()
bei System.Runtime.Remoting.Channels.SocketCache.GetSocket(String machinePortAndSid, Boolean openNew)
bei System.Runtime.Remoting.Channels.Tcp.TcpClientTransportSink.SendRequestWithRetry(IMessage msg, ITransportHeaders requestHeaders, Stream requestStream)
bei System.Runtime.Remoting.Channels.Tcp.TcpClientTransportSink.ProcessMessage(IMessage msg, ITransportHeaders requestHeaders, Stream requestStream, ITransportHeaders& responseHeaders, Stream& responseStream)
bei System.Runtime.Remoting.Channels.BinaryClientFormatterSink.SyncProcessMessage(IMessage msg)

Exception rethrown at [0]:
bei System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
bei System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
bei TvLibrary.Interfaces.CiMenuCallbackSink.FireCiMenuCallback(CiMenu Menu)
bei TvService.TVController.CheckForCallback()
bei TvService.TVController.OnCiMenuChoice(Int32 nChoice, String lpszText)
bei TvLibrary.Implementations.DVB.TechnoTrendAPI.onDisplayMenuOrList(IntPtr Context, Byte nSlot, Int16 wItems, IntPtr pStringArray, Int16 wLength)[/collapse]

2014-01-08 08:22:40
[collapse]
[2014-01-08 08:22:40,322] [EPG ] [DVB EPG timer] [INFO ] - Grab for card:#4 transponder #35/36 channel: ORF III
[2014-01-08 08:22:40,326] [EPG ] [DVB EPG timer] [INFO ] - EpgCard: grab epg on card: #4 transponder: #34 ch:ORF III
[2014-01-08 08:22:40,336] [Log ] [DVB EPG timer] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=1502, tuningdetails=DVBS:tv:ORF ORF III Freq:12663000 ONID:1 TSID:1115 SID:13101 PMT:0x44D FTA:False LCN:10000 SymbolRate:22000 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
[2014-01-08 08:22:40,340] [Log ] [DVB EPG timer] [INFO ] - card: Tune on card 4 to subchannel ORF III
[2014-01-08 08:22:40,343] [Log ] [DVB EPG timer] [DEBUG] - card: user: epg:4:-1 tune DVBS:tv:ORF ORF III Freq:12663000 ONID:1 TSID:1115 SID:13101 PMT:0x44D FTA:False LCN:10000 SymbolRate:22000 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
[2014-01-08 08:22:40,353] [Log ] [DVB EPG timer] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2014-01-08 08:22:40,356] [Log ] [DVB EPG timer] [INFO ] - dvbs: TuneVBS:tv:ORF ORF III Freq:12663000 ONID:1 TSID:1115 SID:13101 PMT:0x44D FTA:False LCN:10000 SymbolRate:22000 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
[2014-01-08 08:22:40,360] [Log ] [DVB EPG timer] [INFO ] - dvbs: TuneVBS:tv:ORF ORF III Freq:12663000 ONID:1 TSID:1115 SID:13101 PMT:0x44D FTA:False LCN:10000 SymbolRate:22000 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
[2014-01-08 08:22:40,364] [Log ] [DVB EPG timer] [INFO ] - dvb:GetNewSubChannel:0 #0
[2014-01-08 08:22:40,370] [Log ] [DVB EPG timer] [INFO ] - TvDvbChannel ctor new subchIndex:0
[2014-01-08 08:22:40,374] [Log ] [DVB EPG timer] [INFO ] - card: AddTuneEvent card: 4 / subch: 0
[2014-01-08 08:22:40,377] [Log ] [DVB EPG timer] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2014-01-08 08:22:40,381] [Log ] [DVB EPG timer] [INFO ] - Technotrend DVB-S2 modulation set to:ModNotSet
[2014-01-08 08:22:40,384] [Log ] [DVB EPG timer] [INFO ] - Technotrend DVB-S2 Pilot set to:NotSet
[2014-01-08 08:22:40,387] [Log ] [DVB EPG timer] [INFO ] - Technotrend DVB-S2 RollOff set to:NotSet
[2014-01-08 08:22:40,391] [Log ] [DVB EPG timer] [INFO ] - Technotrend DVB-S2 fec set to:Rate5_6
[2014-01-08 08:22:40,394] [Log ] [DVB EPG timer] [INFO ] - dvbs:channel modulation is set to ModNotSet
[2014-01-08 08:22:40,397] [Log ] [DVB EPG timer] [INFO ] - dvbs:channel FECRate is set to Rate5_6
[2014-01-08 08:22:40,400] [Log ] [DVB EPG timer] [INFO ] - TechnoTrend SendDiseqcCommand() diseqc:None, antenna:0 frequency:12663000, polarisation:LinearH hiband:True
[2014-01-08 08:22:40,664] [Log ] [DVB EPG timer] [INFO ] - TechnoTrend: Diseqc Command Send
[2014-01-08 08:22:40,767] [Log ] [DVB EPG timer] [INFO ] - dvbubmiting tunerequest Channel:ORF III subChannel:0
[2014-01-08 08:22:40,770] [Log ] [DVB EPG timer] [INFO ] - dvb:using existing subchannel:0
[2014-01-08 08:22:40,773] [Log ] [DVB EPG timer] [INFO ] - dvbubmit tunerequest size:1 new:0
[2014-01-08 08:22:40,776] [Log ] [DVB EPG timer] [INFO ] - subch:0 OnBeforeTune
[2014-01-08 08:22:40,779] [Log ] [DVB EPG timer] [INFO ] - dvbubmit tunerequest calling put_TuneRequest
[2014-01-08 08:22:40,782] [Log ] [DVB EPG timer] [INFO ] - dvbubmit tunerequest done calling put_TuneRequest
[2014-01-08 08:22:40,785] [Log ] [DVB EPG timer] [INFO ] - subch:0 OnAfterTune
[2014-01-08 08:22:40,788] [Log ] [DVB EPG timer] [INFO ] - RunGraph
[2014-01-08 08:22:40,792] [Log ] [DVB EPG timer] [INFO ] - subch:0 OnGraphStart
[2014-01-08 08:22:40,795] [Log ] [DVB EPG timer] [INFO ] - dvb: RunGraph
[2014-01-08 08:22:40,999] [Log ] [DVB EPG timer] [INFO ] - dvb: LockInOnSignal ok
[2014-01-08 08:22:41,003] [Log ] [DVB EPG timer] [INFO ] - subch:0 OnGraphStarted
[2014-01-08 08:22:41,006] [Log ] [DVB EPG timer] [INFO ] - subch:0 SetupPmtGrabberid 44D sid:332D
[2014-01-08 08:22:41,010] [Log ] [DVB EPG timer] [INFO ] - subch:0 set pmt grabber pmt:44D sid:332D
[2014-01-08 08:22:41,013] [Log ] [DVB EPG timer] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2014-01-08 08:22:41,016] [Log ] [DVB EPG timer] [DEBUG] - WaitForPMT: Waiting for PMT 44D
[2014-01-08 08:22:41,255] [Log ] [23 ] [INFO ] - subch:0 OnPMTReceived() pmt:44D ran:True dynamic:False
[2014-01-08 08:22:41,258] [Log ] [DVB EPG timer] [DEBUG] - WaitForPMT: Found PMT after 0,2420139 seconds.
[2014-01-08 08:22:41,262] [Log ] [DVB EPG timer] [INFO ] - subch:0 SendPmt:332D 332D FFFFFFFF 0
[2014-01-08 08:22:41,265] [Log ] [DVB EPG timer] [INFO ] - Decode pmt
[2014-01-08 08:22:41,268] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 d 95 e0 dc
[2014-01-08 08:22:41,271] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 6 48 e0 6e
[2014-01-08 08:22:41,274] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 d 5 e0 d2
[2014-01-08 08:22:41,278] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 9 c4 e1 e0
[2014-01-08 08:22:41,281] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 17 2 e1 36
[2014-01-08 08:22:41,284] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 18 33 e1 9a
[2014-01-08 08:22:41,287] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 9 8c e1 ea
[2014-01-08 08:22:41,290] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 d 98 e0 dd
[2014-01-08 08:22:41,293] [Log ] [DVB EPG timer] [INFO ] - descr1 len:6 9 4 6 50 e0 6f
[2014-01-08 08:22:41,296] [Log ] [DVB EPG timer] [INFO ] - Set descriptor data with length 3
[2014-01-08 08:22:41,299] [Log ] [DVB EPG timer] [INFO ] - Set descriptor data with length 3
[2014-01-08 08:22:41,302] [Log ] [DVB EPG timer] [INFO ] - PROBLEM : descriptor lengths dont match 6 9
[2014-01-08 08:22:41,305] [Log ] [DVB EPG timer] [INFO ] - Set descriptor data with length 7
[2014-01-08 08:22:41,307] [Log ] [DVB EPG timer] [INFO ] - PROBLEM : descriptor lengths dont match 3 10
[2014-01-08 08:22:41,310] [Log ] [DVB EPG timer] [INFO ] - Set descriptor data with length 3
[2014-01-08 08:22:41,313] [Log ] [DVB EPG timer] [INFO ] - subch:0 SendPMT version:0 len:131 13101
[2014-01-08 08:22:41,316] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: slot 0 changed
[2014-01-08 08:22:41,320] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: CI statuslotModuleOk
[2014-01-08 08:22:41,324] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: CI text :TechniCrypt B2C
[2014-01-08 08:22:41,327] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: ca system id 05
[2014-01-08 08:22:41,329] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: DescrambleMultiple1)
[2014-01-08 08:22:41,332] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: DescrambleMultiple: serviceId:13101
[2014-01-08 08:22:41,335] [Log ] [DVB EPG timer] [DEBUG] - $ OnCaChange slot:255 reply:E status:0
[2014-01-08 08:22:41,338] [Log ] [DVB EPG timer] [DEBUG] - $ CI: SetProgram OK
[2014-01-08 08:22:41,665] [Log ] [DVB EPG timer] [DEBUG] - $ OnCaChange slot:255 reply:E status:0
[2014-01-08 08:22:41,669] [Log ] [DVB EPG timer] [DEBUG] - $ CI: SetProgram OK
[2014-01-08 08:22:41,672] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: services decodeduccess 1
[2014-01-08 08:22:41,675] [Log ] [DVB EPG timer] [INFO ] - TechnoTrend IsCamReady(): IsCamPresent:True, IsCamReady:True
[2014-01-08 08:22:41,679] [Log ] [DVB EPG timer] [INFO ] - subch:0 cam flags:True
[2014-01-08 08:22:41,683] [Log ] [DVB EPG timer] [INFO ] - subch:0 SetMpegPidMapping
[2014-01-08 08:22:41,686] [Log ] [DVB EPG timer] [INFO ] - subch:0 pid:3F2 pcr
[2014-01-08 08:22:41,690] [Log ] [DVB EPG timer] [INFO ] - subch:0 pid:44D pmt
[2014-01-08 08:22:41,693] [Log ] [DVB EPG timer] [INFO ] - subch:0 pid:3F2 video type:MPEG-2
[2014-01-08 08:22:41,696] [Log ] [DVB EPG timer] [INFO ] - subch:0 map pid:3F2 video type:MPEG-2
[2014-01-08 08:22:41,699] [Log ] [DVB EPG timer] [INFO ] - subch:0 pid:3F3 audio lang:ger type:MPEG-2
[2014-01-08 08:22:41,702] [Log ] [DVB EPG timer] [INFO ] - subch:0 map pid:3F3 audio lang:ger type:MPEG-2
[2014-01-08 08:22:41,704] [Log ] [DVB EPG timer] [INFO ] - subch:0 pid:3F5 teletext type:6
[2014-01-08 08:22:41,707] [Log ] [DVB EPG timer] [INFO ] - subch:0 map pid:3F5 teletext type:6
[2014-01-08 08:22:41,710] [Log ] [DVB EPG timer] [INFO ] - subch:0 pid:3F7 type:6
[2014-01-08 08:22:41,713] [Log ] [DVB EPG timer] [DEBUG] - OnPMTReceived: MDAPI disabled. Possible reasons are _mdplugs=null or provider not listed
[2014-01-08 08:22:41,715] [Log ] [DVB EPG timer] [INFO ] - subch:0 stop tif
[2014-01-08 08:22:41,718] [Log ] [DVB EPG timer] [DEBUG] - WaitForPmt: PMT handling took 0,4560261 seconds.
[2014-01-08 08:22:41,748] [Log ] [DVB EPG timer] [DEBUG] - card: Tuner locked: True
[2014-01-08 08:22:41,752] [Log ] [DVB EPG timer] [INFO ] - **************************************************
[2014-01-08 08:22:41,754] [Log ] [DVB EPG timer] [INFO ] - ***** SIGNAL LEVEL: 83, SIGNAL QUALITY: 100 *****
[2014-01-08 08:22:41,757] [Log ] [DVB EPG timer] [INFO ] - **************************************************
[2014-01-08 08:22:41,761] [Log ] [DVB EPG timer] [DEBUG] - card: tuned user: epg subchannel: 0
[2014-01-08 08:22:41,764] [Log ] [DVB EPG timer] [INFO ] - user:epg add
[2014-01-08 08:22:41,768] [Log ] [DVB EPG timer] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=1502, tuningdetails=DVBS:tv:ORF ORF III Freq:12663000 ONID:1 TSID:1115 SID:13101 PMT:0x44D FTA:False LCN:10000 SymbolRate:22000 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
[2014-01-08 08:22:41,771] [Log ] [DVB EPG timer] [INFO ] - card: SignalTuneEvent card: 4 / subch: 0
[2014-01-08 08:22:41,774] [Log ] [DVB EPG timer] [INFO ] - Controller: GrabEpg on card ID == 4
[2014-01-08 08:22:41,777] [EPG ] [DVB EPG timer] [INFO ] - EpgGrabbing: Start
[2014-01-08 08:22:41,781] [Log ] [DVB EPG timer] [INFO ] - dvb:grab epg...
[2014-01-08 08:22:41,785] [EPG ] [DVB EPG timer] [INFO ] - EpgCard: card: 4 starting to grab DVBS:tv:ORF ORF III Freq:12663000 ONID:1 TSID:1115 SID:13101 PMT:0x44D FTA:False LCN:10000 SymbolRate:22000 Modulation:ModNotSet Polarisation:LinearH InnerFecRate:Rate5_6 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
[2014-01-08 08:22:43,899] [Log ] [24 ] [DEBUG] - TechnoTrend: OnDisplayMenu/List; 5 items; wLength: 105; pStringArray: 176392267
[2014-01-08 08:22:43,902] [Log ] [24 ] [DEBUG] - TechnoTrend: 0: Cryptoworks
[2014-01-08 08:22:43,905] [Log ] [24 ] [DEBUG] - TechnoTrend: 1:
[2014-01-08 08:22:43,908] [Log ] [24 ] [DEBUG] - TechnoTrend: 2:
[2014-01-08 08:22:43,912] [Log ] [24 ] [DEBUG] - TechnoTrend: 3: Keine Authorisation zum Sehen des Programms.
[2014-01-08 08:22:43,915] [Log ] [24 ] [DEBUG] - TechnoTrend: 4: Bitte kontaktieren Sie den Kundenservice.
[2014-01-08 08:23:11,811] [EPG ] [26 ] [INFO ] - EpgCard: allow grabbing for 30,0227172 seconds on card 4
[2014-01-08 08:23:25,923] [Log ] [24 ] [DEBUG] - TechnoTrend: OnDisplayMenu() exception: System.Net.Sockets.SocketException (0x80004005): Ein Verbindungsversuch ist fehlgeschlagen, da die Gegenstelle nach einer bestimmten Zeitspanne nicht richtig reagiert hat, oder die hergestellte Verbindung war fehlerhaft, da der verbundene Host nicht reagiert hat 53.2.172.238:50576

Server stack trace:
bei System.Net.Sockets.Socket.DoConnect(EndPoint endPointSnapshot, SocketAddress socketAddress)
bei System.Net.Sockets.Socket.Connect(EndPoint remoteEP)
bei System.Runtime.Remoting.Channels.RemoteConnection.CreateNewSocket(EndPoint ipEndPoint)
bei System.Runtime.Remoting.Channels.RemoteConnection.CreateNewSocket()
bei System.Runtime.Remoting.Channels.RemoteConnection.GetSocket()
bei System.Runtime.Remoting.Channels.SocketCache.GetSocket(String machinePortAndSid, Boolean openNew)
bei System.Runtime.Remoting.Channels.Tcp.TcpClientTransportSink.SendRequestWithRetry(IMessage msg, ITransportHeaders requestHeaders, Stream requestStream)
bei System.Runtime.Remoting.Channels.Tcp.TcpClientTransportSink.ProcessMessage(IMessage msg, ITransportHeaders requestHeaders, Stream requestStream, ITransportHeaders& responseHeaders, Stream& responseStream)
bei System.Runtime.Remoting.Channels.BinaryClientFormatterSink.SyncProcessMessage(IMessage msg)

Exception rethrown at [0]:
bei System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage reqMsg, IMessage retMsg)
bei System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData& msgData, Int32 type)
bei TvLibrary.Interfaces.CiMenuCallbackSink.FireCiMenuCallback(CiMenu Menu)
bei TvService.TVController.CheckForCallback()
bei TvService.TVController.OnCiMenuChoice(Int32 nChoice, String lpszText)
bei TvLibrary.Implementations.DVB.TechnoTrendAPI.onDisplayMenuOrList(IntPtr Context, Byte nSlot, Int16 wItems, IntPtr pStringArray, Int16 wLength)[/collapse]

Also interesting is what seems to be a new problem. When trying to decrypt RTL Crime, suddenly the TT API says:

[2014-01-08 09:30:13,148] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: slot 0 changed
[2014-01-08 09:30:13,151] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: CI statuslotModuleOk
[2014-01-08 09:30:13,153] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: CI text :TechniCrypt B2C
[2014-01-08 09:30:13,156] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: ca system id 05
[2014-01-08 09:30:13,159] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: DescrambleMultiple1)
[2014-01-08 09:30:13,162] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: DescrambleMultiple: serviceId:27
[2014-01-08 09:30:13,165] [Log ] [DVB EPG timer] [DEBUG] - $ OnCaChange slot:255 reply:E status:5
[2014-01-08 09:30:13,169] [Log ] [DVB EPG timer] [DEBUG] - $ CI: ERROR:etProgram failed !!! (no CA resource available)
[2014-01-08 09:30:13,279] [Log ] [DVB EPG timer] [DEBUG] - $ OnCaChange slot:255 reply:E status:5
[2014-01-08 09:30:13,283] [Log ] [DVB EPG timer] [DEBUG] - $ CI: ERROR:etProgram failed !!! (no CA resource available)
[2014-01-08 09:30:13,286] [Log ] [DVB EPG timer] [DEBUG] - TechnoTrend: services not decodeduccess ciStatus: -1
[2014-01-08 09:30:13,290] [Log ] [DVB EPG timer] [INFO ] - TechnoTrend IsCamReady(): IsCamPresent:True, IsCamReady:True
[2014-01-08 09:30:13,292] [Log ] [DVB EPG timer] [INFO ] - subch:0 SendPmt failed cam flags:True

I cannot see any reason for this. No exceptions. Nothing. The CI just suddenly starts to give this message.
In this case it looks like the CAM continues to allow streaming for free channels, but it fails to decrypt channels.

Did you try to remove and reinsert the CAM?

mm

 

[ramu]

Hi mm,

I talked today to technotrend, they said I should try the driver for MS mediacenter. I tried that before but had some problems .. Will comeback with results..

Meanwhile I updated zu 1.6 final, but I'm not sure if this RTL Crime topic belongs to that update because perhaps somebody at home added RTL Crime latly to my DVB-S group???

No, I didn't removed CAM this time, but it helped before... I'll doublecheck next time.

ramu

 

[ramu]

Result for DBA driver Technotrend 5.0.3.6 for MS Mediacenter:

DVB-S is running well but CI module is not recognized so no crypted channels viewable...

See logs:

I'll go back to normal bda driver...

ramu

 

[mm1352000]

Result for DBA driver Technotrend 5.0.3.6 for MS Mediacenter:

DVB-S is running well but CI module is not recognized so no crypted channels viewable...

See logs

The CI module is recognised. TV Server just doesn't think it is ready.

[2014-01-09 21:18:06,647] [Log ] [27 ] [DEBUG] - TechnoTrend: slot 0 changed
[2014-01-09 21:18:06,650] [Log ] [27 ] [DEBUG] - TechnoTrend: DescrambleMultiple1)
[2014-01-09 21:18:06,652] [Log ] [27 ] [DEBUG] - TechnoTrend: DescrambleMultiple: serviceId:13012
[2014-01-09 21:18:06,655] [Log ] [27 ] [DEBUG] - TechnoTrend: CI module inserted but not yet ready
[2014-01-09 21:18:06,657] [Log ] [27 ] [INFO ] - TechnoTrend IsCamReady(): IsCamPresent:True, IsCamReady:False
[2014-01-09 21:18:06,660] [Log ] [27 ] [INFO ] - subch:0 SendPmt failed cam flags:False

This means that the status is SlotModuleInserted, but never SlotCaOk or SlotModuleOk.

Please ask TechnoTrend about the difference between the two drivers. Maybe we're meant to use a different interface (which I don't know about) or the driver behaves differently.

mm

 

[ramu]

Hi mm,

a short update for You.

Meanwhile I'm in touch with technotrend. They are very helpful and trying to find the problem...

I updated to final 1.6 MP version and tried to install the technotrend MCE driver. Because the newer version (MCE version) does not work with normal win7 I chanced and went back to the older version. Not quite sure, I did that 2-3 times and now MP is running since more than 7 days without problems. Can You please have a look to the logs, also error log with this db epg-update problem. Can You see any diffenerces or problems there? And give me a hint if db is corruoted?

I asked technotrend for a compled list of driver files to check if a hybrid version of both driver versions is running on my system now. Realy I do not have any further idea what had be chanced and why Mp is running now? Could MP 1.6 final had changed anything?


Regards
ramu

 

[ramu]

Dear mm,

knowing You have a lot to do with 1.7 prerelease. But I hope You can just answer two questions ;-))

Technotrend is still investigating the problem. After up- and later downgrading the TT driver my system run stable but nobody knows why and if any part of newer driver-files had left over somewhere. So TT asked for a compled reinstall of all their drivers...

Afterwards the problem occured once more... Now we found that in some BDA drivers there is a addition file called LVUSBS64.sys listed by windows. TT can't answer why win7 put up this file to their driver. I think LVUSB.sys came with labtec webcam which is connected, too.

So first question: Did You ever saw something like that?

Also they are asking me if this problem only occurs on ORF III and no other channel. They are asking also for the following channel on same frequency:
- BTV
- GoTV
- L-TV/TVM
- LT1
- ServusTV
- Sixx Austria
- Welt der Wunder

All this channels were not in the epg grabbing list, I just added them waiting what will hapen...

Second question: Did You ever saw in my logs any other channel causing that problem and for what log entry I have to search for to find the first occures of that problem to report that to TT`?

Thanks and best wished
ramu

 

[mm1352000]

Hello ramu

Can You please have a look to the logs, also error log with this db epg-update problem. Can You see any diffenerces or problems there?

Sorry I don't understand. What exactly are you asking me to look for?

And give me a hint if db is corruoted?

It doesn't look like the database is corrupted.

Could MP 1.6 final had changed anything?

Unlikely. TV Server is in code freeze. No changes to TechnoTrend or BDA code.

Afterwards the problem occured once more... Now we found that in some BDA drivers there is a addition file called LVUSBS64.sys listed by windows. TT can't answer why win7 put up this file to their driver. I think LVUSB.sys came with labtec webcam which is connected, too.

So first question: Did You ever saw something like that?

No.

Also they are asking me if this problem only occurs on ORF III and no other channel. They are asking also for the following channel on same frequency:
- BTV
- GoTV
- L-TV/TVM
- LT1
- ServusTV
- Sixx Austria
- Welt der Wunder

All this channels were not in the epg grabbing list, I just added them waiting what will hapen...

Second question: Did You ever saw in my logs any other channel causing that problem...

No.

...and for what log entry I have to search for to find the first occures of that problem to report that to TT`?

Take a look at my previous posts in this thread and you'll see the answer. For example:
https://forum.team-mediaportal.com/...-have-that-problem.123171/page-3#post-1049580

Best regards,
mm