KNC1 DVB-C CI/CAM issue (1 Viewer)

F

faugusztin

New Member
May 12, 2011
3
0
Home Country
Slovakia Slovakia
MediaPortal Version: 1.1.3
MediaPortal Skin: none, using XBMC frontend
Windows Version: 7 Home Premium SP1
CPU Type: Core i3 530
HDD: Intel X25-M 80GB G1
Memory: 2x2GB (CMG4GX3M2A1600C7)
Motherboard: MSI H55M-ED55
Video Card: ZOTAC GeForce GT 430 ZONE (ZT-40601-20L)
Video Card Driver: 270.61
Sound Card: NVIDIA High Definition Audio (HDMI soundcard from GT430)
Sound Card AC3: no
Sound Card Driver: -
1. TV Card: KNC1 TV-Station DVB-C
1. TV Card Type: DVB-C
1. TV Card Driver: 2.1.1130.0 (from 30.11.2010)
2. TV Card:
2. TV Card Type:
2. TV Card Driver:
3. TV Card:
3. TV Card Type:
3. TV Card Driver:
4. TV Card:
4. TV Card Type:
4. TV Card Driver:
MPEG2 Video Codec:
MPEG2 Audio Codec:
h.264 Video Codec:
Satelite/CableTV Provider: UPC Slovakia
HTPC Case: Fractal Design Define R3
Cooling: 3x Noiseblocker M12-S1, Coolink Corator DS on CPU
Power Supply: Seasonic X-650
Remote: Logitech Harmony One, set to emulate Compro K100 (Microsoft eHome remote compatible)
TV: LG 42LC3R
TV - HTPC Connection: HDMI

My problem is that after some time of watching TV, the scrambled channels stop working and the only solution to get them back is a reboot. Let me explain it with logs :
Code: 
2011-05-12 14:21:38.414842 [TVService(5)]: Detecting Cards
2011-05-12 14:21:38.477242 [TVService(5)]: Detected IP TV Card 0
2011-05-12 14:21:38.799243 [TVService(5)]: Found card:knc bda dvb-c
2011-05-12 14:21:39.769244 [TVService(5)]: Detected DVB card:knc bda dvb-c
2011-05-12 14:21:39.769244 [TVService(5)]: Detecting type by MSNP 0: 143827ab-f77b-498d-81ca-5a007aec28bf
2011-05-12 14:21:39.769244 [TVService(5)]: Detecting type by MSNP 1: dc0c0fe7-0485-4266-b93f-68fbf80ed834
2011-05-12 14:21:39.769244 [TVService(5)]: Detected DVB-C* card:knc bda dvb-c
2011-05-12 14:21:39.779244 [TVService(5)]: Remove filter from graph: DVBC Network Provider
2011-05-12 14:21:39.779244 [TVService(5)]: Remove filter from graph: ATSC Network Provider
2011-05-12 14:21:39.779244 [TVService(5)]: Remove filter from graph: DVBS Network Provider
2011-05-12 14:21:39.779244 [TVService(5)]: Remove filter from graph: DVBT Network Provider
2011-05-12 14:21:39.789244 [TVService(5)]: Controller: started at FILEBOX
2011-05-12 14:21:39.789244 [TVService(5)]: Controller: local ip address:192.168.1.143
2011-05-12 14:21:39.789244 [TVService(5)]: Controller: local ip address:192.168.56.1
2011-05-12 14:21:39.859244 [TVService(5)]: Controller: server running on 192.168.1.143
2011-05-12 14:21:39.869244 [TVService(5)]: Controller: preloading card :KNC BDA DVB-C
2011-05-12 14:21:39.869244 [TVService(5)]: dvbc:BuildGraph
2011-05-12 14:21:39.879244 [TVService(5)]: dvb:AddNetworkProviderFilter
2011-05-12 14:21:39.879244 [TVService(5)]: dvb:Add Generic Network Provider
2011-05-12 14:21:39.879244 [TVService(5)]: dvbc:CreateTuningSpace()
2011-05-12 14:21:39.889244 [TVService(5)]: dvbc:Found correct tuningspace MediaPortal DVBC TuningSpace
2011-05-12 14:21:39.889244 [TVService(5)]: dvb:Add MPEG2 Demultiplexer filter
2011-05-12 14:21:39.889244 [TVService(5)]: dvb:add Inf Tee filter
2011-05-12 14:21:39.899244 [TVService(5)]: dvb:AddAndConnectBDABoardFilters
2011-05-12 14:21:39.899244 [TVService(5)]: dvb: find bda tuner
2011-05-12 14:21:39.919244 [TVService(5)]: dvb:  using [Tuner]: KNC BDA DVB-C
2011-05-12 14:21:39.919244 [TVService(5)]: dvb:  Render [Network provider]->[Tuner] OK
2011-05-12 14:21:39.919244 [TVService(5)]: dvb:  Single BDA filter implementation...
2011-05-12 14:21:39.929244 [TVService(5)]: dvb:  WinTv CI module not detected.
2011-05-12 14:21:39.929244 [TVService(5)]: dvb:  Render [tuner]->[inftee]
2011-05-12 14:21:39.929244 [TVService(5)]: dvb:  OK
2011-05-12 14:21:39.929244 [TVService(5)]: dvb:  using only tv tuner filter...
2011-05-12 14:21:39.929244 [TVService(5)]: dvb:  Render [inftee]->[demux]
2011-05-12 14:21:39.939244 [TVService(5)]: dvb:  Add Mediaportal TsWriter filter
2011-05-12 14:21:39.939244 [TVService(5)]: dvb:  Render [InfTee]->[TsWriter]
2011-05-12 14:21:39.949244 [TVService(5)]: CAM is Default model
2011-05-12 14:21:39.949244 [TVService(5)]: Check for KNC
2011-05-12 14:21:39.949244 [TVService(5)]: KNC: card 0 detected: KNC BDA DVB-C
2011-05-12 14:21:39.969244 [TVService(5)]: KNC: card 0 detected without CAM
2011-05-12 14:21:39.969244 [TVService(5)]: KNC: IsKNC True
2011-05-12 14:21:39.969244 [TVService(5)]: KNC card detected
2011-05-12 14:21:39.969244 [TVService(5)]: dvb:  AddTransportStreamFiltersToGraph
2011-05-12 14:21:39.969244 [TVService(5)]:     add BDA MPEG2 Transport Information Filter filter
2011-05-12 14:21:39.969244 [TVService(5)]:     pinTif:name:IB Input [3/1] Direction:Input Connected:False
2011-05-12 14:21:39.969244 [TVService(5)]:     Connect tif and mpeg2 sections and tables
2011-05-12 14:21:39.969244 [TVService(5)]: dvb:try tif:name:001 [5/1] Direction:Output Connected:False
2011-05-12 14:21:39.979244 [TVService(5)]:     tif connected
2011-05-12 14:21:39.979244 [TVService(5)]: dvb: GetTunerSignalStatistics()
2011-05-12 14:21:39.989244 [TVService(5)]: Controller: setup hybrid cards
2011-05-12 14:21:40.049245 [TVService(5)]: Controller: card KNC BDA DVB-C: current timeshiftpath = C:\Data\Private\TV\MediaPortal\timeshift
2011-05-12 14:21:40.049245 [TVService(5)]: Controller: card MediaPortal IPTV Source Filter: current timeshiftpath = C:\Data\Private\TV\MediaPortal\timeshift
2011-05-12 14:21:40.049245 [TVService(5)]: Controller: card RadioWebStream Card (builtin): current timeshiftpath = C:\Data\Private\TV\MediaPortal\timeshift

... some time later...

2011-05-12 14:21:45.456422 [(15)]: KNC: card 0 CI State: Conax Conditional Access Initializing
2011-05-12 14:21:49.944678 [(15)]: KNC: card 0 CI State: Conax Conditional Access Ready

So first it detects the DVB-C card without CI/CAM module, then about 10 seconds later it is initialized and ready. Fine, then i tune to some channel :
Code: 
2011-05-12 14:25:35.348531 [(19)]: TVServerXBMC: Start timeshift for channel 370 for user 'XBMCpvrclient1
2011-05-12 14:25:35.355531 [(19)]: Controller: StartTimeShifting Eurosport 2 370
2011-05-12 14:25:35.367532 [(19)]: Controller: find free card for channel Eurosport 2
2011-05-12 14:25:35.375532 [(19)]: Controller:   got 1 tuning details for Eurosport 2
2011-05-12 14:25:35.378533 [(19)]: Controller:   channel #1 DVBC:tv: Eurosport 2 Freq:426000 ONID:1 TSID:108 SID:8001 PMT:0x20 FTA:False LCN:370 SymbolRate:6900 Modulation:Mod64Qam 
2011-05-12 14:25:35.380533 [(19)]: RemoteControl: RegisterChannel first called in Domain TVService.exe for thread  with id 19
2011-05-12 14:25:35.459537 [(19)]: Controller:    card:2 type:DvbC is available priority:3 #users:0 same transponder:True
2011-05-12 14:25:35.459537 [(19)]: Controller:    card:1 type:DvbIP is disabled
2011-05-12 14:25:35.459537 [(19)]: Controller:    card:3 type:RadioWebStream is disabled
2011-05-12 14:25:35.460537 [(19)]: Controller: found 1 available
2011-05-12 14:25:35.460537 [(19)]: AdvancedCardAllocation.GetAvailableCardsForChannel took 92 msec
2011-05-12 14:25:35.466538 [(19)]: card: CardTune 2 Eurosport 2 XBMCpvrclient1:2:-1
2011-05-12 14:25:35.471538 [(19)]: card: Tune 2 to Eurosport 2
2011-05-12 14:25:35.471538 [(19)]: card: user: XBMCpvrclient1:2:-1 tune DVBC:tv: Eurosport 2 Freq:426000 ONID:1 TSID:108 SID:8001 PMT:0x20 FTA:False LCN:370 SymbolRate:6900 Modulation:Mod64Qam
2011-05-12 14:25:35.479538 [(19)]: dvbc: Tune:DVBC:tv: Eurosport 2 Freq:426000 ONID:1 TSID:108 SID:8001 PMT:0x20 FTA:False LCN:370 SymbolRate:6900 Modulation:Mod64Qam
2011-05-12 14:25:35.482539 [(19)]: dvb:Submiting tunerequest Channel:Eurosport 2 subChannel:-1 
2011-05-12 14:25:35.482539 [(19)]: dvb:Getting new subchannel
2011-05-12 14:25:35.483539 [(19)]: dvb:GetNewSubChannel:0 #0
2011-05-12 14:25:35.489539 [(19)]: TvDvbChannel ctor new subchIndex:0
2011-05-12 14:25:35.489539 [(19)]: dvb:Submit tunerequest size:1 new:0
2011-05-12 14:25:35.490539 [(19)]: subch:0 OnBeforeTune
2011-05-12 14:25:35.491539 [(19)]: dvb:Submit tunerequest calling put_TuneRequest
2011-05-12 14:25:35.492539 [(19)]: dvb:Submit tunerequest done calling put_TuneRequest
2011-05-12 14:25:35.493539 [(19)]: subch:0 OnAfterTune
2011-05-12 14:25:35.497539 [(19)]: subch:0 OnGraphStart
2011-05-12 14:25:35.499539 [(19)]: dvb:  RunGraph
2011-05-12 14:25:37.534656 [(19)]: dvb:  LockedInOnSignal ok
2011-05-12 14:25:37.534656 [(19)]: subch:0 OnGraphStarted
2011-05-12 14:25:37.537656 [(19)]: subch:0 SetupPmtGrabber:pid 20 sid:1F41
2011-05-12 14:25:37.537656 [(19)]: subch:0 set pmt grabber pmt:20 sid:1F41
2011-05-12 14:25:37.538656 [(19)]: WaitForPMT: Waiting for PMT 20
2011-05-12 14:25:37.933679 [(12)]: subch:0 OnPMTReceived() pmt:20 ran:True dynamic:False
2011-05-12 14:25:37.933679 [(19)]: WaitForPMT: Found PMT after 0,3950226 seconds.
2011-05-12 14:25:37.937679 [(19)]: subch:0 SendPmt:1F41 1F41 FFFFFFFF 5
2011-05-12 14:25:37.941679 [(19)]: Decode pmt
2011-05-12 14:25:37.941679 [(19)]: descr1 len:6 9 4 b 0 f3 ee 
2011-05-12 14:25:37.942679 [(19)]: Set descriptor data with length 6
2011-05-12 14:25:37.942679 [(19)]: Set descriptor data with length 7
2011-05-12 14:25:37.943679 [(19)]: subch:0 SendPMT version:5 len:84 8001
2011-05-12 14:25:37.944679 [(19)]: Decode pmt
2011-05-12 14:25:37.944679 [(19)]: descr1 len:6 9 4 b 0 f3 ee 
2011-05-12 14:25:37.944679 [(19)]: Set descriptor data with length 6
2011-05-12 14:25:37.945679 [(19)]: Set descriptor data with length 7
2011-05-12 14:25:37.946679 [(19)]: KNC: SendPMT success = True
2011-05-12 14:25:37.947680 [(19)]: KNC: IsCAMReady True
2011-05-12 14:25:37.948680 [(19)]: subch:0 cam flags:True
2011-05-12 14:25:37.954680 [(19)]: subch:0 SetMpegPidMapping
2011-05-12 14:25:37.954680 [(19)]: subch:0  pid:B09 pcr
2011-05-12 14:25:37.955680 [(19)]: subch:0  pid:20 pmt
2011-05-12 14:25:37.956680 [(19)]: subch:0  pid:B07 audio lang:eng type:MPEG-1
2011-05-12 14:25:37.956680 [(19)]: subch:0    map pid:B07 audio lang:eng type:MPEG-1
2011-05-12 14:25:37.957680 [(19)]: subch:0  pid:B09 video type:MPEG-2
2011-05-12 14:25:37.957680 [(19)]: subch:0    map pid:B09 video type:MPEG-2
2011-05-12 14:25:37.957680 [(19)]: subch:0  pid:B0F teletext type:6
2011-05-12 14:25:37.958680 [(19)]: subch:0    map pid:B0F teletext type:6
2011-05-12 14:25:37.958680 [(19)]: subch:0 stop tif
2011-05-12 14:25:37.958680 [(19)]: WaitForPmt: PMT handling took 0,0250014 seconds.
2011-05-12 14:25:37.976681 [(19)]: card: Tuner locked: True
2011-05-12 14:25:37.976681 [(19)]: **************************************************
2011-05-12 14:25:37.977681 [(19)]: ***** SIGNAL LEVEL: 59, SIGNAL QUALITY: 59 *****
2011-05-12 14:25:37.977681 [(19)]: **************************************************
2011-05-12 14:25:37.977681 [(19)]: card: tuned user: XBMCpvrclient1 subchannel: 0
2011-05-12 14:25:37.978681 [(19)]: user:XBMCpvrclient1 add
2011-05-12 14:25:37.978681 [(19)]: card2:XBMCpvrclient1 2 0
2011-05-12 14:25:37.979681 [(19)]: Controller: XBMCpvrclient1 2 0
2011-05-12 14:25:37.979681 [(19)]: control2:XBMCpvrclient1 2 0
2011-05-12 14:25:37.984682 [(19)]: Controller: delete timeshift files C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts
2011-05-12 14:25:37.993682 [(19)]: card: StartTimeShifting 2 C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts 
2011-05-12 14:25:37.994682 [(19)]: card: CAM enabled : True
2011-05-12 14:25:37.995682 [(19)]: subch:0 SetTimeShiftFileName:C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts
2011-05-12 14:25:37.996682 [(19)]: Set video / audio observer
2011-05-12 14:25:37.997682 [(19)]: subch:0 SetTimeShiftFileName fill in pids
2011-05-12 14:25:37.999682 [(19)]: subch:0-0 tswriter StartTimeshifting...
2011-05-12 14:25:38.427707 [(19)]: card: WaitForTimeShiftFile - waiting _eventAudio & _eventVideo
2011-05-12 14:25:38.598717 [(12)]: PID seen - type = Audio
2011-05-12 14:25:38.599717 [(12)]: audioVideoEventHandler Audio
2011-05-12 14:25:38.698722 [(12)]: PID seen - type = Video
2011-05-12 14:25:38.698722 [(12)]: audioVideoEventHandler Video
2011-05-12 14:25:38.699723 [(19)]: card: WaitForTimeShiftFile - video and audio are seen after 0,2720156 seconds
2011-05-12 14:25:38.871732 [(19)]: user:XBMCpvrclient1 card:2 sub:0 add stream:C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts.tsbuffer
2011-05-12 14:25:38.872732 [(19)]: RTSP: start streamer
2011-05-12 14:25:38.872732 [RTSP Streaming thread(20)]: RTSP: Streamer started
2011-05-12 14:25:38.873732 [(19)]: RTSP: add stream stream2.0 file:C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts.tsbuffer
2011-05-12 14:25:38.874733 [(19)]: Controller: StartTimeShifting started on card:2 to C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts.tsbuffer
2011-05-12 14:25:38.890733 [Channel state thread(21)]: Controller: DoSetChannelStates for 116 channels
2011-05-12 14:25:38.890733 [Channel state thread(21)]: ChannelStates.DoSetChannelStates took 0 msec
2011-05-12 14:25:40.966852 [(19)]: TVServerXBMC: Timeshift started for channel: 'Eurosport 2' on device 'KNC BDA DVB-C'
2011-05-12 14:25:40.966852 [(19)]: TVServerXBMC: TV Server returned 'rtsp://192.168.1.143:554/stream2.0' as timeshift URL and C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts.tsbuffer as timeshift file
2011-05-12 14:25:40.967852 [(19)]: TVServerXBMC: Remote server='FILEBOX'
2011-05-12 14:25:40.967852 [(19)]: TVServerXBMC: StartTimeShifting took 5618 ms
2011-05-12 14:25:40.967852 [(19)]: TVServerXBMC: PlayChannel 370 => URL=rtsp://192.168.1.143/stream2.0

