Scrambled DVBS (1 Viewer)

[GagReflex]

TV-Server Version: Latest RC2 SVN
MediaPortal Version: Latest RC2 SVN
MediaPortal Skin: Xface
Windows Version: XP Pro SP3
CPU Type: Intel Core 2 Duo E6300
HDD: 3 x Seagate 320G SATA
Memory: 1 GB DDR2
Motherboard: Gigabyte 965P-DS3
Video Card: Nvidia 7600GS passive cooled
Video Card Driver:
Sound Card:
Sound Card AC3:
Sound Card Driver:
1. TV Card: Dvico Fusion
1. TV Card Type: DVB-T
1. TV Card Driver:
2. TV Card: DNTV Live!
2. TV Card Type: DVB-T
2. TV Card Driver:
3. TV Card: TwinhanDTV Sat-CI
3. TV Card Type: DVB-S
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: SelecTV
HTPC Case: Thermaltake 'Bach'
Cooling:
Power Supply:
Remote: Microsoft MCE
TV: Panasonic AE500 Projector
TV - HTPC Connection: DVI

Since RC2 (including the latest SVN) I'm having hassles trying to tune DVBS channels.
The channels keep coming up as scrambled, I have to keep on tying until one finally tunes and descrambles. This often takes 10+ attempts. Using RC1 there were no problems.

I tried deleting the SQL database and reinstalling from scratch, but the problem still remains. I'm using a client server setup, but I'm seeing the same issue just trying to 'preview' directly from the TV Server setup program.
Anyone else having similar issues??

Thanks

 

[dalmer]

This is the way it used to behave. When you tuned to a channel that was scrambled it would wait until the timeout specified in "wait for scrambled" (or something like that) setting in TVServer. If the signal was still scrambled it would display the message you see.

In recent RC1 SVN's it seemed to behave as other DVB S programs do. It would tune to the channel and show a black screen until the signal became unscrambled.

It seems to have reverted to the previous behaviour. I really wish this would be returned to the black screen while waiting. For one thing it doesn't "lock" the GUI while waiting. You could even display and overlay that says waiting of unscrambled or something so users know what is happening. Devs: Any explanation for the reversion? I didn't see anything in the SVN logs about it. Then again, I didn't see anything about it changing to the black screen either, but I was really happy about it.

GagReflex: Try changing the setting about to a longer value until you find one that works for your CAM. Reinstalling would have reset it to 5 or 10 seconds or whatever it defaults to. Hope this helps.

 

[GagReflex]

My issue is a little more ugly
RC1 would always unscramble without any issues.. RC2, even after setting the timeout high it still fails to unscramble. After MANY attempts at tuning a channel it will come up ok.. and after that I can change to other scrambled channels without an issue. Until I stop or tune to a DVBT channel and then try to go back to a scrambled DVBS.. Then the fun beigins again ...

 

[blaudden]

Hi,

I'm experiencing the same problem with TwinhanDTV Sat-CI as you describe, random failures to tune a descrambled channel from DVB-S.

Have extracted the log files for a number of failed attempts and one good against the same channel. Trying to see if anything differs in the setup of the tune/descramble. Also looking at the code to see if it would be possible to set a longer timeout in 'WaitForUnscramledSignal' but the 5000ms timeout seems to have been hardcoded, so a recompile would be necessary to see if a longer timeout would do the trick.

Please see the logs below. Any hints?


Failed tune of TV4, with "Twhinhan: CAM failed 0x8007001F":