All fine, everything works well. Watching few different channels in meantime. Then i decide to watch STV1 HD, again it has no problems tuning to the channel :
Code: 
2011-05-12 19:52:40.221009 [(19)]: TVServerXBMC: Handling command: TimeshiftChannel
2011-05-12 19:52:40.222009 [(19)]: TVServerXBMC: Start timeshift for channel 373 for user 'XBMCpvrclient1
2011-05-12 19:52:40.225010 [(19)]: Controller: StartTimeShifting STV1 HD 373
2011-05-12 19:52:40.225010 [(19)]: Controller: find free card for channel STV1 HD
2011-05-12 19:52:40.226010 [(19)]: Controller:   got 1 tuning details for STV1 HD
2011-05-12 19:52:40.227010 [(19)]: Controller:   channel #1 DVBC:tv: STV1 HD Freq:426000 ONID:1 TSID:108 SID:8004 PMT:0xFF4 FTA:False LCN:373 SymbolRate:6900 Modulation:Mod64Qam 
2011-05-12 19:52:40.230010 [(19)]: Controller:    card:2 type:DvbC is available priority:3 #users:0 same transponder:True
2011-05-12 19:52:40.230010 [(19)]: Controller:    card:1 type:DvbIP is disabled
2011-05-12 19:52:40.230010 [(19)]: Controller:    card:3 type:RadioWebStream is disabled
2011-05-12 19:52:40.230010 [(19)]: Controller: found 1 available
2011-05-12 19:52:40.231010 [(19)]: AdvancedCardAllocation.GetAvailableCardsForChannel took 5 msec
2011-05-12 19:52:40.232010 [(19)]: card: CardTune 2 STV1 HD XBMCpvrclient1:2:-1
2011-05-12 19:52:40.232010 [(19)]: card: Tune 2 to STV1 HD
2011-05-12 19:52:40.233010 [(19)]: card: user: XBMCpvrclient1:2:-1 tune DVBC:tv: STV1 HD Freq:426000 ONID:1 TSID:108 SID:8004 PMT:0xFF4 FTA:False LCN:373 SymbolRate:6900 Modulation:Mod64Qam
2011-05-12 19:52:40.238010 [(19)]: dvbc: Tune:DVBC:tv: STV1 HD Freq:426000 ONID:1 TSID:108 SID:8004 PMT:0xFF4 FTA:False LCN:373 SymbolRate:6900 Modulation:Mod64Qam
2011-05-12 19:52:40.239010 [(19)]: dvb:Submiting tunerequest Channel:STV1 HD subChannel:-1 
2011-05-12 19:52:40.239010 [(19)]: dvb:Getting new subchannel
2011-05-12 19:52:40.239010 [(19)]: dvb:GetNewSubChannel:0 #0
2011-05-12 19:52:40.240010 [(19)]: TvDvbChannel ctor new subchIndex:0
2011-05-12 19:52:40.240010 [(19)]: dvb:Submit tunerequest size:1 new:0
2011-05-12 19:52:40.240010 [(19)]: subch:0 OnBeforeTune
2011-05-12 19:52:40.241010 [(19)]: dvb:Submit tunerequest calling put_TuneRequest
2011-05-12 19:52:40.241010 [(19)]: dvb:Submit tunerequest done calling put_TuneRequest
2011-05-12 19:52:40.241010 [(19)]: subch:0 OnAfterTune
2011-05-12 19:52:40.242011 [(19)]: subch:0 OnGraphStart
2011-05-12 19:52:40.242011 [(19)]: dvb:  RunGraph
2011-05-12 19:52:40.250011 [(19)]: dvb:  LockedInOnSignal ok
2011-05-12 19:52:40.250011 [(19)]: subch:0 OnGraphStarted
2011-05-12 19:52:40.251011 [(19)]: subch:0 SetupPmtGrabber:pid FF4 sid:1F44
2011-05-12 19:52:40.251011 [(19)]: subch:0 set pmt grabber pmt:FF4 sid:1F44
2011-05-12 19:52:40.251011 [(19)]: WaitForPMT: Waiting for PMT FF4
2011-05-12 19:52:40.595031 [(12)]: subch:0 OnPMTReceived() pmt:FF4 ran:True dynamic:False
2011-05-12 19:52:40.595031 [(19)]: WaitForPMT: Found PMT after 0,3440197 seconds.
2011-05-12 19:52:40.596031 [(19)]: subch:0 SendPmt:1F44 1F44 FFFFFFFF 3
2011-05-12 19:52:40.596031 [(19)]: Decode pmt
2011-05-12 19:52:40.596031 [(19)]: descr1 len:6 9 4 b 0 f3 ee 
2011-05-12 19:52:40.596031 [(19)]: Set descriptor data with length 6
2011-05-12 19:52:40.597031 [(19)]: subch:0 SendPMT version:3 len:45 8004
2011-05-12 19:52:40.597031 [(19)]: Decode pmt
2011-05-12 19:52:40.597031 [(19)]: descr1 len:6 9 4 b 0 f3 ee 
2011-05-12 19:52:40.597031 [(19)]: Set descriptor data with length 6
2011-05-12 19:52:40.597031 [(19)]: KNC: SendPMT success = True
2011-05-12 19:52:40.598031 [(19)]: KNC: IsCAMReady True
2011-05-12 19:52:40.598031 [(19)]: subch:0 cam flags:True
2011-05-12 19:52:40.598031 [(19)]: subch:0 SetMpegPidMapping
2011-05-12 19:52:40.598031 [(19)]: subch:0  pid:FA4 pcr
2011-05-12 19:52:40.599031 [(19)]: subch:0  pid:FF4 pmt
2011-05-12 19:52:40.599031 [(19)]: subch:0  pid:FA4 video type:H.264
2011-05-12 19:52:40.599031 [(19)]: subch:0    map pid:FA4 video type:H.264
2011-05-12 19:52:40.600031 [(19)]: subch:0  pid:1044 audio lang:slo type:MPEG-1
2011-05-12 19:52:40.600031 [(19)]: subch:0    map pid:1044 audio lang:slo type:MPEG-1
2011-05-12 19:52:40.600031 [(19)]: subch:0 stop tif
2011-05-12 19:52:40.600031 [(19)]: WaitForPmt: PMT handling took 0,0050003 seconds.
2011-05-12 19:52:40.614032 [(19)]: card: Tuner locked: True
2011-05-12 19:52:40.614032 [(19)]: **************************************************
2011-05-12 19:52:40.615032 [(19)]: ***** SIGNAL LEVEL: 59, SIGNAL QUALITY: 59 *****
2011-05-12 19:52:40.615032 [(19)]: **************************************************
2011-05-12 19:52:40.615032 [(19)]: card: tuned user: XBMCpvrclient1 subchannel: 0
2011-05-12 19:52:40.615032 [(19)]: user:XBMCpvrclient1 add
2011-05-12 19:52:40.615032 [(19)]: card2:XBMCpvrclient1 2 0
2011-05-12 19:52:40.616032 [(19)]: Controller: XBMCpvrclient1 2 0
2011-05-12 19:52:40.616032 [(19)]: control2:XBMCpvrclient1 2 0
2011-05-12 19:52:40.628033 [(19)]: Controller: delete timeshift files C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts
2011-05-12 19:52:40.631033 [(19)]: card: StartTimeShifting 2 C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts 
2011-05-12 19:52:40.631033 [(19)]: card: CAM enabled : True
2011-05-12 19:52:40.632033 [(19)]: subch:0 SetTimeShiftFileName:C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts
2011-05-12 19:52:40.632033 [(19)]: Set video / audio observer
2011-05-12 19:52:40.633033 [(19)]: subch:0 SetTimeShiftFileName fill in pids
2011-05-12 19:52:40.634033 [(19)]: subch:0-0 tswriter StartTimeshifting...
2011-05-12 19:52:40.638033 [(19)]: card: WaitForTimeShiftFile - waiting _eventAudio & _eventVideo
2011-05-12 19:52:40.837045 [(12)]: PID seen - type = Video
2011-05-12 19:52:40.837045 [(12)]: audioVideoEventHandler Video
2011-05-12 19:52:40.957051 [(12)]: PID seen - type = Audio
2011-05-12 19:52:40.958052 [(12)]: audioVideoEventHandler Audio
2011-05-12 19:52:40.958052 [(19)]: card: WaitForTimeShiftFile - video and audio are seen after 0,3200183 seconds
2011-05-12 19:52:40.961052 [(19)]: user:XBMCpvrclient1 card:2 sub:0 add stream:C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts.tsbuffer
2011-05-12 19:52:40.962052 [(19)]: RTSP: add stream stream2.0 file:C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts.tsbuffer
2011-05-12 19:52:40.962052 [(19)]: Controller: StartTimeShifting started on card:2 to C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts.tsbuffer
2011-05-12 19:52:40.964052 [Channel state thread(27)]: Controller: DoSetChannelStates for 116 channels
2011-05-12 19:52:40.964052 [Channel state thread(27)]: ChannelStates.DoSetChannelStates took 0 msec
2011-05-12 19:52:40.974052 [(19)]: TVServerXBMC: Timeshift started for channel: 'STV1 HD' on device 'KNC BDA DVB-C'
2011-05-12 19:52:40.974052 [(19)]: TVServerXBMC: TV Server returned 'rtsp://192.168.1.143:554/stream2.0' as timeshift URL and C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts.tsbuffer as timeshift file
2011-05-12 19:52:40.975052 [(19)]: TVServerXBMC: Remote server='FILEBOX'
2011-05-12 19:52:40.975052 [(19)]: TVServerXBMC: StartTimeShifting took 753 ms
2011-05-12 19:52:40.975052 [(19)]: TVServerXBMC: PlayChannel 373 => URL=rtsp://192.168.1.143/stream2.0

All is well, i'm watching the channel, but then suddenly the stream stops. I see this in tv.log at the time when stream stopped :

Code: 
2011-05-12 20:31:06.818939 [(15)]: OnKncCiOpenDisplay slot: 0
2011-05-12 20:31:06.931946 [(15)]: OnKncCiMenu slot:       0
2011-05-12 20:31:06.931946 [(15)]: OnKncCiMenu title:      
2011-05-12 20:31:06.931946 [(15)]: OnKncCiMenu subtitle:   
2011-05-12 20:31:06.932946 [(15)]: OnKncCiMenu bottom:     
2011-05-12 20:31:06.932946 [(15)]: OnKncCiMenu lpszBottom: 
2011-05-12 20:31:06.932946 [(15)]: OnKncCiMenu nNumChoices:1
2011-05-12 20:31:06.933946 [(15)]: OnKncCiMenuChoice slot:0 choice:0 text: Card problem - check card
2011-05-12 20:31:16.932518 [(15)]: OnKncCiCloseDisplay slot:0 nDelay:0
2011-05-12 20:31:17.045524 [(15)]: OnKncCiOpenDisplay slot: 0
2011-05-12 20:31:17.159531 [(15)]: OnKncCiMenu slot:       0
2011-05-12 20:31:17.159531 [(15)]: OnKncCiMenu title:      
2011-05-12 20:31:17.159531 [(15)]: OnKncCiMenu subtitle:   
2011-05-12 20:31:17.160531 [(15)]: OnKncCiMenu bottom:     
2011-05-12 20:31:17.160531 [(15)]: OnKncCiMenu lpszBottom: 
2011-05-12 20:31:17.160531 [(15)]: OnKncCiMenu nNumChoices:1
2011-05-12 20:31:17.160531 [(15)]: OnKncCiMenuChoice slot:0 choice:0 text: Card problem - check card

What card problem ? It is the same card it was using just seconds ago! :mad: Of course in XBMC i get this error, because the TV server is not pushing any new data into the stream anymore (but the URL itself was alive, and TV server still said it is timeshifting) :

Code: 
20:31:09 T:4224 M:2173829120 WARNING: CDVDMessageQueue(audio)::Get - asked for new data packet, with nothing available

Let's try to tune to the channel i watched so far again :
Code: 
2011-05-12 20:34:38.502047 [(19)]: Controller: StartTimeShifting STV1 HD 373
2011-05-12 20:34:38.503047 [(19)]: user:epg remove
2011-05-12 20:34:38.503047 [(19)]: tvcard:FreeSubChannel: subchannels count 1 subch#0 keep graph=False
2011-05-12 20:34:38.503047 [(19)]: DVB subch:0 Decompose()
2011-05-12 20:34:38.504047 [(19)]: FreeSubChannel CA: freeing sub channel : 0
2011-05-12 20:34:38.504047 [(19)]: tvcard:FreeSubChannel : no subchannels present, stopping graph
2011-05-12 20:34:38.505047 [(19)]: dvb:StopGraph called
2011-05-12 20:34:38.505047 [(19)]: tvcard:FreeAllSubChannels
2011-05-12 20:34:38.505047 [(19)]: dvb:StopGraph
2011-05-12 20:34:38.506047 [(19)]: Controller: find free card for channel STV1 HD
2011-05-12 20:34:38.507047 [(19)]: Controller:   got 1 tuning details for STV1 HD
2011-05-12 20:34:38.508047 [(19)]: Controller:   channel #1 DVBC:tv: STV1 HD Freq:426000 ONID:1 TSID:108 SID:8004 PMT:0xFF4 FTA:False LCN:373 SymbolRate:6900 Modulation:Mod64Qam 
2011-05-12 20:34:38.511047 [(19)]: Controller:    card:2 type:DvbC is available priority:3 #users:0 same transponder:True
2011-05-12 20:34:38.511047 [(19)]: Controller:    card:1 type:DvbIP is disabled
2011-05-12 20:34:38.512047 [(19)]: Controller:    card:3 type:RadioWebStream is disabled
2011-05-12 20:34:38.512047 [(19)]: Controller: found 1 available
2011-05-12 20:34:38.512047 [(19)]: AdvancedCardAllocation.GetAvailableCardsForChannel took 6 msec
2011-05-12 20:34:38.514047 [(19)]: card: CardTune 2 STV1 HD XBMCpvrclient1:2:-1
2011-05-12 20:34:38.514047 [(19)]: card: Tune 2 to STV1 HD
2011-05-12 20:34:38.515048 [(19)]: card: user: XBMCpvrclient1:2:-1 tune DVBC:tv: STV1 HD Freq:426000 ONID:1 TSID:108 SID:8004 PMT:0xFF4 FTA:False LCN:373 SymbolRate:6900 Modulation:Mod64Qam
2011-05-12 20:34:38.520048 [(19)]: dvbc: Tune:DVBC:tv: STV1 HD Freq:426000 ONID:1 TSID:108 SID:8004 PMT:0xFF4 FTA:False LCN:373 SymbolRate:6900 Modulation:Mod64Qam
2011-05-12 20:34:38.520048 [(19)]: dvb:Submiting tunerequest Channel:STV1 HD subChannel:-1 
2011-05-12 20:34:38.521048 [(19)]: dvb:Getting new subchannel
2011-05-12 20:34:38.521048 [(19)]: dvb:GetNewSubChannel:0 #0
2011-05-12 20:34:38.522048 [(19)]: TvDvbChannel ctor new subchIndex:0
2011-05-12 20:34:38.522048 [(19)]: dvb:Submit tunerequest size:1 new:0
2011-05-12 20:34:38.523048 [(19)]: subch:0 OnBeforeTune
2011-05-12 20:34:38.523048 [(19)]: dvb:Submit tunerequest calling put_TuneRequest
2011-05-12 20:34:38.524048 [(19)]: dvb:Submit tunerequest done calling put_TuneRequest
2011-05-12 20:34:38.524048 [(19)]: subch:0 OnAfterTune
2011-05-12 20:34:38.525048 [(19)]: subch:0 OnGraphStart
2011-05-12 20:34:38.525048 [(19)]: dvb:  RunGraph
2011-05-12 20:34:38.835066 [(15)]: OnKncCiOpenDisplay slot: 0
2011-05-12 20:34:38.948072 [(15)]: OnKncCiMenu slot:       0
2011-05-12 20:34:38.948072 [(15)]: OnKncCiMenu title:      
2011-05-12 20:34:38.948072 [(15)]: OnKncCiMenu subtitle:   
2011-05-12 20:34:38.949072 [(15)]: OnKncCiMenu bottom:     
2011-05-12 20:34:38.949072 [(15)]: OnKncCiMenu lpszBottom: 
2011-05-12 20:34:38.949072 [(15)]: OnKncCiMenu nNumChoices:1
2011-05-12 20:34:38.949072 [(15)]: OnKncCiMenuChoice slot:0 choice:0 text: No card inserted
2011-05-12 20:34:39.206087 [(19)]: dvb:  LockedInOnSignal ok
2011-05-12 20:34:39.206087 [(19)]: subch:0 OnGraphStarted
2011-05-12 20:34:39.206087 [(19)]: subch:0 SetupPmtGrabber:pid FF4 sid:1F44
2011-05-12 20:34:39.206087 [(19)]: subch:0 set pmt grabber pmt:FF4 sid:1F44
2011-05-12 20:34:39.207087 [(19)]: WaitForPMT: Waiting for PMT FF4
2011-05-12 20:34:39.579108 [(12)]: subch:0 OnPMTReceived() pmt:FF4 ran:True dynamic:False
2011-05-12 20:34:39.579108 [(19)]: WaitForPMT: Found PMT after 0,3720212 seconds.
2011-05-12 20:34:39.579108 [(19)]: subch:0 SendPmt:1F44 1F44 FFFFFFFF 3
2011-05-12 20:34:39.580108 [(19)]: Decode pmt
2011-05-12 20:34:39.580108 [(19)]: descr1 len:6 9 4 b 0 f3 ee 
2011-05-12 20:34:39.580108 [(19)]: Set descriptor data with length 6
2011-05-12 20:34:39.581109 [(19)]: subch:0 SendPMT version:3 len:45 8004
2011-05-12 20:34:39.581109 [(19)]: Decode pmt
2011-05-12 20:34:39.581109 [(19)]: descr1 len:6 9 4 b 0 f3 ee 
2011-05-12 20:34:39.581109 [(19)]: Set descriptor data with length 6
2011-05-12 20:34:39.582109 [(19)]: KNC: SendPMT success = True
2011-05-12 20:34:39.582109 [(19)]: KNC: IsCAMReady True
2011-05-12 20:34:39.582109 [(19)]: subch:0 cam flags:True
2011-05-12 20:34:39.582109 [(19)]: subch:0 SetMpegPidMapping
2011-05-12 20:34:39.583109 [(19)]: subch:0  pid:FA4 pcr
2011-05-12 20:34:39.583109 [(19)]: subch:0  pid:FF4 pmt
2011-05-12 20:34:39.583109 [(19)]: subch:0  pid:FA4 video type:H.264
2011-05-12 20:34:39.583109 [(19)]: subch:0    map pid:FA4 video type:H.264
2011-05-12 20:34:39.584109 [(19)]: subch:0  pid:1044 audio lang:slo type:MPEG-1
2011-05-12 20:34:39.584109 [(19)]: subch:0    map pid:1044 audio lang:slo type:MPEG-1
2011-05-12 20:34:39.584109 [(19)]: subch:0 stop tif
2011-05-12 20:34:39.585109 [(19)]: WaitForPmt: PMT handling took 0,0050003 seconds.
2011-05-12 20:34:39.600110 [(19)]: card: Tuner locked: True
2011-05-12 20:34:39.600110 [(19)]: **************************************************
2011-05-12 20:34:39.600110 [(19)]: ***** SIGNAL LEVEL: 59, SIGNAL QUALITY: 59 *****
2011-05-12 20:34:39.601110 [(19)]: **************************************************
2011-05-12 20:34:39.601110 [(19)]: card: tuned user: XBMCpvrclient1 subchannel: 0
2011-05-12 20:34:39.601110 [(19)]: user:XBMCpvrclient1 add
2011-05-12 20:34:39.601110 [(19)]: card2:XBMCpvrclient1 2 0
2011-05-12 20:34:39.601110 [(19)]: Controller: XBMCpvrclient1 2 0
2011-05-12 20:34:39.602110 [(19)]: control2:XBMCpvrclient1 2 0
2011-05-12 20:34:39.603110 [(19)]: Controller: delete timeshift files C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts
2011-05-12 20:34:39.608110 [(19)]: card: StartTimeShifting 2 C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts 
2011-05-12 20:34:39.608110 [(19)]: card: CAM enabled : True
2011-05-12 20:34:39.608110 [(19)]: subch:0 SetTimeShiftFileName:C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts
2011-05-12 20:34:39.609110 [(19)]: Set video / audio observer
2011-05-12 20:34:39.610110 [(19)]: subch:0 SetTimeShiftFileName fill in pids
2011-05-12 20:34:39.611110 [(19)]: subch:0-0 tswriter StartTimeshifting...
2011-05-12 20:34:39.613110 [(19)]: card: WaitForTimeShiftFile - waiting _eventAudio & _eventVideo
2011-05-12 20:34:39.780120 [(15)]: OnKncCiCloseDisplay slot:0 nDelay:0
2011-05-12 20:34:39.892126 [(15)]: OnKncCiOpenDisplay slot: 0
2011-05-12 20:34:40.005133 [(15)]: OnKncCiMenu slot:       0
2011-05-12 20:34:40.005133 [(15)]: OnKncCiMenu title:      
2011-05-12 20:34:40.005133 [(15)]: OnKncCiMenu subtitle:   
2011-05-12 20:34:40.005133 [(15)]: OnKncCiMenu bottom:     
2011-05-12 20:34:40.006133 [(15)]: OnKncCiMenu lpszBottom: 
2011-05-12 20:34:40.006133 [(15)]: OnKncCiMenu nNumChoices:1
2011-05-12 20:34:40.006133 [(15)]: OnKncCiMenuChoice slot:0 choice:0 text: No card inserted
2011-05-12 20:34:50.007705 [(15)]: OnKncCiCloseDisplay slot:0 nDelay:0
2011-05-12 20:34:54.613968 [(19)]: card: WaitForTimeShiftFile - no audio was found after 15,000858 seconds
2011-05-12 20:34:54.613968 [(19)]: card: WaitForTimeShiftFile - audio and video stream is scrambled
2011-05-12 20:34:54.614968 [(19)]: card KNC BDA DVB-C: StopTimeShifting user:XBMCpvrclient1 sub:0
2011-05-12 20:34:54.615968 [(19)]: card: StopTimeShifting user:XBMCpvrclient1 sub:0
2011-05-12 20:34:54.615968 [(19)]: card not IDLE - removing user: XBMCpvrclient1
2011-05-12 20:34:54.616969 [(19)]: user:XBMCpvrclient1 remove
2011-05-12 20:34:54.616969 [(19)]: subch:0-0 tswriter StopTimeshifting...
2011-05-12 20:34:54.617969 [(19)]: tvcard:FreeSubChannel: subchannels count 1 subch#0 keep graph=False
2011-05-12 20:34:54.617969 [(19)]: DVB subch:0 Decompose()
2011-05-12 20:34:54.618969 [(19)]: FreeSubChannel CA: freeing sub channel : 0
2011-05-12 20:34:54.618969 [(19)]: tvcard:FreeSubChannel : no subchannels present, stopping graph
2011-05-12 20:34:54.618969 [(19)]: dvb:StopGraph called
2011-05-12 20:34:54.619969 [(19)]: tvcard:FreeAllSubChannels
2011-05-12 20:34:54.619969 [(19)]: dvb:StopGraph
2011-05-12 20:34:54.620969 [TS_File_Cleanup(30)]: card: delete timeshift files C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts
2011-05-12 20:34:54.621969 [(19)]: dvb:StopGraph called
2011-05-12 20:34:54.621969 [(19)]: tvcard:FreeAllSubChannels
2011-05-12 20:34:54.621969 [(19)]: dvb:StopGraph filterstate already stopped, returning.
2011-05-12 20:34:54.622969 [(19)]: user:XBMCpvrclient1 remove
2011-05-12 20:34:54.728975 [(19)]: TVServerXBMC: Failed. TvResult = ChannelIsScrambled
2011-05-12 20:34:54.728975 [(19)]: TVServerXBMC: StartTimeShifting took 16298 ms
2011-05-12 20:34:54.729975 [(19)]: TVServerXBMC: PlayChannel 373 => URL=[ERROR]: TVServer answer: ChannelIsScrambled

Now it says "No card inserted". What is going on ? I mean for 6 hours it had absolutely no problems, then it just decided i have a card problem and then that i have no card inserted ?

Now let's reboot the computer. What do we have here ?

Code: 
2011-05-12 21:10:34.131645 [TVService(5)]: Detecting Cards
2011-05-12 21:10:34.161645 [TVService(5)]: Detected IP TV Card 0
2011-05-12 21:10:34.451645 [TVService(5)]: Found card:knc bda dvb-c
2011-05-12 21:10:35.271646 [TVService(5)]: Detected DVB card:knc bda dvb-c
2011-05-12 21:10:35.281646 [TVService(5)]: Detecting type by MSNP 0: 143827ab-f77b-498d-81ca-5a007aec28bf
2011-05-12 21:10:35.281646 [TVService(5)]: Detecting type by MSNP 1: dc0c0fe7-0485-4266-b93f-68fbf80ed834
2011-05-12 21:10:35.281646 [TVService(5)]: Detected DVB-C* card:knc bda dvb-c
2011-05-12 21:10:35.281646 [TVService(5)]: Remove filter from graph: DVBC Network Provider
2011-05-12 21:10:35.291646 [TVService(5)]: Remove filter from graph: ATSC Network Provider
2011-05-12 21:10:35.291646 [TVService(5)]: Remove filter from graph: DVBS Network Provider
2011-05-12 21:10:35.291646 [TVService(5)]: Remove filter from graph: DVBT Network Provider
2011-05-12 21:10:35.291646 [TVService(5)]: Controller: started at FILEBOX
2011-05-12 21:10:35.291646 [TVService(5)]: Controller: local ip address:192.168.1.143
2011-05-12 21:10:35.291646 [TVService(5)]: Controller: local ip address:192.168.56.1
2011-05-12 21:10:35.361646 [TVService(5)]: Controller: server running on 192.168.1.143
2011-05-12 21:10:35.371646 [TVService(5)]: Controller: preloading card :KNC BDA DVB-C
2011-05-12 21:10:35.371646 [TVService(5)]: dvbc:BuildGraph
2011-05-12 21:10:35.381646 [TVService(5)]: dvb:AddNetworkProviderFilter
2011-05-12 21:10:35.381646 [TVService(5)]: dvb:Add Generic Network Provider
2011-05-12 21:10:35.381646 [TVService(5)]: dvbc:CreateTuningSpace()
2011-05-12 21:10:35.391646 [TVService(5)]: dvbc:Found correct tuningspace MediaPortal DVBC TuningSpace
2011-05-12 21:10:35.391646 [TVService(5)]: dvb:Add MPEG2 Demultiplexer filter
2011-05-12 21:10:35.391646 [TVService(5)]: dvb:add Inf Tee filter
2011-05-12 21:10:35.401646 [TVService(5)]: dvb:AddAndConnectBDABoardFilters
2011-05-12 21:10:35.411646 [TVService(5)]: dvb: find bda tuner
2011-05-12 21:10:35.431646 [TVService(5)]: dvb:  using [Tuner]: KNC BDA DVB-C
2011-05-12 21:10:35.431646 [TVService(5)]: dvb:  Render [Network provider]->[Tuner] OK
2011-05-12 21:10:35.431646 [TVService(5)]: dvb:  Single BDA filter implementation...
2011-05-12 21:10:35.441646 [TVService(5)]: dvb:  WinTv CI module not detected.
2011-05-12 21:10:35.441646 [TVService(5)]: dvb:  Render [tuner]->[inftee]
2011-05-12 21:10:35.441646 [TVService(5)]: dvb:  OK
2011-05-12 21:10:35.441646 [TVService(5)]: dvb:  using only tv tuner filter...
2011-05-12 21:10:35.451646 [TVService(5)]: dvb:  Render [inftee]->[demux]
2011-05-12 21:10:35.451646 [TVService(5)]: dvb:  Add Mediaportal TsWriter filter
2011-05-12 21:10:35.451646 [TVService(5)]: dvb:  Render [InfTee]->[TsWriter]
2011-05-12 21:10:35.461646 [TVService(5)]: CAM is Default model
2011-05-12 21:10:35.461646 [TVService(5)]: Check for KNC
2011-05-12 21:10:35.461646 [TVService(5)]: KNC: card 0 detected: KNC BDA DVB-C
2011-05-12 21:10:35.481646 [TVService(5)]: KNC: card 0 detected without CAM
2011-05-12 21:10:35.481646 [TVService(5)]: KNC: IsKNC True
2011-05-12 21:10:35.481646 [TVService(5)]: KNC card detected
2011-05-12 21:10:35.481646 [TVService(5)]: dvb:  AddTransportStreamFiltersToGraph
2011-05-12 21:10:35.481646 [TVService(5)]:     add BDA MPEG2 Transport Information Filter filter
2011-05-12 21:10:35.491646 [TVService(5)]:     pinTif:name:IB Input [3/1] Direction:Input Connected:False
2011-05-12 21:10:35.491646 [TVService(5)]:     Connect tif and mpeg2 sections and tables
2011-05-12 21:10:35.491646 [TVService(5)]: dvb:try tif:name:001 [5/1] Direction:Output Connected:False
2011-05-12 21:10:35.491646 [TVService(5)]:     tif connected
2011-05-12 21:10:35.501646 [TVService(5)]: dvb: GetTunerSignalStatistics()
2011-05-12 21:10:35.501646 [TVService(5)]: Controller: setup hybrid cards
2011-05-12 21:10:35.551647 [TVService(5)]: Controller: card KNC BDA DVB-C: current timeshiftpath = C:\Data\Private\TV\MediaPortal\timeshift
2011-05-12 21:10:35.561647 [TVService(5)]: Controller: card MediaPortal IPTV Source Filter: current timeshiftpath = C:\Data\Private\TV\MediaPortal\timeshift
2011-05-12 21:10:35.561647 [TVService(5)]: Controller: card RadioWebStream Card (builtin): current timeshiftpath = C:\Data\Private\TV\MediaPortal\timeshift
... some time later ...
2011-05-12 21:10:40.940826 [(18)]: KNC: card 0 CI State: Conax Conditional Access Initializing
2011-05-12 21:10:45.476085 [(18)]: KNC: card 0 CI State: Conax Conditional Access Ready

Hm. It looks very similar to the first log in this post. Let's tune to STV1 HD again :

Code: 
2011-05-12 21:13:13.635343 [(19)]: TVServerXBMC: Start timeshift for channel 373 for user 'XBMCpvrclient1
2011-05-12 21:13:13.642343 [(19)]: Controller: StartTimeShifting STV1 HD 373
2011-05-12 21:13:13.654344 [(19)]: Controller: find free card for channel STV1 HD
2011-05-12 21:13:13.662345 [(19)]: Controller:   got 1 tuning details for STV1 HD
2011-05-12 21:13:13.665345 [(19)]: Controller:   channel #1 DVBC:tv: STV1 HD Freq:426000 ONID:1 TSID:108 SID:8004 PMT:0xFF4 FTA:False LCN:373 SymbolRate:6900 Modulation:Mod64Qam 
2011-05-12 21:13:13.668345 [(19)]: RemoteControl: RegisterChannel first called in Domain TVService.exe for thread  with id 19
2011-05-12 21:13:13.742349 [(19)]: Controller:    card:2 type:DvbC is available priority:3 #users:0 same transponder:True
2011-05-12 21:13:13.743349 [(19)]: Controller:    card:1 type:DvbIP is disabled
2011-05-12 21:13:13.743349 [(19)]: Controller:    card:3 type:RadioWebStream is disabled
2011-05-12 21:13:13.743349 [(19)]: Controller: found 1 available
2011-05-12 21:13:13.744349 [(19)]: AdvancedCardAllocation.GetAvailableCardsForChannel took 89 msec
2011-05-12 21:13:13.749350 [(19)]: card: CardTune 2 STV1 HD XBMCpvrclient1:2:-1
2011-05-12 21:13:13.754350 [(19)]: card: Tune 2 to STV1 HD
2011-05-12 21:13:13.754350 [(19)]: card: user: XBMCpvrclient1:2:-1 tune DVBC:tv: STV1 HD Freq:426000 ONID:1 TSID:108 SID:8004 PMT:0xFF4 FTA:False LCN:373 SymbolRate:6900 Modulation:Mod64Qam
2011-05-12 21:13:13.765350 [(19)]: dvbc: Tune:DVBC:tv: STV1 HD Freq:426000 ONID:1 TSID:108 SID:8004 PMT:0xFF4 FTA:False LCN:373 SymbolRate:6900 Modulation:Mod64Qam
2011-05-12 21:13:13.767351 [(19)]: dvb:Submiting tunerequest Channel:STV1 HD subChannel:-1 
2011-05-12 21:13:13.767351 [(19)]: dvb:Getting new subchannel
2011-05-12 21:13:13.768351 [(19)]: dvb:GetNewSubChannel:0 #0
2011-05-12 21:13:13.774351 [(19)]: TvDvbChannel ctor new subchIndex:0
2011-05-12 21:13:13.775351 [(19)]: dvb:Submit tunerequest size:1 new:0
2011-05-12 21:13:13.776351 [(19)]: subch:0 OnBeforeTune
2011-05-12 21:13:13.776351 [(19)]: dvb:Submit tunerequest calling put_TuneRequest
2011-05-12 21:13:13.778351 [(19)]: dvb:Submit tunerequest done calling put_TuneRequest
2011-05-12 21:13:13.779351 [(19)]: subch:0 OnAfterTune
2011-05-12 21:13:13.783352 [(19)]: subch:0 OnGraphStart
2011-05-12 21:13:13.785352 [(19)]: dvb:  RunGraph
2011-05-12 21:13:15.815468 [(19)]: dvb:  LockedInOnSignal ok
2011-05-12 21:13:15.815468 [(19)]: subch:0 OnGraphStarted
2011-05-12 21:13:15.818468 [(19)]: subch:0 SetupPmtGrabber:pid FF4 sid:1F44
2011-05-12 21:13:15.818468 [(19)]: subch:0 set pmt grabber pmt:FF4 sid:1F44
2011-05-12 21:13:15.819468 [(19)]: WaitForPMT: Waiting for PMT FF4
2011-05-12 21:13:15.875471 [(12)]: subch:0 OnPMTReceived() pmt:FF4 ran:True dynamic:False
2011-05-12 21:13:15.875471 [(19)]: WaitForPMT: Found PMT after 0,0560032 seconds.
2011-05-12 21:13:15.879471 [(19)]: subch:0 SendPmt:1F44 1F44 FFFFFFFF 3
2011-05-12 21:13:15.883472 [(19)]: Decode pmt
2011-05-12 21:13:15.883472 [(19)]: descr1 len:6 9 4 b 0 f3 ee 
2011-05-12 21:13:15.884472 [(19)]: Set descriptor data with length 6
2011-05-12 21:13:15.884472 [(19)]: subch:0 SendPMT version:3 len:45 8004
2011-05-12 21:13:15.885472 [(19)]: Decode pmt
2011-05-12 21:13:15.886472 [(19)]: descr1 len:6 9 4 b 0 f3 ee 
2011-05-12 21:13:15.886472 [(19)]: Set descriptor data with length 6
2011-05-12 21:13:15.888472 [(19)]: KNC: SendPMT success = True
2011-05-12 21:13:15.889472 [(19)]: KNC: IsCAMReady True
2011-05-12 21:13:15.889472 [(19)]: subch:0 cam flags:True
2011-05-12 21:13:15.896472 [(19)]: subch:0 SetMpegPidMapping
2011-05-12 21:13:15.896472 [(19)]: subch:0  pid:FA4 pcr
2011-05-12 21:13:15.896472 [(19)]: subch:0  pid:FF4 pmt
2011-05-12 21:13:15.898472 [(19)]: subch:0  pid:FA4 video type:H.264
2011-05-12 21:13:15.898472 [(19)]: subch:0    map pid:FA4 video type:H.264
2011-05-12 21:13:15.899473 [(19)]: subch:0  pid:1044 audio lang:slo type:MPEG-1
2011-05-12 21:13:15.899473 [(19)]: subch:0    map pid:1044 audio lang:slo type:MPEG-1
2011-05-12 21:13:15.899473 [(19)]: subch:0 stop tif
2011-05-12 21:13:15.900473 [(19)]: WaitForPmt: PMT handling took 0,0250015 seconds.
2011-05-12 21:13:15.918474 [(19)]: card: Tuner locked: True
2011-05-12 21:13:15.918474 [(19)]: **************************************************
2011-05-12 21:13:15.919474 [(19)]: ***** SIGNAL LEVEL: 59, SIGNAL QUALITY: 59 *****
2011-05-12 21:13:15.919474 [(19)]: **************************************************
2011-05-12 21:13:15.920474 [(19)]: card: tuned user: XBMCpvrclient1 subchannel: 0
2011-05-12 21:13:15.921474 [(19)]: user:XBMCpvrclient1 add
2011-05-12 21:13:15.921474 [(19)]: card2:XBMCpvrclient1 2 0
2011-05-12 21:13:15.921474 [(19)]: Controller: XBMCpvrclient1 2 0
2011-05-12 21:13:15.922474 [(19)]: control2:XBMCpvrclient1 2 0
2011-05-12 21:13:15.927474 [(19)]: Controller: delete timeshift files C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts
2011-05-12 21:13:15.936475 [(19)]: card: StartTimeShifting 2 C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts 
2011-05-12 21:13:15.937475 [(19)]: card: CAM enabled : True
2011-05-12 21:13:15.938475 [(19)]: subch:0 SetTimeShiftFileName:C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts
2011-05-12 21:13:15.939475 [(19)]: Set video / audio observer
2011-05-12 21:13:15.940475 [(19)]: subch:0 SetTimeShiftFileName fill in pids
2011-05-12 21:13:15.942475 [(19)]: subch:0-0 tswriter StartTimeshifting...
2011-05-12 21:13:16.368499 [(19)]: card: WaitForTimeShiftFile - waiting _eventAudio & _eventVideo
2011-05-12 21:13:16.580512 [(12)]: PID seen - type = Video
2011-05-12 21:13:16.581512 [(12)]: audioVideoEventHandler Video
2011-05-12 21:13:16.681517 [(12)]: PID seen - type = Audio
2011-05-12 21:13:16.681517 [(12)]: audioVideoEventHandler Audio
2011-05-12 21:13:16.681517 [(19)]: card: WaitForTimeShiftFile - video and audio are seen after 0,3140179 seconds
2011-05-12 21:13:16.844527 [(19)]: user:XBMCpvrclient1 card:2 sub:0 add stream:C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts.tsbuffer
2011-05-12 21:13:16.845527 [(19)]: RTSP: start streamer
2011-05-12 21:13:16.846527 [RTSP Streaming thread(20)]: RTSP: Streamer started
2011-05-12 21:13:16.847527 [(19)]: RTSP: add stream stream2.0 file:C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts.tsbuffer
2011-05-12 21:13:16.847527 [(19)]: Controller: StartTimeShifting started on card:2 to C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts.tsbuffer
2011-05-12 21:13:16.863528 [Channel state thread(21)]: Controller: DoSetChannelStates for 116 channels
2011-05-12 21:13:16.864528 [Channel state thread(21)]: ChannelStates.DoSetChannelStates took 0 msec
2011-05-12 21:13:19.218662 [(19)]: TVServerXBMC: Timeshift started for channel: 'STV1 HD' on device 'KNC BDA DVB-C'
2011-05-12 21:13:19.218662 [(19)]: TVServerXBMC: TV Server returned 'rtsp://192.168.1.143:554/stream2.0' as timeshift URL and C:\Data\Private\TV\MediaPortal\timeshift\live2-0.ts.tsbuffer as timeshift file
2011-05-12 21:13:19.219662 [(19)]: TVServerXBMC: Remote server='FILEBOX'
2011-05-12 21:13:19.219662 [(19)]: TVServerXBMC: StartTimeShifting took 5583 ms
2011-05-12 21:13:19.219662 [(19)]: TVServerXBMC: PlayChannel 373 => URL=rtsp://192.168.1.143/stream2.0

No hardware changes were made, didn't touch anything (CI/CAM, antenna or anything). The only thing i did was a reboot.

Before anyone asks - when the CI/CAM card stops working in TV server, it stops working for GlobeTV application as well, so the CI/CAM card is probably left in state where it cannot be used anymore.

It is a software issue in MediaPortal ? Or it is a driver issue from KNC1 ? I think we can safely skip the possibility of the hardware issue, because in that case a simple reboot wouldn't solve it. Any ideas, how to solve it ?
 
F

faugusztin

New Member
May 12, 2011
3
0
Home Country
Slovakia Slovakia
Just a small folowup - after upgrading to 1.2.0 Beta i again got this 25 minutes after the initial tuning :
Code: 
2011-05-13 13:47:41.828596 [(14)]: OnKncCiOpenDisplay slot: 0
2011-05-13 13:47:41.942602 [(14)]: OnKncCiMenu slot:       0
2011-05-13 13:47:41.942602 [(14)]: OnKncCiMenu title:      
2011-05-13 13:47:41.942602 [(14)]: OnKncCiMenu subtitle:   
2011-05-13 13:47:41.943602 [(14)]: OnKncCiMenu bottom:     
2011-05-13 13:47:41.943602 [(14)]: OnKncCiMenu lpszBottom: 
2011-05-13 13:47:41.943602 [(14)]: OnKncCiMenu nNumChoices:1
2011-05-13 13:47:41.944602 [(14)]: OnKncCiMenuChoice slot:0 choice:0 text: Card problem - check card
2011-05-13 13:47:52.025179 [(14)]: OnKncCiCloseDisplay slot:0 nDelay:0

But the similarity to 1.1.3 ends here, because on 1.2.0beta the stream continues, so this is better than before. Also it has no probem switching to other scrambled channels, so my problem was probably fixed between 1.1.3 and 1.2.0beta.
 
M

mm1352000

Retired Team Member
  • Premium Supporter
    • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    Hi faugusztin

    Good interpretation of your logs! :)
    If anything this is a KNC driver, CAM or smartcard problem. All that TV Server can do is to ask the tuner/CAM to decode channels. If we are passing the instructions to the CAM in the wrong way or at the wrong time then it will usually complain straight away and channels will not be decoded. For decoding to stop and not be able to continue until after a reboot, and for other applications to also not be able to use the CAM clearly indicates a driver, CAM or smartcard problem like I said before. It would be interesting to know if reinserting your smartcard or CAM resolves the problem...

    mm

    PS: I will check the code to see if anything has changed between 1.2.0b and 1.1.3. I doubt there would be anything significant, but I will still confirm...
     
    F

    faugusztin

    New Member
    May 12, 2011
    3
    0
    Home Country
    Slovakia Slovakia
    Well, then i have no explanation so far. But the fact is that 1.2.0 beta survived at least one error from CI which did "kill" 1.1.3. The TV server now runs since 13:21:41, at 13:47:41 i got the "OnKncCiMenuChoice slot:0 choice:0 text: Card problem - check card" error, since then i watched 4 different channels. Now it's 15:57 and it still works. Let's hope i will be able to say the same after few more hours.
     
    M

    mm1352000

    Retired Team Member
  • Premium Supporter
    • September 1, 2008
    21,577
    8,224
    Home Country
    New Zealand New Zealand
    Hi again

    It is just as I thought: there have been no significant changes to the KNC hardware handlers since September 2009...
     

    Users who are viewing this thread

    Online now: 2 (members: 0, guests: 2)

    About The Project

    The vision of the MediaPortal project is to create a free open source media centre application, which supports all advanced media centre functions, and is accessible to all Windows users.

    In reaching this goal we are working every day to make sure our software is one of the best.

             

    Quick Navigation

    Support MediaPortal!

    The team works very hard to make sure the community is running the best HTPC-software. We give away MediaPortal for free but hosting and software is not for us.

    Care to support our work with a few bucks? We'd really appreciate it!

    Community platform by XenForo® © 2010-2021 XenForo Ltd.
    Top Bottom