2008-08-03 11:27:02.353500 [5]: Controller: StartTimeShifting TV4 582
2008-08-03 11:27:02.353500 [5]: Controller: find free card for channel TV4
2008-08-03 11:27:02.353500 [5]: Controller: got 1 tuning details for TV4
2008-08-03 11:27:02.369125 [5]: Controller: channel #1 DVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:27:02.447250 [5]: Controller: card:1 typevbS is available priority:2 #users:0 same transponder:False
2008-08-03 11:27:02.462875 [5]: Controller: card:2 type:RadioWebStream cannot tune to channel
2008-08-03 11:27:02.462875 [5]: Controller: found 1 available
2008-08-03 11:27:02.478500 [5]: card: CardTune 1 TV4 neptunus:1:-1
2008-08-03 11:27:02.478500 [5]: card: Tune 1 to TV4
2008-08-03 11:27:02.478500 [5]: card: user: neptunus:1:-1 tune DVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:27:02.556625 [5]: dvbs: TuneVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:27:02.556625 [5]: LNB low:9750 hi:10600 switch:11700
2008-08-03 11:27:02.572250 [5]: Twinhan DVB-S2 modulation set to:ModNotSet
2008-08-03 11:27:02.572250 [5]: Twinhan DVB-S2 Pilot set to:NotSet
2008-08-03 11:27:02.572250 [5]: Twinhan DVB-S2 RollOff set to:NotSet
2008-08-03 11:27:02.572250 [5]: Twinhan DVB-S2 fec set to:Rate7_8
2008-08-03 11:27:02.572250 [5]: Channel modulation is set to ModNotSet
2008-08-03 11:27:02.572250 [5]: Channel FECRate is set to Rate7_8
2008-08-03 11:27:02.572250 [5]: Twinhan: SetLnb diseqc port:0 22khz:1 low:9750 hi:10600 switch:11700 power:True
2008-08-03 11:27:02.572250 [5]: Twinhan: SetLNB ok 0x0
2008-08-03 11:27:02.884750 [5]: TwinHan DiSEqC cmd:4 0 0 0 E0 10 38 FC 0 0 0 0 0 0 0 0 succeeded
2008-08-03 11:27:02.994125 [5]: dvbubmiting tunerequest Channel:TV4 subChannel:-1
2008-08-03 11:27:02.994125 [5]: dvb:Getting new subchannel
2008-08-03 11:27:02.994125 [5]: dvb:GetNewSubChannel:0 #0
2008-08-03 11:27:02.994125 [5]: dvbubmit tunerequest size:1 new:0
2008-08-03 11:27:02.994125 [5]: subch:0 OnBeforeTune
2008-08-03 11:27:02.994125 [5]: dvbubmit tunerequest calling put_TuneRequest
2008-08-03 11:27:03.259750 [5]: dvbubmit tunerequest done calling put_TuneRequest
2008-08-03 11:27:03.259750 [5]: subch:0 OnAfterTune
2008-08-03 11:27:03.259750 [5]: subch:0 OnGraphStart
2008-08-03 11:27:03.259750 [5]: subch0:RunGraph
2008-08-03 11:27:03.259750 [5]: dvb: RunGraph
2008-08-03 11:27:04.197250 [5]: subch:0 OnGraphStart
2008-08-03 11:27:04.197250 [5]: subch:0 RunGraph: already running
2008-08-03 11:27:04.197250 [5]: subch:0 SetupPmtGrabberid 100 sid:642
2008-08-03 11:27:04.197250 [5]: subch:0 set pmt grabber pmt:100 sid:642
2008-08-03 11:27:04.197250 [5]: subch:0 wait for pmt 100
2008-08-03 11:27:04.228500 [5]: subch:0 wait for pmt 100
2008-08-03 11:27:04.244125 [5]: subch:0 wait for pmt 100
2008-08-03 11:27:04.259750 [5]: subch:0 wait for pmt 100
2008-08-03 11:27:04.291000 [5]: subch:0 wait for pmt 100
2008-08-03 11:27:04.431625 [12]: subch:0 OnPMTReceived() True
2008-08-03 11:27:04.431625 [12]: subch:0 SendPmt:642 642 FFFFFFFF 8
2008-08-03 11:27:04.431625 [12]: Decode pmt
2008-08-03 11:27:04.431625 [12]: descr1 len:6 9 4 b 0 e0 40
2008-08-03 11:27:04.431625 [12]: Set descriptor data with length 6
2008-08-03 11:27:04.431625 [12]: Set descriptor data with length 7
2008-08-03 11:27:04.447250 [12]: Set descriptor data with length 3
2008-08-03 11:27:04.447250 [12]: subch:0 SendPMT version:8 len:114 1602
2008-08-03 11:27:04.447250 [12]: Decode pmt
2008-08-03 11:27:04.447250 [12]: descr1 len:6 9 4 b 0 e0 40
2008-08-03 11:27:04.447250 [12]: Set descriptor data with length 6
2008-08-03 11:27:04.447250 [12]: Set descriptor data with length 7
2008-08-03 11:27:04.447250 [12]: Set descriptor data with length 3
2008-08-03 11:27:04.447250 [12]: Twinhan: Send PMT camefault len:23 video:0x200 audio:0x280
2008-08-03 11:27:04.447250 [12]: capmt:3 6 42 D1 0 7 1 9 4 B 0 E0 40 2 E2 0 0 0 4 E2 80 0 0
2008-08-03 11:27:04.447250 [5]: subch:0 wait for pmt 100
2008-08-03 11:27:04.462875 [5]: subch:0 wait for pmt 100
2008-08-03 11:27:04.494125 [5]: subch:0 wait for pmt 100
2008-08-03 11:27:04.509750 [5]: subch:0 wait for pmt 100
2008-08-03 11:27:04.541000 [5]: subch:0 wait for pmt 100
2008-08-03 11:27:05.353500 [12]: Twinhan: CAM failed 0x8007001F
2008-08-03 11:27:05.353500 [12]: subch:0 cam flags:True
2008-08-03 11:27:05.353500 [12]: subch:0 SetMpegPidMapping
2008-08-03 11:27:05.353500 [12]: subch:0 pid:0 pcr
2008-08-03 11:27:05.353500 [12]: subch:0 pid:100 pmt
2008-08-03 11:27:05.369125 [12]: subch:0 pid:200 video type:MPEG-2
2008-08-03 11:27:05.369125 [12]: subch:0 map pid:200 video type:MPEG-2
2008-08-03 11:27:05.369125 [12]: subch:0 pid:280 audio lang:swe type:MPEG-2
2008-08-03 11:27:05.369125 [12]: subch:0 map pid:280 audio lang:swe type:MPEG-2
2008-08-03 11:27:05.369125 [12]: subch:0 pid:240 teletext type:6
2008-08-03 11:27:05.369125 [12]: subch:0 map pid:240 teletext type:6
2008-08-03 11:27:05.369125 [12]: subch:0 pid:8FB type:B
2008-08-03 11:27:05.369125 [12]: subch:0 pid:350 type:C0
2008-08-03 11:27:05.369125 [12]: subch:0 pid:250 type:6
2008-08-03 11:27:05.369125 [12]: subch:0 stop tif
2008-08-03 11:27:05.369125 [5]: card: tuned user: neptunus subchannel: 0
2008-08-03 11:27:05.384750 [5]: user:neptunus add
2008-08-03 11:27:14.900375 [5]: card: Tuner locked: False
2008-08-03 11:27:14.900375 [5]: **************************************************
2008-08-03 11:27:14.900375 [5]: ***** SIGNAL LEVEL: 0, SIGNAL QUALITY: 0 *****
2008-08-03 11:27:14.900375 [5]: **************************************************
2008-08-03 11:27:14.900375 [5]: card2:neptunus 1 0
2008-08-03 11:27:14.900375 [5]: Controller: neptunus 1 0
2008-08-03 11:27:14.916000 [5]: control2:neptunus 1 0
2008-08-03 11:27:16.728500 [5]: Controller: delete timeshift files D:\tvserver\timeshiftbuffer\live1-0.ts
2008-08-03 11:27:16.744125 [5]: Controller: delete D:\tvserver\timeshiftbuffer\live1-0.ts.tsbuffer
2008-08-03 11:27:16.759750 [5]: Controller: delete D:\tvserver\timeshiftbuffer\live1-0.ts.tsbuffer1.ts
2008-08-03 11:27:16.759750 [5]: Controller: delete D:\tvserver\timeshiftbuffer\live1-0.ts.tsbuffer2.ts
2008-08-03 11:27:16.775375 [5]: card: StartTimeShifting 1 D:\tvserver\timeshiftbuffer\live1-0.ts
2008-08-03 11:27:16.791000 [5]: card: WaitForUnScrambledSignal
2008-08-03 11:27:16.791000 [5]: card: scrambled, sleep 100
2008-08-03 11:27:16.884750 [5]: card: scrambled, sleep 100
2008-08-03 11:27:16.994125 [5]: card: scrambled, sleep 100
2008-08-03 11:27:17.087875 [5]: card: scrambled, sleep 100
2008-08-03 11:27:17.197250 [5]: card: scrambled, sleep 100
2008-08-03 11:27:21.822250 [5]: card: return scrambled
2008-08-03 11:27:21.822250 [5]: card: channel is scrambled
2008-08-03 11:27:21.822250 [5]: card: remove user:neptunus sub:0
2008-08-03 11:27:21.822250 [5]: user:neptunus remove
2008-08-03 11:27:21.837875 [5]: card: free subchannel sub:0
2008-08-03 11:27:21.837875 [5]: tvcard:FreeSubChannel:1 #0
2008-08-03 11:27:21.837875 [5]: analog subch:0 Decompose()
2008-08-03 11:27:21.837875 [5]: tvcard:FreeAllSubChannels:
2008-08-03 11:27:21.837875 [5]: dvbtopGraph
2008-08-03 11:27:21.853500 [5]: tvcard:FreeAllSubChannels:


Failed tune of TV4, but notice "Twinhan: CAM returned 0x0":


2008-08-03 11:30:52.228500 [9]: card: CardTune 1 TV4 neptunus:1:-1
2008-08-03 11:30:52.228500 [9]: card: Tune 1 to TV4
2008-08-03 11:30:52.228500 [9]: card: user: neptunus:1:-1 tune DVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:30:52.337875 [9]: dvbs: TuneVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:30:52.337875 [9]: LNB low:9750 hi:10600 switch:11700
2008-08-03 11:30:52.337875 [9]: Twinhan DVB-S2 modulation set to:ModNotSet
2008-08-03 11:30:52.337875 [9]: Twinhan DVB-S2 Pilot set to:NotSet
2008-08-03 11:30:52.337875 [9]: Twinhan DVB-S2 RollOff set to:NotSet
2008-08-03 11:30:52.337875 [9]: Twinhan DVB-S2 fec set to:Rate7_8
2008-08-03 11:30:52.337875 [9]: Channel modulation is set to ModNotSet
2008-08-03 11:30:52.337875 [9]: Channel FECRate is set to Rate7_8
2008-08-03 11:30:52.337875 [9]: Twinhan: SetLnb diseqc port:0 22khz:1 low:9750 hi:10600 switch:11700 power:True
2008-08-03 11:30:54.556625 [9]: Twinhan: SetLNB ok 0x0
2008-08-03 11:30:54.837875 [9]: TwinHan DiSEqC cmd:4 0 0 0 E0 10 38 FC 0 0 0 0 0 0 0 0 failed 0x8007001F
2008-08-03 11:30:54.947250 [9]: dvbubmiting tunerequest Channel:TV4 subChannel:-1
2008-08-03 11:30:54.947250 [9]: dvb:Getting new subchannel
2008-08-03 11:30:54.947250 [9]: dvb:GetNewSubChannel:0 #0
2008-08-03 11:30:54.947250 [9]: dvbubmit tunerequest size:1 new:0
2008-08-03 11:30:54.947250 [9]: subch:0 OnBeforeTune
2008-08-03 11:30:54.962875 [9]: dvbubmit tunerequest calling put_TuneRequest
2008-08-03 11:31:03.650375 [9]: dvbubmit tunerequest done calling put_TuneRequest
2008-08-03 11:31:03.650375 [9]: subch:0 OnAfterTune
2008-08-03 11:31:03.650375 [9]: subch:0 OnGraphStart
2008-08-03 11:31:03.666000 [9]: subch0:RunGraph
2008-08-03 11:31:03.666000 [9]: dvb: RunGraph
2008-08-03 11:31:04.244125 [9]: subch:0 OnGraphStart
2008-08-03 11:31:04.244125 [9]: subch:0 RunGraph: already running
2008-08-03 11:31:04.244125 [9]: subch:0 SetupPmtGrabberid 100 sid:642
2008-08-03 11:31:04.244125 [9]: subch:0 set pmt grabber pmt:100 sid:642
2008-08-03 11:31:04.244125 [9]: subch:0 wait for pmt 100
2008-08-03 11:31:04.275375 [9]: subch:0 wait for pmt 100
2008-08-03 11:31:04.291000 [9]: subch:0 wait for pmt 100
2008-08-03 11:31:04.306625 [9]: subch:0 wait for pmt 100
2008-08-03 11:31:04.337875 [9]: subch:0 wait for pmt 100
2008-08-03 11:31:04.400375 [12]: subch:0 OnPMTReceived() True
2008-08-03 11:31:04.400375 [12]: subch:0 SendPmt:642 642 FFFFFFFF 8
2008-08-03 11:31:04.400375 [12]: Decode pmt
2008-08-03 11:31:04.400375 [12]: descr1 len:6 9 4 b 0 e0 40
2008-08-03 11:31:04.416000 [12]: Set descriptor data with length 6
2008-08-03 11:31:04.416000 [12]: Set descriptor data with length 7
2008-08-03 11:31:04.416000 [12]: Set descriptor data with length 3
2008-08-03 11:31:04.416000 [12]: subch:0 SendPMT version:8 len:114 1602
2008-08-03 11:31:04.416000 [12]: Decode pmt
2008-08-03 11:31:04.416000 [12]: descr1 len:6 9 4 b 0 e0 40
2008-08-03 11:31:04.416000 [12]: Set descriptor data with length 6
2008-08-03 11:31:04.416000 [12]: Set descriptor data with length 7
2008-08-03 11:31:04.416000 [12]: Set descriptor data with length 3
2008-08-03 11:31:04.416000 [12]: Twinhan: Send PMT camefault len:23 video:0x200 audio:0x280
2008-08-03 11:31:04.416000 [12]: capmt:3 6 42 D1 0 7 1 9 4 B 0 E0 40 2 E2 0 0 0 4 E2 80 0 0
2008-08-03 11:31:04.416000 [9]: subch:0 wait for pmt 100
2008-08-03 11:31:04.447250 [9]: subch:0 wait for pmt 100
2008-08-03 11:31:04.447250 [12]: Twinhan: CAM returned ok 0x0
2008-08-03 11:31:04.447250 [12]: subch:0 cam flags:True
2008-08-03 11:31:04.447250 [12]: subch:0 SetMpegPidMapping
2008-08-03 11:31:04.447250 [12]: subch:0 pid:0 pcr
2008-08-03 11:31:04.462875 [12]: subch:0 pid:100 pmt
2008-08-03 11:31:04.462875 [12]: subch:0 pid:200 video type:MPEG-2
2008-08-03 11:31:04.462875 [12]: subch:0 map pid:200 video type:MPEG-2
2008-08-03 11:31:04.462875 [12]: subch:0 pid:280 audio lang:swe type:MPEG-2
2008-08-03 11:31:04.462875 [12]: subch:0 map pid:280 audio lang:swe type:MPEG-2
2008-08-03 11:31:04.462875 [12]: subch:0 pid:240 teletext type:6
2008-08-03 11:31:04.462875 [12]: subch:0 map pid:240 teletext type:6
2008-08-03 11:31:04.462875 [12]: subch:0 pid:8FB type:B
2008-08-03 11:31:04.462875 [12]: subch:0 pid:350 type:C0
2008-08-03 11:31:04.462875 [12]: subch:0 pid:250 type:6
2008-08-03 11:31:04.478500 [12]: subch:0 stop tif
2008-08-03 11:31:04.478500 [9]: card: tuned user: neptunus subchannel: 0
2008-08-03 11:31:04.478500 [9]: user:neptunus add
2008-08-03 11:31:04.525375 [9]: card: Tuner locked: False
2008-08-03 11:31:04.525375 [9]: **************************************************
2008-08-03 11:31:04.525375 [9]: ***** SIGNAL LEVEL: 0, SIGNAL QUALITY: 0 *****
2008-08-03 11:31:04.525375 [9]: **************************************************
2008-08-03 11:31:04.525375 [9]: card2:neptunus 1 0
2008-08-03 11:31:04.525375 [9]: Controller: neptunus 1 0
2008-08-03 11:31:04.541000 [9]: control2:neptunus 1 0
2008-08-03 11:31:04.556625 [9]: Controller: delete timeshift files D:\tvserver\timeshiftbuffer\live1-0.ts
2008-08-03 11:31:04.556625 [9]: card: StartTimeShifting 1 D:\tvserver\timeshiftbuffer\live1-0.ts
2008-08-03 11:31:04.556625 [9]: card: WaitForUnScrambledSignal
2008-08-03 11:31:04.556625 [9]: card: scrambled, sleep 100
2008-08-03 11:31:04.666000 [9]: card: scrambled, sleep 100
2008-08-03 11:31:04.775375 [9]: card: scrambled, sleep 100
2008-08-03 11:31:04.869125 [9]: card: scrambled, sleep 100
2008-08-03 11:31:04.978500 [9]: card: scrambled, sleep 100
2008-08-03 11:31:09.603500 [9]: card: return scrambled
2008-08-03 11:31:09.603500 [9]: card: channel is scrambled
2008-08-03 11:31:09.603500 [9]: card: remove user:neptunus sub:0
2008-08-03 11:31:09.603500 [9]: user:neptunus remove
2008-08-03 11:31:09.619125 [9]: card: free subchannel sub:0
2008-08-03 11:31:09.619125 [9]: tvcard:FreeSubChannel:1 #0
2008-08-03 11:31:09.619125 [9]: analog subch:0 Decompose()
2008-08-03 11:31:09.619125 [9]: tvcard:FreeAllSubChannels:
2008-08-03 11:31:09.619125 [9]: dvbtopGraph
2008-08-03 11:31:09.619125 [9]: tvcard:FreeAllSubChannels:



Failed tune of TV4, altough it seems like the descramble "kind of worked", it failed with can't

2008-08-03 11:33:01.541000 [9]: Controller: StartTimeShifting TV4 582
2008-08-03 11:33:01.541000 [9]: Controller: find free card for channel TV4
2008-08-03 11:33:01.556625 [9]: Controller: got 1 tuning details for TV4
2008-08-03 11:33:01.556625 [9]: Controller: channel #1 DVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:33:03.572250 [9]: Controller: card:1 typevbS is available priority:2 #users:0 same transponder:False
2008-08-03 11:33:03.572250 [9]: Controller: card:2 type:RadioWebStream cannot tune to channel
2008-08-03 11:33:03.572250 [9]: Controller: found 1 available
2008-08-03 11:33:03.572250 [9]: card: CardTune 1 TV4 neptunus:1:-1
2008-08-03 11:33:03.572250 [9]: card: Tune 1 to TV4
2008-08-03 11:33:03.572250 [9]: card: user: neptunus:1:-1 tune DVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:33:03.666000 [9]: dvbs: TuneVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:33:03.666000 [9]: LNB low:9750 hi:10600 switch:11700
2008-08-03 11:33:03.666000 [9]: Twinhan DVB-S2 modulation set to:ModNotSet
2008-08-03 11:33:03.666000 [9]: Twinhan DVB-S2 Pilot set to:NotSet
2008-08-03 11:33:03.666000 [9]: Twinhan DVB-S2 RollOff set to:NotSet
2008-08-03 11:33:03.666000 [9]: Twinhan DVB-S2 fec set to:Rate7_8
2008-08-03 11:33:03.666000 [9]: Channel modulation is set to ModNotSet
2008-08-03 11:33:03.666000 [9]: Channel FECRate is set to Rate7_8
2008-08-03 11:33:03.681625 [9]: Twinhan: SetLnb diseqc port:0 22khz:1 low:9750 hi:10600 switch:11700 power:True
2008-08-03 11:33:03.681625 [9]: Twinhan: SetLNB ok 0x0
2008-08-03 11:33:03.994125 [9]: TwinHan DiSEqC cmd:4 0 0 0 E0 10 38 FC 0 0 0 0 0 0 0 0 succeeded
2008-08-03 11:33:04.087875 [9]: dvbubmiting tunerequest Channel:TV4 subChannel:-1
2008-08-03 11:33:04.087875 [9]: dvb:Getting new subchannel
2008-08-03 11:33:04.087875 [9]: dvb:GetNewSubChannel:0 #0
2008-08-03 11:33:04.103500 [9]: dvbubmit tunerequest size:1 new:0
2008-08-03 11:33:04.103500 [9]: subch:0 OnBeforeTune
2008-08-03 11:33:04.103500 [9]: dvbubmit tunerequest calling put_TuneRequest
2008-08-03 11:33:04.353500 [9]: dvbubmit tunerequest done calling put_TuneRequest
2008-08-03 11:33:04.353500 [9]: subch:0 OnAfterTune
2008-08-03 11:33:04.353500 [9]: subch:0 OnGraphStart
2008-08-03 11:33:04.353500 [9]: subch0:RunGraph
2008-08-03 11:33:04.353500 [9]: dvb: RunGraph
2008-08-03 11:33:04.916000 [9]: subch:0 OnGraphStart
2008-08-03 11:33:04.916000 [9]: subch:0 RunGraph: already running
2008-08-03 11:33:04.916000 [9]: subch:0 SetupPmtGrabberid 100 sid:642
2008-08-03 11:33:04.916000 [9]: subch:0 set pmt grabber pmt:100 sid:642
2008-08-03 11:33:04.916000 [9]: subch:0 wait for pmt 100
2008-08-03 11:33:04.931625 [9]: subch:0 wait for pmt 100
2008-08-03 11:33:04.962875 [9]: subch:0 wait for pmt 100
2008-08-03 11:33:04.978500 [9]: subch:0 wait for pmt 100
2008-08-03 11:33:04.994125 [12]: subch:0 OnPMTReceived() True
2008-08-03 11:33:04.994125 [12]: subch:0 SendPmt:642 642 FFFFFFFF 8
2008-08-03 11:33:04.994125 [12]: Decode pmt
2008-08-03 11:33:04.994125 [12]: descr1 len:6 9 4 b 0 e0 40
2008-08-03 11:33:04.994125 [12]: Set descriptor data with length 6
2008-08-03 11:33:04.994125 [12]: Set descriptor data with length 7
2008-08-03 11:33:04.994125 [12]: Set descriptor data with length 3
2008-08-03 11:33:04.994125 [12]: subch:0 SendPMT version:8 len:114 1602
2008-08-03 11:33:04.994125 [12]: Decode pmt
2008-08-03 11:33:04.994125 [12]: descr1 len:6 9 4 b 0 e0 40
2008-08-03 11:33:04.994125 [12]: Set descriptor data with length 6
2008-08-03 11:33:05.009750 [12]: Set descriptor data with length 7
2008-08-03 11:33:05.009750 [12]: Set descriptor data with length 3
2008-08-03 11:33:05.009750 [12]: Twinhan: Send PMT camefault len:23 video:0x200 audio:0x280
2008-08-03 11:33:05.009750 [12]: capmt:3 6 42 D1 0 7 1 9 4 B 0 E0 40 2 E2 0 0 0 4 E2 80 0 0
2008-08-03 11:33:05.009750 [9]: subch:0 wait for pmt 100
2008-08-03 11:33:05.025375 [9]: subch:0 wait for pmt 100
2008-08-03 11:33:05.056625 [9]: subch:0 wait for pmt 100
2008-08-03 11:33:05.072250 [9]: subch:0 wait for pmt 100
2008-08-03 11:33:05.087875 [9]: subch:0 wait for pmt 100
2008-08-03 11:33:05.900375 [12]: Twinhan: CAM failed 0x8007001F
2008-08-03 11:33:05.900375 [12]: subch:0 cam flags:True
2008-08-03 11:33:05.900375 [12]: subch:0 SetMpegPidMapping
2008-08-03 11:33:05.900375 [12]: subch:0 pid:0 pcr
2008-08-03 11:33:05.900375 [12]: subch:0 pid:100 pmt
2008-08-03 11:33:05.900375 [12]: subch:0 pid:200 video type:MPEG-2
2008-08-03 11:33:05.900375 [12]: subch:0 map pid:200 video type:MPEG-2
2008-08-03 11:33:05.900375 [9]: card: tuned user: neptunus subchannel: 0
2008-08-03 11:33:05.900375 [9]: user:neptunus add
2008-08-03 11:33:05.931625 [9]: card: Tuner locked: False
2008-08-03 11:33:05.931625 [9]: **************************************************
2008-08-03 11:33:05.931625 [9]: ***** SIGNAL LEVEL: 0, SIGNAL QUALITY: 0 *****
2008-08-03 11:33:05.931625 [9]: **************************************************
2008-08-03 11:33:05.931625 [9]: card2:neptunus 1 0
2008-08-03 11:33:05.931625 [9]: Controller: neptunus 1 0
2008-08-03 11:33:05.947250 [12]: subch:0 pid:280 audio lang:swe type:MPEG-2
2008-08-03 11:33:05.947250 [12]: subch:0 map pid:280 audio lang:swe type:MPEG-2
2008-08-03 11:33:05.947250 [12]: subch:0 pid:240 teletext type:6
2008-08-03 11:33:05.947250 [12]: subch:0 map pid:240 teletext type:6
2008-08-03 11:33:05.947250 [12]: subch:0 pid:8FB type:B
2008-08-03 11:33:05.947250 [12]: subch:0 pid:350 type:C0
2008-08-03 11:33:05.947250 [12]: subch:0 pid:250 type:6
2008-08-03 11:33:05.947250 [12]: subch:0 stop tif
2008-08-03 11:33:05.962875 [9]: control2:neptunus 1 0
2008-08-03 11:33:05.978500 [9]: Controller: delete timeshift files D:\tvserver\timeshiftbuffer\live1-0.ts
2008-08-03 11:33:05.994125 [9]: card: StartTimeShifting 1 D:\tvserver\timeshiftbuffer\live1-0.ts
2008-08-03 11:33:05.994125 [9]: card: WaitForUnScrambledSignal
2008-08-03 11:33:05.994125 [9]: card: return not scrambled
2008-08-03 11:33:05.994125 [9]: subch:0 SetTimeShiftFileName:\tvserver\timeshiftbuffer\live1-0.ts
2008-08-03 11:33:05.994125 [9]: subch:0 SetTimeShiftFileName fill in pids
2008-08-03 11:33:05.994125 [9]: Set video / audio observer
2008-08-03 11:33:06.009750 [9]: card: WaitForTimeShiftFile
2008-08-03 11:33:06.009750 [9]: card: WaitForUnScrambledSignal
2008-08-03 11:33:06.009750 [9]: card: return not scrambled
2008-08-03 11:33:06.009750 [9]: card: WaitForTimeShiftFile - waiting _eventAudio & _eventVideo
2008-08-03 11:33:09.759750 [9]: card: WaitForTimeShiftFile - new observer based method didn't work, using the old one as fall back!
2008-08-03 11:33:17.306625 [9]: card: timeshifting fileSize:0 TIMEOUT
2008-08-03 11:33:17.306625 [9]: card: remove user:neptunus sub:0
2008-08-03 11:33:17.306625 [9]: user:neptunus remove
2008-08-03 11:33:17.306625 [9]: card: free subchannel sub:0
2008-08-03 11:33:17.306625 [9]: tvcard:FreeSubChannel:1 #0
2008-08-03 11:33:17.306625 [9]: analog subch:0 Decompose()
2008-08-03 11:33:17.306625 [9]: subch:0 StopTimeshifting()
2008-08-03 11:33:17.322250 [9]: tvcard:FreeAllSubChannels:
2008-08-03 11:33:17.322250 [9]: dvbtopGraph
2008-08-03 11:33:17.322250 [9]: tvcard:FreeAllSubChannels:


And finally, after 10+ attempts a succesful descramble and tune.

2008-08-03 11:35:26.181625 [9]: Controller: StartTimeShifting TV4 582
2008-08-03 11:35:26.197250 [9]: Controller: find free card for channel TV4
2008-08-03 11:35:26.197250 [9]: Controller: got 1 tuning details for TV4
2008-08-03 11:35:26.197250 [9]: Controller: channel #1 DVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:35:26.697250 [9]: Controller: card:1 typevbS is available priority:2 #users:0 same transponder:False
2008-08-03 11:35:26.697250 [9]: Controller: card:2 type:RadioWebStream cannot tune to channel
2008-08-03 11:35:26.697250 [9]: Controller: found 1 available
2008-08-03 11:35:26.697250 [9]: card: CardTune 1 TV4 neptunus:1:-1
2008-08-03 11:35:26.697250 [9]: card: Tune 1 to TV4
2008-08-03 11:35:26.712875 [9]: card: user: neptunus:1:-1 tune DVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:35:26.806625 [9]: dvbs: TuneVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:35:26.806625 [9]: LNB low:9750 hi:10600 switch:11700
2008-08-03 11:35:26.806625 [9]: Twinhan DVB-S2 modulation set to:ModNotSet
2008-08-03 11:35:26.806625 [9]: Twinhan DVB-S2 Pilot set to:NotSet
2008-08-03 11:35:26.806625 [9]: Twinhan DVB-S2 RollOff set to:NotSet
2008-08-03 11:35:26.806625 [9]: Twinhan DVB-S2 fec set to:Rate7_8
2008-08-03 11:35:26.806625 [9]: Channel modulation is set to ModNotSet
2008-08-03 11:35:26.806625 [9]: Channel FECRate is set to Rate7_8
2008-08-03 11:35:26.806625 [9]: Twinhan: SetLnb diseqc port:0 22khz:1 low:9750 hi:10600 switch:11700 power:True
2008-08-03 11:35:26.822250 [9]: Twinhan: SetLNB ok 0x0
2008-08-03 11:35:27.134750 [9]: TwinHan DiSEqC cmd:4 0 0 0 E0 10 38 FC 0 0 0 0 0 0 0 0 succeeded
2008-08-03 11:35:27.228500 [9]: dvbubmiting tunerequest Channel:TV4 subChannel:-1
2008-08-03 11:35:27.228500 [9]: dvb:Getting new subchannel
2008-08-03 11:35:27.228500 [9]: dvb:GetNewSubChannel:0 #0
2008-08-03 11:35:27.228500 [9]: dvbubmit tunerequest size:1 new:0
2008-08-03 11:35:27.244125 [9]: subch:0 OnBeforeTune
2008-08-03 11:35:27.244125 [9]: dvbubmit tunerequest calling put_TuneRequest
2008-08-03 11:35:27.494125 [9]: dvbubmit tunerequest done calling put_TuneRequest
2008-08-03 11:35:27.494125 [9]: subch:0 OnAfterTune
2008-08-03 11:35:27.494125 [9]: subch:0 OnGraphStart
2008-08-03 11:35:27.494125 [9]: subch0:RunGraph
2008-08-03 11:35:27.494125 [9]: dvb: RunGraph
2008-08-03 11:35:28.056625 [9]: subch:0 OnGraphStart
2008-08-03 11:35:28.056625 [9]: subch:0 RunGraph: already running
2008-08-03 11:35:28.056625 [9]: subch:0 SetupPmtGrabberid 100 sid:642
2008-08-03 11:35:28.056625 [9]: subch:0 set pmt grabber pmt:100 sid:642
2008-08-03 11:35:28.056625 [9]: subch:0 wait for pmt 100
2008-08-03 11:35:28.072250 [9]: subch:0 wait for pmt 100
2008-08-03 11:35:28.103500 [9]: subch:0 wait for pmt 100
2008-08-03 11:35:28.119125 [9]: subch:0 wait for pmt 100
2008-08-03 11:35:28.134750 [12]: subch:0 OnPMTReceived() True
2008-08-03 11:35:28.134750 [12]: subch:0 SendPmt:642 642 FFFFFFFF 8
2008-08-03 11:35:28.134750 [12]: Decode pmt
2008-08-03 11:35:28.134750 [12]: descr1 len:6 9 4 b 0 e0 40
2008-08-03 11:35:28.134750 [12]: Set descriptor data with length 6
2008-08-03 11:35:28.150375 [12]: Set descriptor data with length 7
2008-08-03 11:35:28.150375 [12]: Set descriptor data with length 3
2008-08-03 11:35:28.150375 [12]: subch:0 SendPMT version:8 len:114 1602
2008-08-03 11:35:28.150375 [12]: Decode pmt
2008-08-03 11:35:28.150375 [12]: descr1 len:6 9 4 b 0 e0 40
2008-08-03 11:35:28.150375 [12]: Set descriptor data with length 6
2008-08-03 11:35:28.150375 [12]: Set descriptor data with length 7
2008-08-03 11:35:28.150375 [12]: Set descriptor data with length 3
2008-08-03 11:35:28.150375 [12]: Twinhan: Send PMT camefault len:23 video:0x200 audio:0x280
2008-08-03 11:35:28.150375 [9]: subch:0 wait for pmt 100
2008-08-03 11:35:28.150375 [12]: capmt:3 6 42 D1 0 7 1 9 4 B 0 E0 40 2 E2 0 0 0 4 E2 80 0 0
2008-08-03 11:35:28.166000 [9]: subch:0 wait for pmt 100
2008-08-03 11:35:28.181625 [12]: Twinhan: CAM returned ok 0x0
2008-08-03 11:35:28.181625 [12]: subch:0 cam flags:True
2008-08-03 11:35:28.181625 [12]: subch:0 SetMpegPidMapping
2008-08-03 11:35:28.181625 [12]: subch:0 pid:0 pcr
2008-08-03 11:35:28.181625 [12]: subch:0 pid:100 pmt
2008-08-03 11:35:28.181625 [12]: subch:0 pid:200 video type:MPEG-2
2008-08-03 11:35:28.181625 [12]: subch:0 map pid:200 video type:MPEG-2
2008-08-03 11:35:28.197250 [12]: subch:0 pid:280 audio lang:swe type:MPEG-2
2008-08-03 11:35:28.197250 [12]: subch:0 map pid:280 audio lang:swe type:MPEG-2
2008-08-03 11:35:28.197250 [9]: card: tuned user: neptunus subchannel: 0
2008-08-03 11:35:28.197250 [9]: user:neptunus add
2008-08-03 11:35:28.197250 [12]: subch:0 pid:240 teletext type:6
2008-08-03 11:35:28.197250 [12]: subch:0 map pid:240 teletext type:6
2008-08-03 11:35:28.197250 [12]: subch:0 pid:8FB type:B
2008-08-03 11:35:28.197250 [12]: subch:0 pid:350 type:C0
2008-08-03 11:35:28.197250 [12]: subch:0 pid:250 type:6
2008-08-03 11:35:28.197250 [12]: subch:0 stop tif
2008-08-03 11:35:28.291000 [9]: card: Tuner locked: False
2008-08-03 11:35:28.291000 [9]: **************************************************
2008-08-03 11:35:28.291000 [9]: ***** SIGNAL LEVEL: 0, SIGNAL QUALITY: 0 *****
2008-08-03 11:35:28.291000 [9]: **************************************************
2008-08-03 11:35:28.291000 [9]: card2:neptunus 1 0
2008-08-03 11:35:28.291000 [9]: Controller: neptunus 1 0
2008-08-03 11:35:28.291000 [9]: control2:neptunus 1 0
2008-08-03 11:35:28.306625 [9]: Controller: delete timeshift files D:\tvserver\timeshiftbuffer\live1-0.ts
2008-08-03 11:35:28.306625 [9]: card: StartTimeShifting 1 D:\tvserver\timeshiftbuffer\live1-0.ts
2008-08-03 11:35:28.306625 [9]: card: WaitForUnScrambledSignal
2008-08-03 11:35:28.322250 [9]: card: scrambled, sleep 100
2008-08-03 11:35:28.416000 [9]: card: scrambled, sleep 100
2008-08-03 11:35:28.525375 [9]: card: scrambled, sleep 100
2008-08-03 11:35:28.619125 [9]: card: scrambled, sleep 100
2008-08-03 11:35:28.728500 [9]: card: scrambled, sleep 100
2008-08-03 11:35:30.634750 [9]: card: return not scrambled
2008-08-03 11:35:30.634750 [9]: subch:0 SetTimeShiftFileName:\tvserver\timeshiftbuffer\live1-0.ts
2008-08-03 11:35:30.634750 [9]: subch:0 SetTimeShiftFileName fill in pids
2008-08-03 11:35:30.650375 [9]: Set video / audio observer
2008-08-03 11:35:30.650375 [9]: card: WaitForTimeShiftFile
2008-08-03 11:35:30.666000 [9]: card: WaitForUnScrambledSignal
2008-08-03 11:35:30.666000 [9]: card: return not scrambled
2008-08-03 11:35:30.666000 [9]: card: WaitForTimeShiftFile - waiting _eventAudio & _eventVideo
2008-08-03 11:35:30.775375 [12]: PID seen - type = Audio
2008-08-03 11:35:30.775375 [12]: audioVideoEventHandler Audio
2008-08-03 11:35:31.009750 [12]: PID seen - type = Video
2008-08-03 11:35:31.009750 [12]: audioVideoEventHandler Video
2008-08-03 11:35:31.009750 [9]: card: WaitForTimeShiftFile - start of the video & audio is seen
2008-08-03 11:35:31.275375 [9]: user:neptunus card:1 sub:0 add stream:\tvserver\timeshiftbuffer\live1-0.ts.tsbuffer
2008-08-03 11:35:31.291000 [9]: RTSP: add stream stream1.0 file:\tvserver\timeshiftbuffer\live1-0.ts.tsbuffer
2008-08-03 11:35:31.291000 [9]: Controller: StartTimeShifting started on card:1 to D:\tvserver\timeshiftbuffer\live1-0.ts.tsbuffer
2008-08-03 11:35:31.306625 [SetupTv]: preview TV4 user:1 0 neptunus D:\tvserver\timeshiftbuffer\live1-0.ts.tsbuffer
2008-08-03 11:35:31.322250 [SetupTv]: play:\tvserver\timeshiftbuffer\live1-0.ts.tsbuffer
2008-08-03 11:35:31.947250 [SetupTv]: TSReaderPlayer:add TsReader to graph
2008-08-03 11:35:31.947250 [SetupTv]: load file in Ts
2008-08-03 11:35:31.962875 [SetupTv]: TSReaderPlayer:render TsReader outputs
2008-08-03 11:35:34.712875 [SetupTv]: run graph
2008-08-03 11:35:34.759750 [SetupTv]: TSReaderPlayer:running:1
2008-08-03 11:35:57.150375 [PowerEventThread]: TV service PowerEventThread 49388


Next attempt, failas again:

2008-08-03 11:37:17.712875 [5]: Controller: StartTimeShifting TV4 582
2008-08-03 11:37:17.712875 [5]: Controller: find free card for channel TV4
2008-08-03 11:37:17.728500 [5]: Controller: got 1 tuning details for TV4
2008-08-03 11:37:17.728500 [5]: Controller: channel #1 DVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:37:17.759750 [5]: Controller: card:1 typevbS is available priority:2 #users:0 same transponder:False
2008-08-03 11:37:17.759750 [5]: Controller: card:2 type:RadioWebStream cannot tune to channel
2008-08-03 11:37:17.759750 [5]: Controller: found 1 available
2008-08-03 11:37:17.759750 [5]: card: CardTune 1 TV4 neptunus:1:-1
2008-08-03 11:37:17.759750 [5]: card: Tune 1 to TV4
2008-08-03 11:37:17.759750 [5]: card: user: neptunus:1:-1 tune DVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:37:17.853500 [5]: dvbs: TuneVBS:tv:Telenor TV4 Freq:11216000 ONID:70 TSID:27 SID:1602 PMT:100 FTA:False LCN:582 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:None band:Universal Pilot:NotSet RollOff:NotSet
2008-08-03 11:37:17.853500 [5]: LNB low:9750 hi:10600 switch:11700
2008-08-03 11:37:17.869125 [5]: Twinhan DVB-S2 modulation set to:ModNotSet
2008-08-03 11:37:17.869125 [5]: Twinhan DVB-S2 Pilot set to:NotSet
2008-08-03 11:37:17.869125 [5]: Twinhan DVB-S2 RollOff set to:NotSet
2008-08-03 11:37:17.869125 [5]: Twinhan DVB-S2 fec set to:Rate7_8
2008-08-03 11:37:17.869125 [5]: Channel modulation is set to ModNotSet
2008-08-03 11:37:17.869125 [5]: Channel FECRate is set to Rate7_8
2008-08-03 11:37:17.869125 [5]: Twinhan: SetLnb diseqc port:0 22khz:1 low:9750 hi:10600 switch:11700 power:True
2008-08-03 11:37:17.869125 [5]: Twinhan: SetLNB ok 0x0
2008-08-03 11:37:18.181625 [5]: TwinHan DiSEqC cmd:4 0 0 0 E0 10 38 FC 0 0 0 0 0 0 0 0 succeeded
2008-08-03 11:37:18.291000 [5]: dvbubmiting tunerequest Channel:TV4 subChannel:-1
2008-08-03 11:37:18.291000 [5]: dvb:Getting new subchannel
2008-08-03 11:37:18.291000 [5]: dvb:GetNewSubChannel:0 #0
2008-08-03 11:37:18.291000 [5]: dvbubmit tunerequest size:1 new:0
2008-08-03 11:37:18.291000 [5]: subch:0 OnBeforeTune
2008-08-03 11:37:18.306625 [5]: dvbubmit tunerequest calling put_TuneRequest
2008-08-03 11:37:18.556625 [5]: dvbubmit tunerequest done calling put_TuneRequest
2008-08-03 11:37:18.556625 [5]: subch:0 OnAfterTune
2008-08-03 11:37:18.556625 [5]: subch:0 OnGraphStart
2008-08-03 11:37:18.556625 [5]: subch0:RunGraph
2008-08-03 11:37:18.556625 [5]: dvb: RunGraph
2008-08-03 11:37:19.103500 [5]: subch:0 OnGraphStart
2008-08-03 11:37:19.119125 [5]: subch:0 RunGraph: already running
2008-08-03 11:37:19.119125 [5]: subch:0 SetupPmtGrabberid 100 sid:642
2008-08-03 11:37:19.119125 [5]: subch:0 set pmt grabber pmt:100 sid:642
2008-08-03 11:37:19.119125 [5]: subch:0 wait for pmt 100
2008-08-03 11:37:19.134750 [5]: subch:0 wait for pmt 100
2008-08-03 11:37:19.166000 [5]: subch:0 wait for pmt 100
2008-08-03 11:37:19.181625 [5]: subch:0 wait for pmt 100
2008-08-03 11:37:19.212875 [5]: subch:0 wait for pmt 100
2008-08-03 11:37:19.353500 [12]: subch:0 OnPMTReceived() True
2008-08-03 11:37:19.353500 [12]: subch:0 SendPmt:642 642 FFFFFFFF 8
2008-08-03 11:37:19.353500 [12]: Decode pmt
2008-08-03 11:37:19.353500 [12]: descr1 len:6 9 4 b 0 e0 40
2008-08-03 11:37:19.353500 [12]: Set descriptor data with length 6
2008-08-03 11:37:19.353500 [12]: Set descriptor data with length 7
2008-08-03 11:37:19.353500 [12]: Set descriptor data with length 3
2008-08-03 11:37:19.353500 [12]: subch:0 SendPMT version:8 len:114 1602
2008-08-03 11:37:19.353500 [12]: Decode pmt
2008-08-03 11:37:19.353500 [12]: descr1 len:6 9 4 b 0 e0 40
2008-08-03 11:37:19.353500 [12]: Set descriptor data with length 6
2008-08-03 11:37:19.369125 [12]: Set descriptor data with length 7
2008-08-03 11:37:19.369125 [12]: Set descriptor data with length 3
2008-08-03 11:37:19.369125 [12]: Twinhan: Send PMT camefault len:23 video:0x200 audio:0x280
2008-08-03 11:37:19.369125 [12]: capmt:3 6 42 D1 0 7 1 9 4 B 0 E0 40 2 E2 0 0 0 4 E2 80 0 0
2008-08-03 11:37:19.369125 [5]: subch:0 wait for pmt 100
2008-08-03 11:37:19.384750 [5]: subch:0 wait for pmt 100
2008-08-03 11:37:19.416000 [5]: subch:0 wait for pmt 100
2008-08-03 11:37:19.431625 [5]: subch:0 wait for pmt 100
2008-08-03 11:37:19.447250 [5]: subch:0 wait for pmt 100
2008-08-03 11:37:20.259750 [12]: Twinhan: CAM failed 0x8007001F
2008-08-03 11:37:20.259750 [12]: subch:0 cam flags:True
2008-08-03 11:37:20.259750 [12]: subch:0 SetMpegPidMapping
2008-08-03 11:37:20.275375 [12]: subch:0 pid:0 pcr
2008-08-03 11:37:20.275375 [12]: subch:0 pid:100 pmt
2008-08-03 11:37:20.275375 [12]: subch:0 pid:200 video type:MPEG-2
2008-08-03 11:37:20.275375 [12]: subch:0 map pid:200 video type:MPEG-2
2008-08-03 11:37:20.275375 [12]: subch:0 pid:280 audio lang:swe type:MPEG-2
2008-08-03 11:37:20.275375 [12]: subch:0 map pid:280 audio lang:swe type:MPEG-2
2008-08-03 11:37:20.275375 [12]: subch:0 pid:240 teletext type:6
2008-08-03 11:37:20.275375 [12]: subch:0 map pid:240 teletext type:6
2008-08-03 11:37:20.275375 [12]: subch:0 pid:8FB type:B
2008-08-03 11:37:20.275375 [12]: subch:0 pid:350 type:C0
2008-08-03 11:37:20.291000 [12]: subch:0 pid:250 type:6
2008-08-03 11:37:20.291000 [12]: subch:0 stop tif
2008-08-03 11:37:20.291000 [5]: card: tuned user: neptunus subchannel: 0
2008-08-03 11:37:20.291000 [5]: user:neptunus add
2008-08-03 11:37:22.947250 [5]: card: Tuner locked: False
2008-08-03 11:37:22.947250 [5]: **************************************************
2008-08-03 11:37:22.947250 [5]: ***** SIGNAL LEVEL: 0, SIGNAL QUALITY: 0 *****
2008-08-03 11:37:22.947250 [5]: **************************************************
2008-08-03 11:37:22.947250 [5]: card2:neptunus 1 0
2008-08-03 11:37:22.947250 [5]: Controller: neptunus 1 0
2008-08-03 11:37:22.978500 [5]: control2:neptunus 1 0
2008-08-03 11:37:22.994125 [5]: Controller: delete timeshift files D:\tvserver\timeshiftbuffer\live1-0.ts
2008-08-03 11:37:23.009750 [5]: card: StartTimeShifting 1 D:\tvserver\timeshiftbuffer\live1-0.ts
2008-08-03 11:37:23.009750 [5]: card: WaitForUnScrambledSignal
2008-08-03 11:37:23.025375 [5]: card: scrambled, sleep 100
2008-08-03 11:37:23.119125 [5]: card: scrambled, sleep 100
2008-08-03 11:37:23.228500 [5]: card: scrambled, sleep 100
2008-08-03 11:37:23.322250 [5]: card: scrambled, sleep 100
2008-08-03 11:37:23.431625 [5]: card: scrambled, sleep 100
2008-08-03 11:37:28.072250 [5]: card: return scrambled
2008-08-03 11:37:28.072250 [5]: card: channel is scrambled
2008-08-03 11:37:28.087875 [5]: card: remove user:neptunus sub:0
2008-08-03 11:37:28.087875 [5]: user:neptunus remove
2008-08-03 11:37:28.087875 [5]: card: free subchannel sub:0
2008-08-03 11:37:28.087875 [5]: tvcard:FreeSubChannel:1 #0
2008-08-03 11:37:28.087875 [5]: analog subch:0 Decompose()
2008-08-03 11:37:28.103500 [5]: tvcard:FreeAllSubChannels:
2008-08-03 11:37:28.103500 [5]: dvbtopGraph
2008-08-03 11:37:28.103500 [5]: tvcard:FreeAllSubChannels: