MEdiaportal+Mdapi plus+diseqc switch
MDAPI_Plus is a DirectShow filter, which can descramble television
Brought to you by:
alexplusplus,
mdapiplus
Hi! I have a small problem and im not sure its related to mdapi plus but it might be. When changing channels between differnet satellites it stops to work and i have to restart tv server to get it working again. For example. only channel 6 is dvb2. All others are dvb1 in thsi example. Switching from 3 to 4 to 5 to 6 works fine, switching back to 5, 4, 3 also works but if i go to 12 or 8 or 9 i first get cant start timeshifting. If i go to 4 or 5 again i maybe get NO SIGNAL but channel 6 works when trying it again. Its like it gets stuck at dvb2 and only tvserver restart solves the problem. I thought it might be mdapi that get stuck...
LOG
[2016-01-28 19:06:10,158] [Log ] [27 ] [INFO ] - Controller: find free card for channel TV3 HD
[2016-01-28 19:06:10,158] [Log ] [27 ] [INFO ] - Controller: find card for channel TV3 HD
[2016-01-28 19:06:10,158] [Log ] [27 ] [INFO ] - Controller: got 1 tuning details for TV3 HD
[2016-01-28 19:06:10,158] [Log ] [27 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:10,158] [Log ] [27 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:06:10,174] [Log ] [27 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:06:10,174] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:06:10,174] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:06:10,174] [Log ] [27 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:06:10,174] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 24 msec
[2016-01-28 19:06:10,189] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:06:10,189] [Log ] [27 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:06:10,189] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 35 msec
[2016-01-28 19:06:10,189] [Log ] [27 ] [INFO ] - Controller: TimeShiftingWouldUseCard TV3 HD 3505
[2016-01-28 19:06:10,189] [Log ] [27 ] [INFO ] - Controller: find free card for channel TV3 HD
[2016-01-28 19:06:10,189] [Log ] [27 ] [INFO ] - Controller: find card for channel TV3 HD
[2016-01-28 19:06:10,205] [Log ] [27 ] [INFO ] - Controller: got 1 tuning details for TV3 HD
[2016-01-28 19:06:10,205] [Log ] [27 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:10,205] [Log ] [27 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:06:10,205] [Log ] [27 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:06:10,205] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:06:10,220] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:06:10,220] [Log ] [27 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:06:10,220] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 23 msec
[2016-01-28 19:06:10,220] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:06:10,220] [Log ] [27 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:06:10,220] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 34 msec
[2016-01-28 19:06:10,236] [Log ] [27 ] [DEBUG] - CiMenuSupported called cardid 4
[2016-01-28 19:06:10,236] [Log ] [27 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:06:10,236] [Log ] [27 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:06:10,236] [Log ] [27 ] [DEBUG] - CiMenuSupported card TBS 6982 DVBS/S2 Tuner B supported: False
[2016-01-28 19:06:10,236] [Log ] [27 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:06:10,236] [Log ] [27 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:06:10,252] [Log ] [27 ] [INFO ] - Controller: StartTimeShifting TV3 HD 3505
[2016-01-28 19:06:10,252] [Log ] [27 ] [INFO ] - Controller: epg stop
[2016-01-28 19:06:10,252] [Log ] [27 ] [INFO ] - Controller: find free card for channel TV3 HD
[2016-01-28 19:06:10,252] [Log ] [27 ] [INFO ] - Controller: find card for channel TV3 HD
[2016-01-28 19:06:10,252] [Log ] [27 ] [INFO ] - Controller: got 1 tuning details for TV3 HD
[2016-01-28 19:06:10,267] [Log ] [27 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:10,267] [Log ] [27 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:06:10,267] [Log ] [27 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:06:10,267] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:06:10,267] [Log ] [27 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:06:10,283] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 20 msec
[2016-01-28 19:06:10,283] [Log ] [27 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:06:10,283] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 28 msec
[2016-01-28 19:06:10,283] [Log ] [27 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=3, tuningdetails=DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:10,283] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:06:10,299] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:06:10,299] [Log ] [27 ] [INFO ] - Controller: try max 1 of 1 cards for timeshifting
[2016-01-28 19:06:10,299] [Log ] [27 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartZapChannel
[2016-01-28 19:06:10,299] [Log ] [27 ] [DEBUG] - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3505, ticket=3, tunestate=Tuning, stopstate=Idle
[2016-01-28 19:06:10,299] [Log ] [27 ] [INFO ] - card: CardTune 4 TV3 HD (S) Hometown:4:-1
[2016-01-28 19:06:10,314] [Log ] [27 ] [INFO ] - card: Tune on card 4 to subchannel TV3 HD (S)
[2016-01-28 19:06:10,314] [Log ] [27 ] [DEBUG] - card: user: Hometown:4:-1 tune DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:10,314] [Log ] [27 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2016-01-28 19:06:10,314] [Log ] [27 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:10,330] [Log ] [27 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:10,330] [Log ] [27 ] [INFO ] - dvb:GetNewSubChannel:0 #0
[2016-01-28 19:06:10,330] [Log ] [27 ] [INFO ] - TvDvbChannel ctor new subchIndex:0
[2016-01-28 19:06:10,330] [Log ] [27 ] [INFO ] - card: AddTuneEvent card: 4 / subch: 0
[2016-01-28 19:06:10,330] [Log ] [27 ] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2016-01-28 19:06:10,330] [Log ] [27 ] [INFO ] - dvbs:channel modulation is set to Mod8Psk
[2016-01-28 19:06:10,345] [Log ] [27 ] [INFO ] - dvbs:channel FECRate is set to Rate3_4
[2016-01-28 19:06:10,345] [Log ] [27 ] [DEBUG] - Turbosight: set tone state, burst = ToneBurst, 22 kHz = Off
[2016-01-28 19:06:10,345] [Log ] [27 ] [DEBUG] - Turbosight: burst result = success
[2016-01-28 19:06:10,345] [Log ] [27 ] [DEBUG] - Turbosight: 22 kHz result = success
[2016-01-28 19:06:10,361] [Log ] [27 ] [INFO ] - Turbosight: Set DVB-S2
[2016-01-28 19:06:10,470] [Log ] [27 ] [INFO ] - dvb:Submiting tunerequest Channel:TV3 HD (S) subChannel:0
[2016-01-28 19:06:10,470] [Log ] [27 ] [INFO ] - dvb:using existing subchannel:0
[2016-01-28 19:06:10,470] [Log ] [27 ] [INFO ] - dvb:Submit tunerequest size:1 new:0
[2016-01-28 19:06:10,470] [Log ] [27 ] [INFO ] - subch:0 OnBeforeTune
[2016-01-28 19:06:10,486] [Log ] [27 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest
[2016-01-28 19:06:10,486] [Log ] [27 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest
[2016-01-28 19:06:10,486] [Log ] [27 ] [INFO ] - subch:0 OnAfterTune
[2016-01-28 19:06:10,486] [Log ] [27 ] [INFO ] - RunGraph
[2016-01-28 19:06:10,486] [Log ] [27 ] [INFO ] - subch:0 OnGraphStart
[2016-01-28 19:06:10,502] [Log ] [27 ] [INFO ] - dvb: RunGraph
[2016-01-28 19:06:10,736] [Log ] [27 ] [INFO ] - dvb: LockInOnSignal ok
[2016-01-28 19:06:10,752] [Log ] [27 ] [INFO ] - subch:0 OnGraphStarted
[2016-01-28 19:06:10,752] [Log ] [27 ] [INFO ] - subch:0 SetupPmtGrabber:pid 18A sid:115E
[2016-01-28 19:06:10,752] [Log ] [27 ] [INFO ] - subch:0 set pmt grabber pmt:18A sid:115E
[2016-01-28 19:06:10,752] [Log ] [27 ] [INFO ] - subch:0 set ca grabber
[2016-01-28 19:06:10,752] [Log ] [27 ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2016-01-28 19:06:10,767] [Log ] [27 ] [DEBUG] - WaitForPMT: Waiting for PMT 18A
[2016-01-28 19:06:10,908] [Log ] [29 ] [INFO ] - subch:0 OnPMTReceived() pmt:18A ran:True dynamic:False
[2016-01-28 19:06:10,908] [Log ] [27 ] [DEBUG] - WaitForPMT: Found PMT after 0,140624 seconds.
[2016-01-28 19:06:11,158] [Log ] [29 ] [INFO ] - subch:OnCaReceived()
[2016-01-28 19:06:11,158] [Log ] [27 ] [INFO ] - subch:0 SendPmt:CA found after 0,2343752 seconds
[2016-01-28 19:06:11,158] [Log ] [27 ] [INFO ] - subch:0 SendPmt:115E 115E FFFFFFFF 1C
[2016-01-28 19:06:11,174] [Log ] [27 ] [INFO ] - Decode pmt
[2016-01-28 19:06:11,174] [Log ] [27 ] [INFO ] - descr1 len:6 9 4 b 0 fb 76
[2016-01-28 19:06:11,174] [Log ] [27 ] [INFO ] - Set descriptor data with length 7
[2016-01-28 19:06:11,174] [Log ] [27 ] [INFO ] - Set descriptor data with length 6
[2016-01-28 19:06:11,189] [Log ] [27 ] [INFO ] - subch:0 SendPMT version:28 len:53 4446
[2016-01-28 19:06:11,189] [Log ] [27 ] [DEBUG] - Turbosight: send PMT to CAM, list action = Only, command = Descrambling
[2016-01-28 19:06:11,189] [Log ] [27 ] [DEBUG] - Turbosight: CAM not available
[2016-01-28 19:06:11,189] [Log ] [27 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:06:11,205] [Log ] [27 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:06:11,205] [Log ] [27 ] [INFO ] - subch:0 cam flags:False
[2016-01-28 19:06:11,205] [Log ] [27 ] [INFO ] - subch:0 SetMpegPidMapping
[2016-01-28 19:06:11,205] [Log ] [27 ] [INFO ] - subch:0 pid:819 pcr
[2016-01-28 19:06:11,205] [Log ] [27 ] [INFO ] - subch:0 pid:18A pmt
[2016-01-28 19:06:11,205] [Log ] [27 ] [INFO ] - subch:0 pid:18BD teletext type:6
[2016-01-28 19:06:11,220] [Log ] [27 ] [INFO ] - subch:0 map pid:18BD teletext type:6
[2016-01-28 19:06:11,220] [Log ] [27 ] [INFO ] - subch:0 pid:819 video type:H.264
[2016-01-28 19:06:11,220] [Log ] [27 ] [INFO ] - subch:0 map pid:819 video type:H.264
[2016-01-28 19:06:11,220] [Log ] [27 ] [INFO ] - subch:0 pid:D14 audio lang:swe type:AC3
[2016-01-28 19:06:11,220] [Log ] [27 ] [INFO ] - subch:0 map pid:D14 audio lang:swe type:AC3
[2016-01-28 19:06:11,220] [Log ] [27 ] [INFO ] - ecm len:6 9 4 B 0 FB 76
[2016-01-28 19:06:11,236] [Log ] [27 ] [INFO ] - emm len:6 9 4 B 0 E0 30
[2016-01-28 19:06:11,236] [Log ] [27 ] [INFO ] - Number of HWPIDS that needs to be sent to tuner :11
[2016-01-28 19:06:11,236] [Log ] [27 ] [INFO ] - mdplug: SetChannel nr of currently decoding channels 0.
[2016-01-28 19:06:11,236] [Log ] [27 ] [INFO ] - mdplug: SetChannel starting decryption on channel 'TV3 HD (S)' using plugin slot 1 of 1 avail.
[2016-01-28 19:06:11,236] [Log ] [27 ] [INFO ] - emm len:6 9 4 B 0 E0 30
[2016-01-28 19:06:11,252] [Log ] [27 ] [INFO ] - EMM #0 CA:0xB00 EMM:0x30 ID:0x0
[2016-01-28 19:06:11,252] [Log ] [27 ] [INFO ] - ecm len:6 9 4 B 0 FB 76
[2016-01-28 19:06:11,252] [Log ] [27 ] [INFO ] - ECM #0 CA:0xB00 ECM:0x1B76 ID:0x0
[2016-01-28 19:06:11,252] [Log ] [27 ] [INFO ] - mdplug: tp_id:24(0x18) sid:4446(0x115E) pmt_id:394(0x18A)
[2016-01-28 19:06:11,252] [Log ] [27 ] [INFO ] - mdplug: #0 CA_typ:2816(0xB00) ECM:7030(0x1B76) EMM:0x30 provider:0(0x0)
[2016-01-28 19:06:11,314] [Log ] [27 ] [INFO ] - mdplug: Send channel change to MDAPI filter Ca_Id:0 CA_Nr:1 ECM_PID:7030(0x1B76)
[2016-01-28 19:06:11,314] [Log ] [27 ] [INFO ] - subch:0 stop tif
[2016-01-28 19:06:11,314] [Log ] [27 ] [DEBUG] - WaitForPmt: PMT handling took 0,3906252 seconds.
[2016-01-28 19:06:11,330] [Log ] [27 ] [DEBUG] - card: Tuner locked: True
[2016-01-28 19:06:11,330] [Log ] [27 ] [INFO ] - klzzwxh:11437klzzwxh:11436klzzwxh:11435klzzwxh:11434klzzwxh:11433klzzwxh:11432klzzwxh:11431
klzzwxh:10792 klzzwxh:10793 klzzwxh:10794 klzzwxh:10795 - ** SIGNAL LEVEL: 94, SIGNAL QUALITY: 82
klzzwxh:10807 klzzwxh:10808 klzzwxh:10809 klzzwxh:10810 - klzzwxh:11430klzzwxh:11429klzzwxh:11428klzzwxh:11427klzzwxh:11426klzzwxh:11425klzzwxh:11424
klzzwxh:10815 klzzwxh:10816 klzzwxh:10817 klzzwxh:10818 - card: tuned user: Hometown subchannel: 0
klzzwxh:10819 klzzwxh:10820 klzzwxh:10821 klzzwxh:10822 - user:Hometown add
klzzwxh:10823 klzzwxh:10824 klzzwxh:10825 klzzwxh:10826 - card2:Hometown 4 0
klzzwxh:10827 klzzwxh:10828 klzzwxh:10829 klzzwxh:10830 - Controller: delete timeshift files C:klzzwxh:10831rogramDataklzzwxh:10832eam MediaPortalklzzwxh:10833ediaPortal TV Serverklzzwxh:10834imeshiftbufferklzzwxh:10835ive4-0.ts
klzzwxh:10836 klzzwxh:10837 klzzwxh:10838 klzzwxh:10839 - Timeshifting started - Recordings=0 TimeShiftingActive=True
klzzwxh:10840 klzzwxh:10841 klzzwxh:10842 klzzwxh:10843 - TVServerKodi: OnTvServerEvent: StartTimeShifting
klzzwxh:10844 klzzwxh:10845 klzzwxh:10846 klzzwxh:10847 - Controller: epg stop
klzzwxh:10848 klzzwxh:10849 klzzwxh:10850 klzzwxh:10851 - card: StartTimeShifting 4 C:klzzwxh:10852rogramDataklzzwxh:10853eam MediaPortalklzzwxh:10854ediaPortal TV Serverklzzwxh:10855imeshiftbufferklzzwxh:10856ive4-0.ts
klzzwxh:10857 klzzwxh:10858 klzzwxh:10859 klzzwxh:10860 - card: CAM enabled : True
klzzwxh:10861 klzzwxh:10862 klzzwxh:10863 klzzwxh:10864 - subch:0 SetTimeShiftFileName:C:klzzwxh:10865rogramDataklzzwxh:10866eam MediaPortalklzzwxh:10867ediaPortal TV Serverklzzwxh:10868imeshiftbufferklzzwxh:10869ive4-0.ts
klzzwxh:10870 klzzwxh:10871 klzzwxh:10872 klzzwxh:10873 - Set video / audio observer
klzzwxh:10874 klzzwxh:10875 klzzwxh:10876 klzzwxh:10877 - subch:0 SetTimeShiftFileName fill in pids
klzzwxh:10878 klzzwxh:10879 klzzwxh:10880 klzzwxh:10881 - subch:0-0 tswriter StartTimeshifting...
klzzwxh:10882 klzzwxh:10883 klzzwxh:10884 klzzwxh:10885 - card: WaitForFile - waiting _eventAudio & _eventVideo
klzzwxh:10886 klzzwxh:10887 klzzwxh:10888 klzzwxh:10889 - PID seen - type = Video
klzzwxh:10890 klzzwxh:10891 klzzwxh:10892 klzzwxh:10893 - audioVideoEventHandler Video
klzzwxh:10894 klzzwxh:10895 klzzwxh:10896 klzzwxh:10897 - PID seen - type = Audio
klzzwxh:10898 klzzwxh:10899 klzzwxh:10900 klzzwxh:10901 - audioVideoEventHandler Audio
klzzwxh:10902 klzzwxh:10903 klzzwxh:10904 klzzwxh:10905 - card: WaitForFile - video and audio are seen after 2,3437558 seconds
klzzwxh:10906 klzzwxh:10907 klzzwxh:10908 klzzwxh:10909 - user:Hometown card:4 sub:0 add stream:C:klzzwxh:10910rogramDataklzzwxh:10911eam MediaPortalklzzwxh:10912ediaPortal TV Serverklzzwxh:10913imeshiftbufferklzzwxh:10914ive4-0.ts.tsbuffer
klzzwxh:10915 klzzwxh:10916 klzzwxh:10917 klzzwxh:10918 - RTSP: add stream stream4.0 file:C:klzzwxh:10919rogramDataklzzwxh:10920eam MediaPortalklzzwxh:10921ediaPortal TV Serverklzzwxh:10922imeshiftbufferklzzwxh:10923ive4-0.ts.tsbuffer
klzzwxh:10924 klzzwxh:10925 klzzwxh:10926 klzzwxh:10927 - Controller: StartTimeShifting started on card:4 to C:klzzwxh:10928rogramDataklzzwxh:10929eam MediaPortalklzzwxh:10930ediaPortal TV Serverklzzwxh:10931imeshiftbufferklzzwxh:10932ive4-0.ts.tsbuffer
klzzwxh:10933 klzzwxh:10934 klzzwxh:10935 klzzwxh:10936 - CardReservation.RemoveTuneTicket: removed reservation with id=3, tuningdetails=DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
klzzwxh:10937 klzzwxh:10938 klzzwxh:10939 klzzwxh:10940 - card: SignalTuneEvent card: 4 / subch: 0
klzzwxh:10941 klzzwxh:10942 klzzwxh:10943 klzzwxh:10944 - Controller: Hometown 4 0
klzzwxh:10945 klzzwxh:10946 klzzwxh:10947 klzzwxh:10948 - TVServerKodi: OnTvServerEvent: EndZapChannel
klzzwxh:10949 klzzwxh:10950 klzzwxh:10951 klzzwxh:10952 - control2:Hometown 4 0
klzzwxh:10953 klzzwxh:10954 klzzwxh:10955 klzzwxh:10956 - Controller: DoSetChannelStates for 1033 channels
klzzwxh:10957 klzzwxh:10958 klzzwxh:10959 klzzwxh:10960 - CiMenuSupported called cardid 4
klzzwxh:10961 klzzwxh:10962 klzzwxh:10963 klzzwxh:10964 - Turbosight: is CAM ready
klzzwxh:10965 klzzwxh:10966 klzzwxh:10967 klzzwxh:10968 - ChannelStates.GetAllTimeshiftingAndRecordingChannels took 0 msec
klzzwxh:10969 klzzwxh:10970 klzzwxh:10971 klzzwxh:10972 - Turbosight: interface not opened
klzzwxh:10973 klzzwxh:10974 klzzwxh:10975 klzzwxh:10976 - CiMenuSupported card TBS 6982 DVBS/S2 Tuner B supported: False
klzzwxh:10977 klzzwxh:10978 klzzwxh:10979 klzzwxh:10980 - Turbosight: is CAM ready
klzzwxh:10981 klzzwxh:10982 klzzwxh:10983 klzzwxh:10984 - Turbosight: interface not opened
klzzwxh:10985 klzzwxh:10986 klzzwxh:10987 klzzwxh:10988 - ChannelStates.DoSetChannelStates took 2171 msec
klzzwxh:10989 klzzwxh:10990 klzzwxh:10991 klzzwxh:10992 - Controller: TimeShiftingWouldUseCard Sjuan 3135
klzzwxh:10993 klzzwxh:10994 klzzwxh:10995 klzzwxh:10996 - Controller: find free card for channel Sjuan
klzzwxh:10997 klzzwxh:10998 klzzwxh:10999 klzzwxh:11000 - Controller: find card for channel Sjuan
klzzwxh:11001 klzzwxh:11002 klzzwxh:11003 klzzwxh:11004 - Controller: got 1 tuning details for Sjuan
klzzwxh:11005 klzzwxh:11006 klzzwxh:11007 klzzwxh:11008 - Controller: channel #1 DVBS:tv:Telenor Sjuan Freq:11216000 ONID:70 TSID:27 SID:2108 PMT:0xAC FTA:False LCN:10000 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:SimpleA band:Universal Pilot:NotSet RollOff:NotSet
klzzwxh:11009 klzzwxh:11010 klzzwxh:11011 klzzwxh:11012 - Controller: card:1 type:RadioWebStream is disabled
klzzwxh:11013 klzzwxh:11014 klzzwxh:11015 klzzwxh:11016 - Controller: card:5 type:DvbS is disabled
klzzwxh:11017 klzzwxh:11018 klzzwxh:11019 klzzwxh:11020 - Controller: card:4 type:DvbS can tune to channel
klzzwxh:11021 klzzwxh:11022 klzzwxh:11023 klzzwxh:11024 - Controller: card:4 type:DvbS users: 0
klzzwxh:11025 klzzwxh:11026 klzzwxh:11027 klzzwxh:11028 - Controller: found 1 card(s) for channel
klzzwxh:11029 klzzwxh:11030 klzzwxh:11031 klzzwxh:11032 - AdvancedCardAllocation.GetAvailableCardsForChannel took 41 msec
klzzwxh:11033 klzzwxh:11034 klzzwxh:11035 klzzwxh:11036 - Controller: card:4 type:DvbS is available
klzzwxh:11037 klzzwxh:11038 klzzwxh:11039 klzzwxh:11040 - Controller: found 1 free card(s)
klzzwxh:11041 klzzwxh:11042 klzzwxh:11043 klzzwxh:11044 - AdvancedCardAllocation.GetFreeCardsForChannel took 54 msec
klzzwxh:11045 klzzwxh:11046 klzzwxh:11047 klzzwxh:11048 - Controller: StartTimeShifting Sjuan 3135
klzzwxh:11049 klzzwxh:11050 klzzwxh:11051 klzzwxh:11052 - Controller: epg stop
klzzwxh:11053 klzzwxh:11054 klzzwxh:11055 klzzwxh:11056 - Controller: find free card for channel Sjuan
klzzwxh:11057 klzzwxh:11058 klzzwxh:11059 klzzwxh:11060 - Controller: find card for channel Sjuan
klzzwxh:11061 klzzwxh:11062 klzzwxh:11063 klzzwxh:11064 - Controller: got 1 tuning details for Sjuan
klzzwxh:11065 klzzwxh:11066 klzzwxh:11067 klzzwxh:11068 - Controller: channel #1 DVBS:tv:Telenor Sjuan Freq:11216000 ONID:70 TSID:27 SID:2108 PMT:0xAC FTA:False LCN:10000 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:SimpleA band:Universal Pilot:NotSet RollOff:NotSet
klzzwxh:11069 klzzwxh:11070 klzzwxh:11071 klzzwxh:11072 - Controller: card:1 type:RadioWebStream is disabled
klzzwxh:11073 klzzwxh:11074 klzzwxh:11075 klzzwxh:11076 - Controller: card:5 type:DvbS is disabled
klzzwxh:11077 klzzwxh:11078 klzzwxh:11079 klzzwxh:11080 - Controller: card:4 type:DvbS can tune to channel
klzzwxh:11081 klzzwxh:11082 klzzwxh:11083 klzzwxh:11084 - Controller: found 1 card(s) for channel
klzzwxh:11085 klzzwxh:11086 klzzwxh:11087 klzzwxh:11088 - AdvancedCardAllocation.GetAvailableCardsForChannel took 22 msec
klzzwxh:11089 klzzwxh:11090 klzzwxh:11091 klzzwxh:11092 - Controller: found 1 free card(s)
klzzwxh:11093 klzzwxh:11094 klzzwxh:11095 klzzwxh:11096 - AdvancedCardAllocation.GetFreeCardsForChannel took 31 msec
klzzwxh:11097 klzzwxh:11098 klzzwxh:11099 klzzwxh:11100 - CardReservationBase.RequestCardTuneReservation: placed reservation with id=4, tuningdetails=DVBS:tv:Telenor Sjuan Freq:11216000 ONID:70 TSID:27 SID:2108 PMT:0xAC FTA:False LCN:10000 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:SimpleA band:Universal Pilot:NotSet RollOff:NotSet
klzzwxh:11101 klzzwxh:11102 klzzwxh:11103 klzzwxh:11104 - Controller: card:4 type:DvbS users: 0
klzzwxh:11105 klzzwxh:11106 klzzwxh:11107 klzzwxh:11108 - Controller: card:4 type:DvbS is available
klzzwxh:11109 klzzwxh:11110 klzzwxh:11111 klzzwxh:11112 - Controller: try max 1 of 1 cards for timeshifting
klzzwxh:11113 klzzwxh:11114 klzzwxh:11115 klzzwxh:11116 - TVServerKodi: OnTvServerEvent: StartZapChannel
klzzwxh:11117 klzzwxh:11118 klzzwxh:11119 klzzwxh:11120 - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3135, ticket=4, tunestate=Tuning, stopstate=Idle
klzzwxh:11121 klzzwxh:11122 klzzwxh:11123 klzzwxh:11124 - card: CardTune 4 Sjuan Hometown:4:-1
klzzwxh:11125 klzzwxh:11126 klzzwxh:11127 klzzwxh:11128 - card: Tune on card 4 to subchannel Sjuan
klzzwxh:11129 klzzwxh:11130 klzzwxh:11131 klzzwxh:11132 - card: user: Hometown:4:0 tune DVBS:tv:Telenor Sjuan Freq:11216000 ONID:70 TSID:27 SID:2108 PMT:0xAC FTA:False LCN:10000 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:SimpleA band:Universal Pilot:NotSet RollOff:NotSet
klzzwxh:11133 klzzwxh:11134 klzzwxh:11135 klzzwxh:11136 - card: to different transponder
klzzwxh:11137 klzzwxh:11138 klzzwxh:11139 klzzwxh:11140 - FreeSubChannel MD: freeing sub channel : 0
klzzwxh:11141 klzzwxh:11142 klzzwxh:11143 klzzwxh:11144 - mdplug: FreeChannel TV3 HD (S)
klzzwxh:11145 klzzwxh:11146 klzzwxh:11147 klzzwxh:11148 - mdplug: usage counter for channel 'TV3 HD (S)' is zero
klzzwxh:11149 klzzwxh:11150 klzzwxh:11151 klzzwxh:11152 - tvcard:FreeSubChannel: subchannels count 1 subch#0
klzzwxh:11153 klzzwxh:11154 klzzwxh:11155 klzzwxh:11156 - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
klzzwxh:11157 klzzwxh:11158 klzzwxh:11159 klzzwxh:11160 - TimeShifter.OnBeforeTune: resetting audio/video events
klzzwxh:11161 klzzwxh:11162 klzzwxh:11163 klzzwxh:11164 - dvbs: Tune:DVBS:tv:Telenor Sjuan Freq:11216000 ONID:70 TSID:27 SID:2108 PMT:0xAC FTA:False LCN:10000 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:SimpleA band:Universal Pilot:NotSet RollOff:NotSet
klzzwxh:11165 klzzwxh:11166 klzzwxh:11167 klzzwxh:11168 - dvbs: Tune:DVBS:tv:Telenor Sjuan Freq:11216000 ONID:70 TSID:27 SID:2108 PMT:0xAC FTA:False LCN:10000 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:SimpleA band:Universal Pilot:NotSet RollOff:NotSet
klzzwxh:11169 klzzwxh:11170 klzzwxh:11171 klzzwxh:11172 - LNB low:9750 hi:10600 switch:11700
klzzwxh:11173 klzzwxh:11174 klzzwxh:11175 klzzwxh:11176 - dvbs:channel modulation is set to ModNotSet
klzzwxh:11177 klzzwxh:11178 klzzwxh:11179 klzzwxh:11180 - dvbs:channel FECRate is set to Rate7_8
klzzwxh:11181 klzzwxh:11182 klzzwxh:11183 klzzwxh:11184 - Turbosight: set tone state, burst = ToneBurst, 22 kHz = Off
klzzwxh:11185 klzzwxh:11186 klzzwxh:11187 klzzwxh:11188 - Turbosight: burst result = success
klzzwxh:11189 klzzwxh:11190 klzzwxh:11191 klzzwxh:11192 - Turbosight: 22 kHz result = success
klzzwxh:11193 klzzwxh:11194 klzzwxh:11195 klzzwxh:11196 - Turbosight: Set DVB-S2
klzzwxh:11197 klzzwxh:11198 klzzwxh:11199 klzzwxh:11200 - dvb:Submiting tunerequest Channel:Sjuan subChannel:0
klzzwxh:11201 klzzwxh:11202 klzzwxh:11203 klzzwxh:11204 - dvb:using existing subchannel:0
klzzwxh:11205 klzzwxh:11206 klzzwxh:11207 klzzwxh:11208 - dvb:Submit tunerequest size:1 new:0
klzzwxh:11209 klzzwxh:11210 klzzwxh:11211 klzzwxh:11212 - subch:0 OnBeforeTune
klzzwxh:11213 klzzwxh:11214 klzzwxh:11215 klzzwxh:11216 - dvb:Submit tunerequest calling put_TuneRequest
klzzwxh:11217 klzzwxh:11218 klzzwxh:11219 klzzwxh:11220 - dvb:Submit tunerequest done calling put_TuneRequest
klzzwxh:11221 klzzwxh:11222 klzzwxh:11223 klzzwxh:11224 - subch:0 OnAfterTune
klzzwxh:11225 klzzwxh:11226 klzzwxh:11227 klzzwxh:11228 - RunGraph
klzzwxh:11229 klzzwxh:11230 klzzwxh:11231 klzzwxh:11232 - dvb: LockInOnSignal ok
klzzwxh:11233 klzzwxh:11234 klzzwxh:11235 klzzwxh:11236 - subch:0 OnGraphStart
klzzwxh:11237 klzzwxh:11238 klzzwxh:11239 klzzwxh:11240 - subch:0 Graph already running - WaitForPMT
klzzwxh:11241 klzzwxh:11242 klzzwxh:11243 klzzwxh:11244 - subch:0 SetupPmtGrabber:pid AC sid:83C
klzzwxh:11245 klzzwxh:11246 klzzwxh:11247 klzzwxh:11248 - subch:0 set pmt grabber pmt:AC sid:83C
klzzwxh:11249 klzzwxh:11250 klzzwxh:11251 klzzwxh:11252 - subch:0 set ca grabber
klzzwxh:11253 klzzwxh:11254 klzzwxh:11255 klzzwxh:11256 - TimeShifter.OnAfterTune: resetting audio/video time
klzzwxh:11257 klzzwxh:11258 klzzwxh:11259 klzzwxh:11260 - WaitForPMT: Waiting for PMT AC
klzzwxh:11261 klzzwxh:11262 klzzwxh:11263 klzzwxh:11264 - subch:0 OnPMTReceived() pmt:AC ran:True dynamic:False
klzzwxh:11265 klzzwxh:11266 klzzwxh:11267 klzzwxh:11268 - WaitForPMT: Found PMT after 0,1130067 seconds.
klzzwxh:11269 klzzwxh:11270 klzzwxh:11271 klzzwxh:11272 - subch:0 SendPmt:CA found after 0 seconds
klzzwxh:11273 klzzwxh:11274 klzzwxh:11275 klzzwxh:11276 - subch:0 SendPmt:83C 83C FFFFFFFF 2
klzzwxh:11277 klzzwxh:11278 klzzwxh:11279 klzzwxh:11280 - Decode pmt
klzzwxh:11281 klzzwxh:11282 klzzwxh:11283 klzzwxh:11284 - descr1 len:6 9 4 b 0 fc 26
klzzwxh:11285 klzzwxh:11286 klzzwxh:11287 klzzwxh:11288 - Set descriptor data with length 6
klzzwxh:11289 klzzwxh:11290 klzzwxh:11291 klzzwxh:11292 - Set descriptor data with length 7
klzzwxh:11293 klzzwxh:11294 klzzwxh:11295 klzzwxh:11296 - subch:0 SendPMT version:2 len:50 2108
klzzwxh:11297 klzzwxh:11298 klzzwxh:11299 klzzwxh:11300 - Turbosight: send PMT to CAM, list action = Only, command = Descrambling
klzzwxh:11301 klzzwxh:11302 klzzwxh:11303 klzzwxh:11304 - Turbosight: CAM not available
klzzwxh:11305 klzzwxh:11306 klzzwxh:11307 klzzwxh:11308 - Turbosight: is CAM ready
klzzwxh:11309 klzzwxh:11310 klzzwxh:11311 klzzwxh:11312 - Turbosight: interface not opened
klzzwxh:11313 klzzwxh:11314 klzzwxh:11315 klzzwxh:11316 - subch:0 cam flags:False
klzzwxh:11317 klzzwxh:11318 klzzwxh:11319 klzzwxh:11320 - subch:0 SetMpegPidMapping
klzzwxh:11321 klzzwxh:11322 klzzwxh:11323 klzzwxh:11324 - subch:0 pid:479 pcr
klzzwxh:11325 klzzwxh:11326 klzzwxh:11327 klzzwxh:11328 - subch:0 pid:AC pmt
klzzwxh:11329 klzzwxh:11330 klzzwxh:11331 klzzwxh:11332 - subch:0 pid:479 video type:MPEG-2
klzzwxh:11333 klzzwxh:11334 klzzwxh:11335 klzzwxh:11336 - subch:0 map pid:479 video type:MPEG-2
klzzwxh:11337 klzzwxh:11338 klzzwxh:11339 klzzwxh:11340 - subch:0 pid:C44 audio lang:swe type:MPEG-2
klzzwxh:11341 klzzwxh:11342 klzzwxh:11343 klzzwxh:11344 - subch:0 map pid:C44 audio lang:swe type:MPEG-2
klzzwxh:11345 klzzwxh:11346 klzzwxh:11347 klzzwxh:11348 - subch:0 pid:179F teletext type:6
klzzwxh:11349 klzzwxh:11350 klzzwxh:11351 klzzwxh:11352 - subch:0 map pid:179F teletext type:6
klzzwxh:11353 klzzwxh:11354 klzzwxh:11355 klzzwxh:11356 - ecm len:6 9 4 B 0 FC 26
klzzwxh:11357 klzzwxh:11358 klzzwxh:11359 klzzwxh:11360 - emm len:6 9 4 B 0 E0 30
klzzwxh:11361 klzzwxh:11362 klzzwxh:11363 klzzwxh:11364 - Number of HWPIDS that needs to be sent to tuner :11
klzzwxh:11365 klzzwxh:11366 klzzwxh:11367 klzzwxh:11368 - mdplug: SetChannel nr of currently decoding channels 0.
klzzwxh:11369 klzzwxh:11370 klzzwxh:11371 klzzwxh:11372 - mdplug: SetChannel starting decryption on channel 'Sjuan' using plugin slot 1 of 1 avail.
klzzwxh:11373 klzzwxh:11374 klzzwxh:11375 klzzwxh:11376 - emm len:6 9 4 B 0 E0 30
klzzwxh:11377 klzzwxh:11378 klzzwxh:11379 klzzwxh:11380 - EMM #0 CA:0xB00 EMM:0x30 ID:0x0
klzzwxh:11381 klzzwxh:11382 klzzwxh:11383 klzzwxh:11384 - ecm len:6 9 4 B 0 FC 26
klzzwxh:11385 klzzwxh:11386 klzzwxh:11387 klzzwxh:11388 - ECM #0 CA:0xB00 ECM:0x1C26 ID:0x0
klzzwxh:11389 klzzwxh:11390 klzzwxh:11391 klzzwxh:11392 - mdplug: tp_id:27(0x1B) sid:2108(0x83C) pmt_id:172(0xAC)
klzzwxh:11393 klzzwxh:11394 klzzwxh:11395 klzzwxh:11396 - mdplug: #0 CA_typ:2816(0xB00) ECM:7206(0x1C26) EMM:0x30 provider:0(0x0)
klzzwxh:11397 klzzwxh:11398 klzzwxh:11399 klzzwxh:11400 - mdplug: Send channel change to MDAPI filter Ca_Id:0 CA_Nr:1 ECM_PID:7206(0x1C26)
klzzwxh:11401 klzzwxh:11402 klzzwxh:11403 klzzwxh:11404 - subch:0 stop tif
klzzwxh:11405 klzzwxh:11406 klzzwxh:11407 klzzwxh:11408 - WaitForPmt: PMT handling took 0,1050063 seconds.
klzzwxh:11409 klzzwxh:11410 klzzwxh:11411 klzzwxh:11412 - card: Tuner locked: True
klzzwxh:11413 klzzwxh:11414 klzzwxh:11415 klzzwxh:11416 - klzzwxh:11423klzzwxh:11422klzzwxh:11421klzzwxh:11420klzzwxh:11419klzzwxh:11418klzzwxh:11417
klzzwxh:10811 klzzwxh:10812 klzzwxh:10813 klzzwxh:10814 - ** SIGNAL LEVEL: 94, SIGNAL QUALITY: 82
klzzwxh:10796 klzzwxh:10797 klzzwxh:10798 klzzwxh:10799 - klzzwxh:10806klzzwxh:10805klzzwxh:10804klzzwxh:10803klzzwxh:10802klzzwxh:10801klzzwxh:10800
[2016-01-28 19:06:25,249] [Log ] [27 ] [DEBUG] - card: tuned user: Hometown subchannel: 0
[2016-01-28 19:06:25,252] [Log ] [27 ] [INFO ] - user:Hometown add
[2016-01-28 19:06:25,256] [Log ] [27 ] [INFO ] - card2:Hometown 4 0
[2016-01-28 19:06:25,259] [Log ] [27 ] [DEBUG] - Timeshifting started - Recordings=0 TimeShiftingActive=True
[2016-01-28 19:06:25,262] [Log ] [27 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartTimeShifting
[2016-01-28 19:06:25,265] [Log ] [27 ] [INFO ] - Controller: epg stop
[2016-01-28 19:06:25,268] [Log ] [27 ] [INFO ] - card: StartTimeShifting 4 C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:06:25,271] [Log ] [27 ] [INFO ] - card: CAM enabled : True
[2016-01-28 19:06:25,274] [Log ] [27 ] [INFO ] - card: WaitForFile - waiting _eventAudio & _eventVideo
[2016-01-28 19:06:26,242] [Log ] [29 ] [INFO ] - PID seen - type = Video
[2016-01-28 19:06:26,247] [Log ] [29 ] [INFO ] - audioVideoEventHandler Video
[2016-01-28 19:06:26,251] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:26
[2016-01-28 19:06:26,282] [Log ] [29 ] [INFO ] - PID seen - type = Audio
[2016-01-28 19:06:26,286] [Log ] [29 ] [INFO ] - audioVideoEventHandler Audio
[2016-01-28 19:06:26,291] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:26
[2016-01-28 19:06:26,296] [Log ] [27 ] [INFO ] - card: WaitForFile - video and audio are seen after 1,0170593 seconds
[2016-01-28 19:06:26,301] [Log ] [27 ] [INFO ] - Controller: StartTimeShifting started on card:4 to C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:06:26,305] [Log ] [27 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=4, tuningdetails=DVBS:tv:Telenor Sjuan Freq:11216000 ONID:70 TSID:27 SID:2108 PMT:0xAC FTA:False LCN:10000 SymbolRate:24500 Modulation:ModNotSet Polarisation:LinearV InnerFecRate:Rate7_8 DisEqc:SimpleA band:Universal Pilot:NotSet RollOff:NotSet
[2016-01-28 19:06:26,309] [Log ] [27 ] [INFO ] - Controller: Hometown 4 0
[2016-01-28 19:06:26,313] [Log ] [27 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndZapChannel
[2016-01-28 19:06:26,317] [Log ] [27 ] [INFO ] - control2:Hometown 4 0
[2016-01-28 19:06:26,322] [Log ] [19 ] [DEBUG] - Controller: DoSetChannelStates for 1033 channels
[2016-01-28 19:06:26,328] [Log ] [19 ] [INFO ] - ChannelStates.GetAllTimeshiftingAndRecordingChannels took 0 msec
[2016-01-28 19:06:27,757] [Log ] [19 ] [INFO ] - ChannelStates.DoSetChannelStates took 1434 msec
[2016-01-28 19:06:33,619] [Log ] [27 ] [INFO ] - Controller: TimeShiftingWouldUseCard Kanal 5 HD 3099
[2016-01-28 19:06:33,624] [Log ] [27 ] [INFO ] - Controller: find free card for channel Kanal 5 HD
[2016-01-28 19:06:33,628] [Log ] [27 ] [INFO ] - Controller: find card for channel Kanal 5 HD
[2016-01-28 19:06:33,633] [Log ] [27 ] [INFO ] - Controller: got 1 tuning details for Kanal 5 HD
[2016-01-28 19:06:33,638] [Log ] [27 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:33,642] [Log ] [27 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:06:33,645] [Log ] [27 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:06:33,648] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:06:33,652] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:06:33,657] [Log ] [27 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:06:33,660] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 32 msec
[2016-01-28 19:06:33,664] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:06:33,667] [Log ] [27 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:06:33,670] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 46 msec
[2016-01-28 19:06:33,725] [Log ] [27 ] [INFO ] - Controller: StartTimeShifting Kanal 5 HD 3099
[2016-01-28 19:06:33,728] [Log ] [27 ] [INFO ] - Controller: epg stop
[2016-01-28 19:06:33,731] [Log ] [27 ] [INFO ] - Controller: find free card for channel Kanal 5 HD
[2016-01-28 19:06:33,734] [Log ] [27 ] [INFO ] - Controller: find card for channel Kanal 5 HD
[2016-01-28 19:06:33,738] [Log ] [27 ] [INFO ] - Controller: got 1 tuning details for Kanal 5 HD
[2016-01-28 19:06:33,741] [Log ] [27 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:33,743] [Log ] [27 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:06:33,746] [Log ] [27 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:06:33,750] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:06:33,753] [Log ] [27 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:06:33,755] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 21 msec
[2016-01-28 19:06:33,758] [Log ] [27 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:06:33,761] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 29 msec
[2016-01-28 19:06:33,766] [Log ] [27 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=5, tuningdetails=DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:33,769] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:06:33,772] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:06:33,775] [Log ] [27 ] [INFO ] - Controller: try max 1 of 1 cards for timeshifting
[2016-01-28 19:06:33,778] [Log ] [27 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartZapChannel
[2016-01-28 19:06:33,781] [Log ] [27 ] [DEBUG] - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3099, ticket=5, tunestate=Tuning, stopstate=Idle
[2016-01-28 19:06:33,784] [Log ] [27 ] [INFO ] - card: CardTune 4 Kanal 5 HD (S) Hometown:4:-1
[2016-01-28 19:06:33,787] [Log ] [27 ] [INFO ] - card: Tune on card 4 to subchannel Kanal 5 HD (S)
[2016-01-28 19:06:33,790] [Log ] [27 ] [DEBUG] - card: user: Hometown:4:0 tune DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:33,798] [Log ] [27 ] [DEBUG] - card: to different transponder
[2016-01-28 19:06:33,801] [Log ] [27 ] [INFO ] - FreeSubChannel MD: freeing sub channel : 0
[2016-01-28 19:06:33,804] [Log ] [27 ] [INFO ] - mdplug: FreeChannel Sjuan
[2016-01-28 19:06:33,807] [Log ] [27 ] [INFO ] - mdplug: usage counter for channel 'Sjuan' is zero
[2016-01-28 19:06:33,810] [Log ] [27 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2016-01-28 19:06:33,813] [Log ] [27 ] [INFO ] - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
[2016-01-28 19:06:33,815] [Log ] [27 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2016-01-28 19:06:33,818] [Log ] [27 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:33,821] [Log ] [27 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:33,824] [Log ] [27 ] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2016-01-28 19:06:33,826] [Log ] [27 ] [INFO ] - dvbs:channel modulation is set to Mod8Psk
[2016-01-28 19:06:33,829] [Log ] [27 ] [INFO ] - dvbs:channel FECRate is set to Rate3_4
[2016-01-28 19:06:33,832] [Log ] [27 ] [DEBUG] - Turbosight: set tone state, burst = ToneBurst, 22 kHz = Off
[2016-01-28 19:06:33,837] [Log ] [27 ] [DEBUG] - Turbosight: burst result = success
[2016-01-28 19:06:33,841] [Log ] [27 ] [DEBUG] - Turbosight: 22 kHz result = success
[2016-01-28 19:06:33,843] [Log ] [27 ] [INFO ] - Turbosight: Set DVB-S2
[2016-01-28 19:06:33,947] [Log ] [27 ] [INFO ] - dvb:Submiting tunerequest Channel:Kanal 5 HD (S) subChannel:0
[2016-01-28 19:06:33,951] [Log ] [27 ] [INFO ] - dvb:using existing subchannel:0
[2016-01-28 19:06:33,954] [Log ] [27 ] [INFO ] - dvb:Submit tunerequest size:1 new:0
[2016-01-28 19:06:33,958] [Log ] [27 ] [INFO ] - subch:0 OnBeforeTune
[2016-01-28 19:06:33,962] [Log ] [27 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest
[2016-01-28 19:06:34,154] [Log ] [27 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest
[2016-01-28 19:06:34,159] [Log ] [27 ] [INFO ] - subch:0 OnAfterTune
[2016-01-28 19:06:34,163] [Log ] [27 ] [INFO ] - RunGraph
[2016-01-28 19:06:34,167] [Log ] [27 ] [INFO ] - dvb: LockInOnSignal ok
[2016-01-28 19:06:34,171] [Log ] [27 ] [INFO ] - subch:0 OnGraphStart
[2016-01-28 19:06:34,175] [Log ] [27 ] [INFO ] - subch:0 Graph already running - WaitForPMT
[2016-01-28 19:06:34,180] [Log ] [27 ] [INFO ] - subch:0 SetupPmtGrabber:pid 132 sid:1A91
[2016-01-28 19:06:34,184] [Log ] [27 ] [INFO ] - subch:0 set pmt grabber pmt:132 sid:1A91
[2016-01-28 19:06:34,188] [Log ] [27 ] [INFO ] - subch:0 set ca grabber
[2016-01-28 19:06:34,192] [Log ] [27 ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2016-01-28 19:06:34,196] [Log ] [27 ] [DEBUG] - WaitForPMT: Waiting for PMT 132
[2016-01-28 19:06:34,217] [Log ] [29 ] [INFO ] - subch:OnCaReceived()
[2016-01-28 19:06:34,312] [Log ] [29 ] [INFO ] - subch:0 OnPMTReceived() pmt:132 ran:True dynamic:False
[2016-01-28 19:06:34,316] [Log ] [27 ] [DEBUG] - WaitForPMT: Found PMT after 0,1200067 seconds.
[2016-01-28 19:06:34,320] [Log ] [27 ] [INFO ] - subch:0 SendPmt:CA found after 0 seconds
[2016-01-28 19:06:34,324] [Log ] [27 ] [INFO ] - subch:0 SendPmt:1A91 1A91 FFFFFFFF 12
[2016-01-28 19:06:34,328] [Log ] [27 ] [INFO ] - Decode pmt
[2016-01-28 19:06:34,332] [Log ] [27 ] [INFO ] - descr1 len:6 9 4 b 0 fb c0
[2016-01-28 19:06:34,336] [Log ] [27 ] [INFO ] - Set descriptor data with length 6
[2016-01-28 19:06:34,340] [Log ] [27 ] [INFO ] - Set descriptor data with length 7
[2016-01-28 19:06:34,344] [Log ] [27 ] [INFO ] - subch:0 SendPMT version:18 len:50 6801
[2016-01-28 19:06:34,348] [Log ] [27 ] [DEBUG] - Turbosight: send PMT to CAM, list action = Only, command = Descrambling
[2016-01-28 19:06:34,352] [Log ] [27 ] [DEBUG] - Turbosight: CAM not available
[2016-01-28 19:06:34,356] [Log ] [27 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:06:34,360] [Log ] [27 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:06:34,363] [Log ] [27 ] [INFO ] - subch:0 cam flags:False
[2016-01-28 19:06:34,366] [Log ] [27 ] [INFO ] - subch:0 SetMpegPidMapping
[2016-01-28 19:06:34,368] [Log ] [27 ] [INFO ] - subch:0 pid:4E7 pcr
[2016-01-28 19:06:34,371] [Log ] [27 ] [INFO ] - subch:0 pid:132 pmt
[2016-01-28 19:06:34,374] [Log ] [27 ] [INFO ] - subch:0 pid:4E7 video type:H.264
[2016-01-28 19:06:34,376] [Log ] [27 ] [INFO ] - subch:0 map pid:4E7 video type:H.264
[2016-01-28 19:06:34,379] [Log ] [27 ] [INFO ] - subch:0 pid:CB7 audio lang:swe type:MPEG-2
[2016-01-28 19:06:34,382] [Log ] [27 ] [INFO ] - subch:0 map pid:CB7 audio lang:swe type:MPEG-2
[2016-01-28 19:06:34,384] [Log ] [27 ] [INFO ] - subch:0 pid:18A6 teletext type:6
[2016-01-28 19:06:34,387] [Log ] [27 ] [INFO ] - subch:0 map pid:18A6 teletext type:6
[2016-01-28 19:06:34,390] [Log ] [27 ] [INFO ] - ecm len:6 9 4 B 0 FB C0
[2016-01-28 19:06:34,393] [Log ] [27 ] [INFO ] - emm len:6 9 4 B 0 E0 30
[2016-01-28 19:06:34,395] [Log ] [27 ] [INFO ] - Number of HWPIDS that needs to be sent to tuner :11
[2016-01-28 19:06:34,399] [Log ] [27 ] [INFO ] - mdplug: SetChannel nr of currently decoding channels 0.
[2016-01-28 19:06:34,401] [Log ] [27 ] [INFO ] - mdplug: SetChannel starting decryption on channel 'Kanal 5 HD (S)' using plugin slot 1 of 1 avail.
[2016-01-28 19:06:34,404] [Log ] [27 ] [INFO ] - emm len:6 9 4 B 0 E0 30
[2016-01-28 19:06:34,407] [Log ] [27 ] [INFO ] - EMM #0 CA:0xB00 EMM:0x30 ID:0x0
[2016-01-28 19:06:34,409] [Log ] [27 ] [INFO ] - ecm len:6 9 4 B 0 FB C0
[2016-01-28 19:06:34,412] [Log ] [27 ] [INFO ] - ECM #0 CA:0xB00 ECM:0x1BC0 ID:0x0
[2016-01-28 19:06:34,415] [Log ] [27 ] [INFO ] - mdplug: tp_id:67(0x43) sid:6801(0x1A91) pmt_id:306(0x132)
[2016-01-28 19:06:34,418] [Log ] [27 ] [INFO ] - mdplug: #0 CA_typ:2816(0xB00) ECM:7104(0x1BC0) EMM:0x30 provider:0(0x0)
[2016-01-28 19:06:34,421] [Log ] [27 ] [INFO ] - mdplug: Send channel change to MDAPI filter Ca_Id:0 CA_Nr:1 ECM_PID:7104(0x1BC0)
[2016-01-28 19:06:34,424] [Log ] [27 ] [INFO ] - subch:0 stop tif
[2016-01-28 19:06:34,427] [Log ] [27 ] [DEBUG] - WaitForPmt: PMT handling took 0,1070058 seconds.
[2016-01-28 19:06:34,435] [Log ] [27 ] [DEBUG] - card: Tuner locked: True
[2016-01-28 19:06:34,438] [Log ] [27 ] [INFO ] - klzzwxh:10791klzzwxh:10790klzzwxh:10789klzzwxh:10788klzzwxh:10787klzzwxh:10786klzzwxh:10785
klzzwxh:10058 klzzwxh:10059 klzzwxh:10060 klzzwxh:10061 - ** SIGNAL LEVEL: 95, SIGNAL QUALITY: 82
klzzwxh:10073 klzzwxh:10074 klzzwxh:10075 klzzwxh:10076 - klzzwxh:10784klzzwxh:10783klzzwxh:10782klzzwxh:10781klzzwxh:10780klzzwxh:10779klzzwxh:10778
klzzwxh:10081 klzzwxh:10082 klzzwxh:10083 klzzwxh:10084 - card: tuned user: Hometown subchannel: 0
klzzwxh:10085 klzzwxh:10086 klzzwxh:10087 klzzwxh:10088 - user:Hometown add
klzzwxh:10089 klzzwxh:10090 klzzwxh:10091 klzzwxh:10092 - card2:Hometown 4 0
klzzwxh:10093 klzzwxh:10094 klzzwxh:10095 klzzwxh:10096 - Timeshifting started - Recordings=0 TimeShiftingActive=True
klzzwxh:10097 klzzwxh:10098 klzzwxh:10099 klzzwxh:10100 - TVServerKodi: OnTvServerEvent: StartTimeShifting
klzzwxh:10101 klzzwxh:10102 klzzwxh:10103 klzzwxh:10104 - Controller: epg stop
klzzwxh:10105 klzzwxh:10106 klzzwxh:10107 klzzwxh:10108 - card: StartTimeShifting 4 C:klzzwxh:10109rogramDataklzzwxh:10110eam MediaPortalklzzwxh:10111ediaPortal TV Serverklzzwxh:10112imeshiftbufferklzzwxh:10113ive4-0.ts
klzzwxh:10114 klzzwxh:10115 klzzwxh:10116 klzzwxh:10117 - card: CAM enabled : True
klzzwxh:10118 klzzwxh:10119 klzzwxh:10120 klzzwxh:10121 - card: WaitForFile - waiting _eventAudio & _eventVideo
klzzwxh:10122 klzzwxh:10123 klzzwxh:10124 klzzwxh:10125 - PID seen - type = Video
klzzwxh:10126 klzzwxh:10127 klzzwxh:10128 klzzwxh:10129 - audioVideoEventHandler Video
klzzwxh:10130 klzzwxh:10131 klzzwxh:10132 klzzwxh:10133 - video last seen at 2016-01-28 19:06:34
klzzwxh:10134 klzzwxh:10135 klzzwxh:10136 klzzwxh:10137 - video last seen at 2016-01-28 19:06:35
klzzwxh:10138 klzzwxh:10139 klzzwxh:10140 klzzwxh:10141 - PID seen - type = Audio
klzzwxh:10142 klzzwxh:10143 klzzwxh:10144 klzzwxh:10145 - audioVideoEventHandler Audio
klzzwxh:10146 klzzwxh:10147 klzzwxh:10148 klzzwxh:10149 - audio last seen at 2016-01-28 19:06:35
klzzwxh:10150 klzzwxh:10151 klzzwxh:10152 klzzwxh:10153 - card: WaitForFile - video and audio are seen after 0,5900344 seconds
klzzwxh:10154 klzzwxh:10155 klzzwxh:10156 klzzwxh:10157 - audio last seen at 2016-01-28 19:06:35
klzzwxh:10158 klzzwxh:10159 klzzwxh:10160 klzzwxh:10161 - Controller: StartTimeShifting started on card:4 to C:klzzwxh:10162rogramDataklzzwxh:10163eam MediaPortalklzzwxh:10164ediaPortal TV Serverklzzwxh:10165imeshiftbufferklzzwxh:10166ive4-0.ts
klzzwxh:10167 klzzwxh:10168 klzzwxh:10169 klzzwxh:10170 - CardReservation.RemoveTuneTicket: removed reservation with id=5, tuningdetails=DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
klzzwxh:10171 klzzwxh:10172 klzzwxh:10173 klzzwxh:10174 - Controller: Hometown 4 0
klzzwxh:10175 klzzwxh:10176 klzzwxh:10177 klzzwxh:10178 - TVServerKodi: OnTvServerEvent: EndZapChannel
klzzwxh:10179 klzzwxh:10180 klzzwxh:10181 klzzwxh:10182 - control2:Hometown 4 0
klzzwxh:10183 klzzwxh:10184 klzzwxh:10185 klzzwxh:10186 - Controller: DoSetChannelStates for 1033 channels
klzzwxh:10187 klzzwxh:10188 klzzwxh:10189 klzzwxh:10190 - ChannelStates.GetAllTimeshiftingAndRecordingChannels took 0 msec
klzzwxh:10191 klzzwxh:10192 klzzwxh:10193 klzzwxh:10194 - ChannelStates.DoSetChannelStates took 1515 msec
klzzwxh:10195 klzzwxh:10196 klzzwxh:10197 klzzwxh:10198 - Controller: TimeShiftingWouldUseCard TV6 3086
klzzwxh:10199 klzzwxh:10200 klzzwxh:10201 klzzwxh:10202 - Controller: find free card for channel TV6
klzzwxh:10203 klzzwxh:10204 klzzwxh:10205 klzzwxh:10206 - Controller: find card for channel TV6
klzzwxh:10207 klzzwxh:10208 klzzwxh:10209 klzzwxh:10210 - Controller: got 1 tuning details for TV6
klzzwxh:10211 klzzwxh:10212 klzzwxh:10213 klzzwxh:10214 - Controller: channel #1 DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
klzzwxh:10215 klzzwxh:10216 klzzwxh:10217 klzzwxh:10218 - Controller: card:1 type:RadioWebStream is disabled
klzzwxh:10219 klzzwxh:10220 klzzwxh:10221 klzzwxh:10222 - Controller: card:5 type:DvbS is disabled
klzzwxh:10223 klzzwxh:10224 klzzwxh:10225 klzzwxh:10226 - Controller: card:4 type:DvbS can tune to channel
klzzwxh:10227 klzzwxh:10228 klzzwxh:10229 klzzwxh:10230 - Controller: card:4 type:DvbS users: 0
klzzwxh:10231 klzzwxh:10232 klzzwxh:10233 klzzwxh:10234 - Controller: found 1 card(s) for channel
klzzwxh:10235 klzzwxh:10236 klzzwxh:10237 klzzwxh:10238 - AdvancedCardAllocation.GetAvailableCardsForChannel took 53 msec
klzzwxh:10239 klzzwxh:10240 klzzwxh:10241 klzzwxh:10242 - Controller: card:4 type:DvbS is available
klzzwxh:10243 klzzwxh:10244 klzzwxh:10245 klzzwxh:10246 - Controller: found 1 free card(s)
klzzwxh:10247 klzzwxh:10248 klzzwxh:10249 klzzwxh:10250 - AdvancedCardAllocation.GetFreeCardsForChannel took 70 msec
klzzwxh:10251 klzzwxh:10252 klzzwxh:10253 klzzwxh:10254 - Controller: StartTimeShifting TV6 3086
klzzwxh:10255 klzzwxh:10256 klzzwxh:10257 klzzwxh:10258 - Controller: epg stop
klzzwxh:10259 klzzwxh:10260 klzzwxh:10261 klzzwxh:10262 - Controller: find free card for channel TV6
klzzwxh:10263 klzzwxh:10264 klzzwxh:10265 klzzwxh:10266 - Controller: find card for channel TV6
klzzwxh:10267 klzzwxh:10268 klzzwxh:10269 klzzwxh:10270 - Controller: got 1 tuning details for TV6
klzzwxh:10271 klzzwxh:10272 klzzwxh:10273 klzzwxh:10274 - Controller: channel #1 DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
klzzwxh:10275 klzzwxh:10276 klzzwxh:10277 klzzwxh:10278 - Controller: card:1 type:RadioWebStream is disabled
klzzwxh:10279 klzzwxh:10280 klzzwxh:10281 klzzwxh:10282 - Controller: card:5 type:DvbS is disabled
klzzwxh:10283 klzzwxh:10284 klzzwxh:10285 klzzwxh:10286 - Controller: card:4 type:DvbS can tune to channel
klzzwxh:10287 klzzwxh:10288 klzzwxh:10289 klzzwxh:10290 - Controller: found 1 card(s) for channel
klzzwxh:10291 klzzwxh:10292 klzzwxh:10293 klzzwxh:10294 - AdvancedCardAllocation.GetAvailableCardsForChannel took 22 msec
klzzwxh:10295 klzzwxh:10296 klzzwxh:10297 klzzwxh:10298 - Controller: found 1 free card(s)
klzzwxh:10299 klzzwxh:10300 klzzwxh:10301 klzzwxh:10302 - AdvancedCardAllocation.GetFreeCardsForChannel took 30 msec
klzzwxh:10303 klzzwxh:10304 klzzwxh:10305 klzzwxh:10306 - CardReservationBase.RequestCardTuneReservation: placed reservation with id=6, tuningdetails=DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
klzzwxh:10307 klzzwxh:10308 klzzwxh:10309 klzzwxh:10310 - Controller: card:4 type:DvbS users: 0
klzzwxh:10311 klzzwxh:10312 klzzwxh:10313 klzzwxh:10314 - Controller: card:4 type:DvbS is available
klzzwxh:10315 klzzwxh:10316 klzzwxh:10317 klzzwxh:10318 - Controller: try max 1 of 1 cards for timeshifting
klzzwxh:10319 klzzwxh:10320 klzzwxh:10321 klzzwxh:10322 - TVServerKodi: OnTvServerEvent: StartZapChannel
klzzwxh:10323 klzzwxh:10324 klzzwxh:10325 klzzwxh:10326 - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3086, ticket=6, tunestate=Tuning, stopstate=Idle
klzzwxh:10327 klzzwxh:10328 klzzwxh:10329 klzzwxh:10330 - card: CardTune 4 TV6 Hometown:4:-1
klzzwxh:10331 klzzwxh:10332 klzzwxh:10333 klzzwxh:10334 - card: Tune on card 4 to subchannel TV6
klzzwxh:10335 klzzwxh:10336 klzzwxh:10337 klzzwxh:10338 - card: user: Hometown:4:0 tune DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
klzzwxh:10339 klzzwxh:10340 klzzwxh:10341 klzzwxh:10342 - card: to different transponder
klzzwxh:10343 klzzwxh:10344 klzzwxh:10345 klzzwxh:10346 - FreeSubChannel MD: freeing sub channel : 0
klzzwxh:10347 klzzwxh:10348 klzzwxh:10349 klzzwxh:10350 - mdplug: FreeChannel Kanal 5 HD (S)
klzzwxh:10351 klzzwxh:10352 klzzwxh:10353 klzzwxh:10354 - mdplug: usage counter for channel 'Kanal 5 HD (S)' is zero
klzzwxh:10355 klzzwxh:10356 klzzwxh:10357 klzzwxh:10358 - tvcard:FreeSubChannel: subchannels count 1 subch#0
klzzwxh:10359 klzzwxh:10360 klzzwxh:10361 klzzwxh:10362 - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
klzzwxh:10363 klzzwxh:10364 klzzwxh:10365 klzzwxh:10366 - TimeShifter.OnBeforeTune: resetting audio/video events
klzzwxh:10367 klzzwxh:10368 klzzwxh:10369 klzzwxh:10370 - dvbs: Tune:DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
klzzwxh:10371 klzzwxh:10372 klzzwxh:10373 klzzwxh:10374 - dvbs: Tune:DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
klzzwxh:10375 klzzwxh:10376 klzzwxh:10377 klzzwxh:10378 - LNB low:9750 hi:10600 switch:11700
klzzwxh:10379 klzzwxh:10380 klzzwxh:10381 klzzwxh:10382 - dvbs:channel modulation is set to ModQpsk
klzzwxh:10383 klzzwxh:10384 klzzwxh:10385 klzzwxh:10386 - dvbs:channel FECRate is set to Rate3_4
klzzwxh:10387 klzzwxh:10388 klzzwxh:10389 klzzwxh:10390 - Turbosight: set tone state, burst = DataBurst, 22 kHz = On
klzzwxh:10391 klzzwxh:10392 klzzwxh:10393 klzzwxh:10394 - Turbosight: burst result = success
klzzwxh:10395 klzzwxh:10396 klzzwxh:10397 klzzwxh:10398 - Turbosight: 22 kHz result = success
klzzwxh:10399 klzzwxh:10400 klzzwxh:10401 klzzwxh:10402 - Turbosight: Set DVB-S2
klzzwxh:10403 klzzwxh:10404 klzzwxh:10405 klzzwxh:10406 - dvb:Submiting tunerequest Channel:TV6 subChannel:0
klzzwxh:10407 klzzwxh:10408 klzzwxh:10409 klzzwxh:10410 - dvb:using existing subchannel:0
klzzwxh:10411 klzzwxh:10412 klzzwxh:10413 klzzwxh:10414 - dvb:Submit tunerequest size:1 new:0
klzzwxh:10415 klzzwxh:10416 klzzwxh:10417 klzzwxh:10418 - subch:0 OnBeforeTune
klzzwxh:10419 klzzwxh:10420 klzzwxh:10421 klzzwxh:10422 - dvb:Submit tunerequest calling put_TuneRequest
klzzwxh:10423 klzzwxh:10424 klzzwxh:10425 klzzwxh:10426 - dvb:Submit tunerequest done calling put_TuneRequest
klzzwxh:10427 klzzwxh:10428 klzzwxh:10429 klzzwxh:10430 - subch:0 OnAfterTune
klzzwxh:10431 klzzwxh:10432 klzzwxh:10433 klzzwxh:10434 - RunGraph
klzzwxh:10435 klzzwxh:10436 klzzwxh:10437 klzzwxh:10438 - dvb: LockInOnSignal ok
klzzwxh:10439 klzzwxh:10440 klzzwxh:10441 klzzwxh:10442 - subch:0 OnGraphStart
klzzwxh:10443 klzzwxh:10444 klzzwxh:10445 klzzwxh:10446 - subch:0 Graph already running - WaitForPMT
klzzwxh:10447 klzzwxh:10448 klzzwxh:10449 klzzwxh:10450 - subch:0 SetupPmtGrabber:pid 488 sid:488
klzzwxh:10451 klzzwxh:10452 klzzwxh:10453 klzzwxh:10454 - subch:0 set pmt grabber pmt:488 sid:488
klzzwxh:10455 klzzwxh:10456 klzzwxh:10457 klzzwxh:10458 - subch:0 set ca grabber
klzzwxh:10459 klzzwxh:10460 klzzwxh:10461 klzzwxh:10462 - TimeShifter.OnAfterTune: resetting audio/video time
klzzwxh:10463 klzzwxh:10464 klzzwxh:10465 klzzwxh:10466 - WaitForPMT: Waiting for PMT 488
klzzwxh:10467 klzzwxh:10468 klzzwxh:10469 klzzwxh:10470 - subch:OnCaReceived()
klzzwxh:10471 klzzwxh:10472 klzzwxh:10473 klzzwxh:10474 - subch:0 OnPMTReceived() pmt:488 ran:True dynamic:False
klzzwxh:10475 klzzwxh:10476 klzzwxh:10477 klzzwxh:10478 - WaitForPMT: Found PMT after 0,0320016 seconds.
klzzwxh:10479 klzzwxh:10480 klzzwxh:10481 klzzwxh:10482 - subch:0 SendPmt:CA found after 0 seconds
klzzwxh:10483 klzzwxh:10484 klzzwxh:10485 klzzwxh:10486 - subch:0 SendPmt:488 488 FFFFFFFF 11
klzzwxh:10487 klzzwxh:10488 klzzwxh:10489 klzzwxh:10490 - Decode pmt
klzzwxh:10491 klzzwxh:10492 klzzwxh:10493 klzzwxh:10494 - descr2 pid:489 len:6 9 4 9 f e4 8d
klzzwxh:10495 klzzwxh:10496 klzzwxh:10497 klzzwxh:10498 - descr2 pid:489 len:6 9 4 9 3e e0 98
klzzwxh:10499 klzzwxh:10500 klzzwxh:10501 klzzwxh:10502 - descr2 pid:489 len:6 9 4 9 40 e1 92
klzzwxh:10503 klzzwxh:10504 klzzwxh:10505 klzzwxh:10506 - Set descriptor data with length 7
klzzwxh:10507 klzzwxh:10508 klzzwxh:10509 klzzwxh:10510 - Set descriptor data with length 6
klzzwxh:10511 klzzwxh:10512 klzzwxh:10513 klzzwxh:10514 - descr2 pid:48A len:6 9 4 9 f e4 8d
klzzwxh:10515 klzzwxh:10516 klzzwxh:10517 klzzwxh:10518 - descr2 pid:48A len:6 9 4 9 3e e0 98
klzzwxh:10519 klzzwxh:10520 klzzwxh:10521 klzzwxh:10522 - descr2 pid:48A len:6 9 4 9 40 e1 92
klzzwxh:10523 klzzwxh:10524 klzzwxh:10525 klzzwxh:10526 - Set descriptor data with length 6
klzzwxh:10527 klzzwxh:10528 klzzwxh:10529 klzzwxh:10530 - descr2 pid:48B len:6 9 4 9 f e4 8d
klzzwxh:10531 klzzwxh:10532 klzzwxh:10533 klzzwxh:10534 - descr2 pid:48B len:6 9 4 9 3e e0 98
klzzwxh:10535 klzzwxh:10536 klzzwxh:10537 klzzwxh:10538 - descr2 pid:48B len:6 9 4 9 40 e1 92
klzzwxh:10539 klzzwxh:10540 klzzwxh:10541 klzzwxh:10542 - subch:0 SendPMT version:17 len:109 1160
klzzwxh:10543 klzzwxh:10544 klzzwxh:10545 klzzwxh:10546 - Turbosight: send PMT to CAM, list action = Only, command = Descrambling
klzzwxh:10547 klzzwxh:10548 klzzwxh:10549 klzzwxh:10550 - Turbosight: CAM not available
klzzwxh:10551 klzzwxh:10552 klzzwxh:10553 klzzwxh:10554 - Turbosight: is CAM ready
klzzwxh:10555 klzzwxh:10556 klzzwxh:10557 klzzwxh:10558 - Turbosight: interface not opened
klzzwxh:10559 klzzwxh:10560 klzzwxh:10561 klzzwxh:10562 - subch:0 cam flags:False
klzzwxh:10563 klzzwxh:10564 klzzwxh:10565 klzzwxh:10566 - subch:0 SetMpegPidMapping
klzzwxh:10567 klzzwxh:10568 klzzwxh:10569 klzzwxh:10570 - subch:0 pid:489 pcr
klzzwxh:10571 klzzwxh:10572 klzzwxh:10573 klzzwxh:10574 - subch:0 pid:488 pmt
klzzwxh:10575 klzzwxh:10576 klzzwxh:10577 klzzwxh:10578 - subch:0 pid:489 video type:MPEG-2
klzzwxh:10579 klzzwxh:10580 klzzwxh:10581 klzzwxh:10582 - subch:0 map pid:489 video type:MPEG-2
klzzwxh:10583 klzzwxh:10584 klzzwxh:10585 klzzwxh:10586 - subch:0 pid:48E teletext type:6
klzzwxh:10587 klzzwxh:10588 klzzwxh:10589 klzzwxh:10590 - subch:0 map pid:48E teletext type:6
klzzwxh:10591 klzzwxh:10592 klzzwxh:10593 klzzwxh:10594 - subch:0 pid:48A audio lang:swe type:MPEG-1
klzzwxh:10595 klzzwxh:10596 klzzwxh:10597 klzzwxh:10598 - subch:0 map pid:48A audio lang:swe type:MPEG-1
klzzwxh:10599 klzzwxh:10600 klzzwxh:10601 klzzwxh:10602 - subch:0 pid:48B audio lang:syn type:MPEG-1
klzzwxh:10603 klzzwxh:10604 klzzwxh:10605 klzzwxh:10606 - ecm len:6 9 4 9 F E4 8D
klzzwxh:10607 klzzwxh:10608 klzzwxh:10609 klzzwxh:10610 - ecm len:6 9 4 9 3E E0 98
klzzwxh:10611 klzzwxh:10612 klzzwxh:10613 klzzwxh:10614 - ecm len:6 9 4 9 40 E1 92
klzzwxh:10615 klzzwxh:10616 klzzwxh:10617 klzzwxh:10618 - ecm len:6 9 4 9 F E4 8D
klzzwxh:10619 klzzwxh:10620 klzzwxh:10621 klzzwxh:10622 - ecm len:6 9 4 9 3E E0 98
klzzwxh:10623 klzzwxh:10624 klzzwxh:10625 klzzwxh:10626 - ecm len:6 9 4 9 40 E1 92
klzzwxh:10627 klzzwxh:10628 klzzwxh:10629 klzzwxh:10630 - ecm len:6 9 4 9 F E4 8D
klzzwxh:10631 klzzwxh:10632 klzzwxh:10633 klzzwxh:10634 - ecm len:6 9 4 9 3E E0 98
klzzwxh:10635 klzzwxh:10636 klzzwxh:10637 klzzwxh:10638 - ecm len:6 9 4 9 40 E1 92
klzzwxh:10639 klzzwxh:10640 klzzwxh:10641 klzzwxh:10642 - emm len:6 9 4 9 F E0 C0
klzzwxh:10643 klzzwxh:10644 klzzwxh:10645 klzzwxh:10646 - emm len:6 9 4 9 3E E0 C1
klzzwxh:10647 klzzwxh:10648 klzzwxh:10649 klzzwxh:10650 - emm len:6 9 4 9 40 E0 C2
klzzwxh:10651 klzzwxh:10652 klzzwxh:10653 klzzwxh:10654 - Number of HWPIDS that needs to be sent to tuner :16
klzzwxh:10655 klzzwxh:10656 klzzwxh:10657 klzzwxh:10658 - mdplug: SetChannel nr of currently decoding channels 0.
klzzwxh:10659 klzzwxh:10660 klzzwxh:10661 klzzwxh:10662 - mdplug: SetChannel starting decryption on channel 'TV6' using plugin slot 1 of 1 avail.
klzzwxh:10663 klzzwxh:10664 klzzwxh:10665 klzzwxh:10666 - emm len:6 9 4 9 F E0 C0
klzzwxh:10667 klzzwxh:10668 klzzwxh:10669 klzzwxh:10670 - emm len:6 9 4 9 3E E0 C1
klzzwxh:10671 klzzwxh:10672 klzzwxh:10673 klzzwxh:10674 - emm len:6 9 4 9 40 E0 C2
klzzwxh:10675 klzzwxh:10676 klzzwxh:10677 klzzwxh:10678 - EMM #0 CA:0x90F EMM:0xC0 ID:0x0
klzzwxh:10679 klzzwxh:10680 klzzwxh:10681 klzzwxh:10682 - EMM #1 CA:0x93E EMM:0xC1 ID:0x0
klzzwxh:10683 klzzwxh:10684 klzzwxh:10685 klzzwxh:10686 - EMM #2 CA:0x940 EMM:0xC2 ID:0x0
klzzwxh:10687 klzzwxh:10688 klzzwxh:10689 klzzwxh:10690 - ecm len:6 9 4 9 F E4 8D
klzzwxh:10691 klzzwxh:10692 klzzwxh:10693 klzzwxh:10694 - ecm len:6 9 4 9 3E E0 98
klzzwxh:10695 klzzwxh:10696 klzzwxh:10697 klzzwxh:10698 - ecm len:6 9 4 9 40 E1 92
klzzwxh:10699 klzzwxh:10700 klzzwxh:10701 klzzwxh:10702 - ecm len:6 9 4 9 F E4 8D
klzzwxh:10703 klzzwxh:10704 klzzwxh:10705 klzzwxh:10706 - ecm len:6 9 4 9 3E E0 98
klzzwxh:10707 klzzwxh:10708 klzzwxh:10709 klzzwxh:10710 - ecm len:6 9 4 9 40 E1 92
klzzwxh:10711 klzzwxh:10712 klzzwxh:10713 klzzwxh:10714 - ecm len:6 9 4 9 F E4 8D
klzzwxh:10715 klzzwxh:10716 klzzwxh:10717 klzzwxh:10718 - ecm len:6 9 4 9 3E E0 98
klzzwxh:10719 klzzwxh:10720 klzzwxh:10721 klzzwxh:10722 - ecm len:6 9 4 9 40 E1 92
klzzwxh:10723 klzzwxh:10724 klzzwxh:10725 klzzwxh:10726 - ECM #0 CA:0x90F ECM:0x48D ID:0x0
klzzwxh:10727 klzzwxh:10728 klzzwxh:10729 klzzwxh:10730 - ECM #1 CA:0x93E ECM:0x98 ID:0x0
klzzwxh:10731 klzzwxh:10732 klzzwxh:10733 klzzwxh:10734 - ECM #2 CA:0x940 ECM:0x192 ID:0x0
klzzwxh:10735 klzzwxh:10736 klzzwxh:10737 klzzwxh:10738 - mdplug: tp_id:3(0x3) sid:1160(0x488) pmt_id:1160(0x488)
klzzwxh:10739 klzzwxh:10740 klzzwxh:10741 klzzwxh:10742 - mdplug: #0 CA_typ:2319(0x90F) ECM:1165(0x48D) EMM:0xC0 provider:0(0x0)
klzzwxh:10743 klzzwxh:10744 klzzwxh:10745 klzzwxh:10746 - mdplug: #1 CA_typ:2366(0x93E) ECM:152(0x98) EMM:0xC1 provider:0(0x0)
klzzwxh:10747 klzzwxh:10748 klzzwxh:10749 klzzwxh:10750 - mdplug: #2 CA_typ:2368(0x940) ECM:402(0x192) EMM:0xC2 provider:0(0x0)
klzzwxh:10751 klzzwxh:10752 klzzwxh:10753 klzzwxh:10754 - mdplug: Send channel change to MDAPI filter Ca_Id:0 CA_Nr:3 ECM_PID:1165(0x48D)
klzzwxh:10755 klzzwxh:10756 klzzwxh:10757 klzzwxh:10758 - subch:0 stop tif
klzzwxh:10759 klzzwxh:10760 klzzwxh:10761 klzzwxh:10762 - WaitForPmt: PMT handling took 0,1920112 seconds.
klzzwxh:10763 klzzwxh:10764 klzzwxh:10765 klzzwxh:10766 - card: Tuner locked: True
klzzwxh:10767 klzzwxh:10768 klzzwxh:10769 klzzwxh:10770 - klzzwxh:10777klzzwxh:10776klzzwxh:10775klzzwxh:10774klzzwxh:10773klzzwxh:10772klzzwxh:10771
klzzwxh:10077 klzzwxh:10078 klzzwxh:10079 klzzwxh:10080 - ** SIGNAL LEVEL: 94, SIGNAL QUALITY: 80
klzzwxh:10062 klzzwxh:10063 klzzwxh:10064 klzzwxh:10065 - klzzwxh:10072klzzwxh:10071klzzwxh:10070klzzwxh:10069klzzwxh:10068klzzwxh:10067klzzwxh:10066
[2016-01-28 19:06:41,447] [Log ] [33 ] [DEBUG] - card: tuned user: Hometown subchannel: 0
[2016-01-28 19:06:41,450] [Log ] [33 ] [INFO ] - user:Hometown add
[2016-01-28 19:06:41,454] [Log ] [33 ] [INFO ] - card2:Hometown 4 0
[2016-01-28 19:06:41,457] [Log ] [33 ] [DEBUG] - Timeshifting started - Recordings=0 TimeShiftingActive=True
[2016-01-28 19:06:41,461] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartTimeShifting
[2016-01-28 19:06:41,464] [Log ] [33 ] [INFO ] - Controller: epg stop
[2016-01-28 19:06:41,467] [Log ] [33 ] [INFO ] - card: StartTimeShifting 4 C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:06:41,470] [Log ] [33 ] [INFO ] - card: CAM enabled : True
[2016-01-28 19:06:41,473] [Log ] [33 ] [INFO ] - card: WaitForFile - waiting _eventAudio & _eventVideo
[2016-01-28 19:06:41,957] [Log ] [29 ] [INFO ] - PID seen - type = Video
[2016-01-28 19:06:41,962] [Log ] [29 ] [INFO ] - audioVideoEventHandler Video
[2016-01-28 19:06:41,966] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:41
[2016-01-28 19:06:41,970] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:41
[2016-01-28 19:06:41,974] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:41
[2016-01-28 19:06:41,978] [Log ] [29 ] [INFO ] - PID seen - type = Audio
[2016-01-28 19:06:41,981] [Log ] [29 ] [INFO ] - audioVideoEventHandler Audio
[2016-01-28 19:06:41,984] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:41
[2016-01-28 19:06:41,987] [Log ] [33 ] [INFO ] - card: WaitForFile - video and audio are seen after 0,51103 seconds
[2016-01-28 19:06:41,989] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:41
[2016-01-28 19:06:41,992] [Log ] [33 ] [INFO ] - Controller: StartTimeShifting started on card:4 to C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:06:41,995] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:41
[2016-01-28 19:06:41,998] [Log ] [33 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=6, tuningdetails=DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
[2016-01-28 19:06:42,001] [Log ] [33 ] [INFO ] - Controller: Hometown 4 0
[2016-01-28 19:06:42,004] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndZapChannel
[2016-01-28 19:06:42,008] [Log ] [33 ] [INFO ] - control2:Hometown 4 0
[2016-01-28 19:06:42,012] [Log ] [38 ] [DEBUG] - Controller: DoSetChannelStates for 1033 channels
[2016-01-28 19:06:42,018] [Log ] [38 ] [INFO ] - ChannelStates.GetAllTimeshiftingAndRecordingChannels took 0 msec
[2016-01-28 19:06:42,033] [Log ] [29 ] [INFO ] - PID seen - type = Audio
[2016-01-28 19:06:42,038] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:41
[2016-01-28 19:06:42,043] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:42
[2016-01-28 19:06:42,046] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:42
[2016-01-28 19:06:42,049] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:42
[2016-01-28 19:06:43,422] [Log ] [38 ] [INFO ] - ChannelStates.DoSetChannelStates took 1409 msec
[2016-01-28 19:06:47,695] [Log ] [33 ] [INFO ] - Controller: TimeShiftingWouldUseCard TV4 HD 3476
[2016-01-28 19:06:47,700] [Log ] [33 ] [INFO ] - Controller: find free card for channel TV4 HD
[2016-01-28 19:06:47,704] [Log ] [33 ] [INFO ] - Controller: find card for channel TV4 HD
[2016-01-28 19:06:47,710] [Log ] [33 ] [INFO ] - Controller: got 1 tuning details for TV4 HD
[2016-01-28 19:06:47,713] [Log ] [33 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:47,716] [Log ] [33 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:06:47,719] [Log ] [33 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:06:47,723] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:06:47,727] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:06:47,732] [Log ] [33 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:06:47,735] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 30 msec
[2016-01-28 19:06:47,738] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:06:47,741] [Log ] [33 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:06:47,744] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 44 msec
[2016-01-28 19:06:47,779] [Log ] [33 ] [INFO ] - Controller: StartTimeShifting TV4 HD 3476
[2016-01-28 19:06:47,782] [Log ] [33 ] [INFO ] - Controller: epg stop
[2016-01-28 19:06:47,785] [Log ] [33 ] [INFO ] - Controller: find free card for channel TV4 HD
[2016-01-28 19:06:47,788] [Log ] [33 ] [INFO ] - Controller: find card for channel TV4 HD
[2016-01-28 19:06:47,791] [Log ] [33 ] [INFO ] - Controller: got 1 tuning details for TV4 HD
[2016-01-28 19:06:47,795] [Log ] [33 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:47,797] [Log ] [33 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:06:47,801] [Log ] [33 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:06:47,804] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:06:47,807] [Log ] [33 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:06:47,810] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 22 msec
[2016-01-28 19:06:47,813] [Log ] [33 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:06:47,815] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 30 msec
[2016-01-28 19:06:47,821] [Log ] [33 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=7, tuningdetails=DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:47,824] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:06:47,827] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:06:47,830] [Log ] [33 ] [INFO ] - Controller: try max 1 of 1 cards for timeshifting
[2016-01-28 19:06:47,833] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartZapChannel
[2016-01-28 19:06:47,835] [Log ] [33 ] [DEBUG] - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3476, ticket=7, tunestate=Tuning, stopstate=Idle
[2016-01-28 19:06:47,838] [Log ] [33 ] [INFO ] - card: CardTune 4 TV4 HD Hometown:4:-1
[2016-01-28 19:06:47,842] [Log ] [33 ] [INFO ] - card: Tune on card 4 to subchannel TV4 HD
[2016-01-28 19:06:47,845] [Log ] [33 ] [DEBUG] - card: user: Hometown:4:0 tune DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:47,852] [Log ] [33 ] [DEBUG] - card: to different transponder
[2016-01-28 19:06:47,856] [Log ] [33 ] [INFO ] - FreeSubChannel MD: freeing sub channel : 0
[2016-01-28 19:06:47,858] [Log ] [33 ] [INFO ] - mdplug: FreeChannel TV6
[2016-01-28 19:06:47,861] [Log ] [33 ] [INFO ] - mdplug: usage counter for channel 'TV6' is zero
[2016-01-28 19:06:47,864] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2016-01-28 19:06:47,867] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
[2016-01-28 19:06:47,869] [Log ] [33 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2016-01-28 19:06:47,872] [Log ] [33 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:47,875] [Log ] [33 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:47,878] [Log ] [33 ] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2016-01-28 19:06:47,881] [Log ] [33 ] [INFO ] - dvbs:channel modulation is set to Mod8Psk
[2016-01-28 19:06:47,884] [Log ] [33 ] [INFO ] - dvbs:channel FECRate is set to Rate3_4
[2016-01-28 19:06:47,886] [Log ] [33 ] [DEBUG] - Turbosight: set tone state, burst = ToneBurst, 22 kHz = Off
[2016-01-28 19:06:47,891] [Log ] [33 ] [DEBUG] - Turbosight: burst result = success
[2016-01-28 19:06:47,895] [Log ] [33 ] [DEBUG] - Turbosight: 22 kHz result = success
[2016-01-28 19:06:47,898] [Log ] [33 ] [INFO ] - Turbosight: Set DVB-S2
[2016-01-28 19:06:48,002] [Log ] [33 ] [INFO ] - dvb:Submiting tunerequest Channel:TV4 HD subChannel:0
[2016-01-28 19:06:48,006] [Log ] [33 ] [INFO ] - dvb:using existing subchannel:0
[2016-01-28 19:06:48,010] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest size:1 new:0
[2016-01-28 19:06:48,014] [Log ] [33 ] [INFO ] - subch:0 OnBeforeTune
[2016-01-28 19:06:48,018] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest
[2016-01-28 19:06:48,210] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest
[2016-01-28 19:06:48,215] [Log ] [33 ] [INFO ] - subch:0 OnAfterTune
[2016-01-28 19:06:48,219] [Log ] [33 ] [INFO ] - RunGraph
[2016-01-28 19:06:48,223] [Log ] [33 ] [INFO ] - dvb: LockInOnSignal ok
[2016-01-28 19:06:48,225] [Log ] [33 ] [INFO ] - subch:0 OnGraphStart
[2016-01-28 19:06:48,228] [Log ] [33 ] [INFO ] - subch:0 Graph already running - WaitForPMT
[2016-01-28 19:06:48,231] [Log ] [33 ] [INFO ] - subch:0 SetupPmtGrabber:pid 4F sid:57D
[2016-01-28 19:06:48,234] [Log ] [33 ] [INFO ] - subch:0 set pmt grabber pmt:4F sid:57D
[2016-01-28 19:06:48,236] [Log ] [33 ] [INFO ] - subch:0 set ca grabber
[2016-01-28 19:06:48,239] [Log ] [33 ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2016-01-28 19:06:48,243] [Log ] [33 ] [DEBUG] - WaitForPMT: Waiting for PMT 4F
[2016-01-28 19:06:48,339] [Log ] [29 ] [INFO ] - subch:0 OnPMTReceived() pmt:4F ran:True dynamic:False
[2016-01-28 19:06:48,343] [Log ] [33 ] [DEBUG] - WaitForPMT: Found PMT after 0,1000064 seconds.
[2016-01-28 19:06:48,347] [Log ] [33 ] [INFO ] - subch:0 SendPmt:CA found after 0 seconds
[2016-01-28 19:06:48,351] [Log ] [33 ] [INFO ] - subch:0 SendPmt:57D 57D FFFFFFFF 14
[2016-01-28 19:06:48,355] [Log ] [33 ] [INFO ] - Decode pmt
[2016-01-28 19:06:48,359] [Log ] [33 ] [INFO ] - descr1 len:6 9 4 b 0 fb d0
[2016-01-28 19:06:48,363] [Log ] [33 ] [INFO ] - Set descriptor data with length 6
[2016-01-28 19:06:48,367] [Log ] [33 ] [INFO ] - Set descriptor data with length 7
[2016-01-28 19:06:48,371] [Log ] [33 ] [INFO ] - subch:0 SendPMT version:20 len:53 1405
[2016-01-28 19:06:48,375] [Log ] [33 ] [DEBUG] - Turbosight: send PMT to CAM, list action = Only, command = Descrambling
[2016-01-28 19:06:48,379] [Log ] [33 ] [DEBUG] - Turbosight: CAM not available
[2016-01-28 19:06:48,383] [Log ] [33 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:06:48,387] [Log ] [33 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:06:48,391] [Log ] [33 ] [INFO ] - subch:0 cam flags:False
[2016-01-28 19:06:48,395] [Log ] [33 ] [INFO ] - subch:0 SetMpegPidMapping
[2016-01-28 19:06:48,399] [Log ] [33 ] [INFO ] - subch:0 pid:417 pcr
[2016-01-28 19:06:48,403] [Log ] [33 ] [INFO ] - subch:0 pid:4F pmt
[2016-01-28 19:06:48,405] [Log ] [33 ] [INFO ] - subch:0 pid:417 video type:H.264
[2016-01-28 19:06:48,408] [Log ] [33 ] [INFO ] - subch:0 map pid:417 video type:H.264
[2016-01-28 19:06:48,411] [Log ] [33 ] [INFO ] - subch:0 pid:BE7 audio lang:swe type:AC3
[2016-01-28 19:06:48,414] [Log ] [33 ] [INFO ] - subch:0 map pid:BE7 audio lang:swe type:AC3
[2016-01-28 19:06:48,416] [Log ] [33 ] [INFO ] - subch:0 pid:179A teletext type:6
[2016-01-28 19:06:48,419] [Log ] [33 ] [INFO ] - subch:0 map pid:179A teletext type:6
[2016-01-28 19:06:48,422] [Log ] [33 ] [INFO ] - ecm len:6 9 4 B 0 FB D0
[2016-01-28 19:06:48,425] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 F E0 C0
[2016-01-28 19:06:48,427] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 3E E0 C1
[2016-01-28 19:06:48,430] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 40 E0 C2
[2016-01-28 19:06:48,433] [Log ] [33 ] [INFO ] - Number of HWPIDS that needs to be sent to tuner :13
[2016-01-28 19:06:48,436] [Log ] [33 ] [INFO ] - mdplug: SetChannel nr of currently decoding channels 0.
[2016-01-28 19:06:48,439] [Log ] [33 ] [INFO ] - mdplug: SetChannel starting decryption on channel 'TV4 HD' using plugin slot 1 of 1 avail.
[2016-01-28 19:06:48,441] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 F E0 C0
[2016-01-28 19:06:48,444] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 3E E0 C1
[2016-01-28 19:06:48,447] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 40 E0 C2
[2016-01-28 19:06:48,449] [Log ] [33 ] [INFO ] - EMM #0 CA:0x90F EMM:0xC0 ID:0x0
[2016-01-28 19:06:48,452] [Log ] [33 ] [INFO ] - EMM #1 CA:0x93E EMM:0xC1 ID:0x0
[2016-01-28 19:06:48,455] [Log ] [33 ] [INFO ] - EMM #2 CA:0x940 EMM:0xC2 ID:0x0
[2016-01-28 19:06:48,458] [Log ] [33 ] [INFO ] - ecm len:6 9 4 B 0 FB D0
[2016-01-28 19:06:48,461] [Log ] [33 ] [INFO ] - ECM #0 CA:0xB00 ECM:0x1BD0 ID:0x0
[2016-01-28 19:06:48,464] [Log ] [33 ] [INFO ] - mdplug: tp_id:14(0xE) sid:1405(0x57D) pmt_id:79(0x4F)
[2016-01-28 19:06:48,466] [Log ] [33 ] [INFO ] - mdplug: #0 CA_typ:2816(0xB00) ECM:7120(0x1BD0) EMM:0x0 provider:0(0x0)
[2016-01-28 19:06:48,469] [Log ] [33 ] [INFO ] - mdplug: #1 CA_typ:2319(0x90F) ECM:0(0x0) EMM:0xC0 provider:0(0x0)
[2016-01-28 19:06:48,472] [Log ] [33 ] [INFO ] - mdplug: #2 CA_typ:2366(0x93E) ECM:0(0x0) EMM:0xC1 provider:0(0x0)
[2016-01-28 19:06:48,475] [Log ] [33 ] [INFO ] - mdplug: #3 CA_typ:2368(0x940) ECM:0(0x0) EMM:0xC2 provider:0(0x0)
[2016-01-28 19:06:48,478] [Log ] [33 ] [INFO ] - mdplug: Send channel change to MDAPI filter Ca_Id:0 CA_Nr:4 ECM_PID:7120(0x1BD0)
[2016-01-28 19:06:48,481] [Log ] [33 ] [INFO ] - subch:0 stop tif
[2016-01-28 19:06:48,484] [Log ] [33 ] [DEBUG] - WaitForPmt: PMT handling took 0,1370082 seconds.
[2016-01-28 19:06:48,493] [Log ] [33 ] [DEBUG] - card: Tuner locked: True
[2016-01-28 19:06:48,496] [Log ] [33 ] [INFO ] - klzzwxh:10057klzzwxh:10056klzzwxh:10055klzzwxh:10054klzzwxh:10053klzzwxh:10052klzzwxh:10051
[2016-01-28 19:06:48,498] [Log ] [33 ] [INFO ] - ** SIGNAL LEVEL: 95, SIGNAL QUALITY: 83
[2016-01-28 19:06:48,501] [Log ] [33 ] [INFO ] - klzzwxh:10050klzzwxh:10049klzzwxh:10048klzzwxh:10047klzzwxh:10046klzzwxh:10045klzzwxh:10044
[2016-01-28 19:06:48,504] [Log ] [33 ] [DEBUG] - card: tuned user: Hometown subchannel: 0
[2016-01-28 19:06:48,506] [Log ] [33 ] [INFO ] - user:Hometown add
[2016-01-28 19:06:48,511] [Log ] [33 ] [INFO ] - card2:Hometown 4 0
[2016-01-28 19:06:48,514] [Log ] [33 ] [DEBUG] - Timeshifting started - Recordings=0 TimeShiftingActive=True
[2016-01-28 19:06:48,517] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartTimeShifting
[2016-01-28 19:06:48,520] [Log ] [33 ] [INFO ] - Controller: epg stop
[2016-01-28 19:06:48,523] [Log ] [33 ] [INFO ] - card: StartTimeShifting 4 C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:06:48,527] [Log ] [33 ] [INFO ] - card: CAM enabled : True
[2016-01-28 19:06:48,530] [Log ] [33 ] [INFO ] - card: WaitForFile - waiting _eventAudio & _eventVideo
[2016-01-28 19:06:49,109] [Log ] [29 ] [INFO ] - PID seen - type = Audio
[2016-01-28 19:06:49,114] [Log ] [29 ] [INFO ] - audioVideoEventHandler Audio
[2016-01-28 19:06:49,118] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:49
[2016-01-28 19:06:49,122] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:49
[2016-01-28 19:06:49,126] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:49
[2016-01-28 19:06:49,130] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:49
[2016-01-28 19:06:49,166] [Log ] [29 ] [INFO ] - PID seen - type = Video
[2016-01-28 19:06:49,170] [Log ] [29 ] [INFO ] - audioVideoEventHandler Video
[2016-01-28 19:06:49,174] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:49
[2016-01-28 19:06:49,178] [Log ] [33 ] [INFO ] - card: WaitForFile - video and audio are seen after 0,6440375 seconds
[2016-01-28 19:06:49,182] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:49
[2016-01-28 19:06:49,186] [Log ] [33 ] [INFO ] - Controller: StartTimeShifting started on card:4 to C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:06:49,190] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:49
[2016-01-28 19:06:49,194] [Log ] [33 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=7, tuningdetails=DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:49,198] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:49
[2016-01-28 19:06:49,202] [Log ] [33 ] [INFO ] - Controller: Hometown 4 0
[2016-01-28 19:06:49,207] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndZapChannel
[2016-01-28 19:06:49,212] [Log ] [33 ] [INFO ] - control2:Hometown 4 0
[2016-01-28 19:06:49,216] [Log ] [38 ] [DEBUG] - Controller: DoSetChannelStates for 1033 channels
[2016-01-28 19:06:49,223] [Log ] [38 ] [INFO ] - ChannelStates.GetAllTimeshiftingAndRecordingChannels took 0 msec
[2016-01-28 19:06:50,780] [Log ] [38 ] [INFO ] - ChannelStates.DoSetChannelStates took 1564 msec
[2016-01-28 19:06:53,100] [Log ] [38 ] [INFO ] - Not the time to fetch remote file yet
[2016-01-28 19:06:54,617] [Log ] [3 ] [INFO ] - Controller: TimeShiftingWouldUseCard TV3 HD 3505
[2016-01-28 19:06:54,621] [Log ] [3 ] [INFO ] - Controller: find free card for channel TV3 HD
[2016-01-28 19:06:54,624] [Log ] [3 ] [INFO ] - Controller: find card for channel TV3 HD
[2016-01-28 19:06:54,628] [Log ] [3 ] [INFO ] - Controller: got 1 tuning details for TV3 HD
[2016-01-28 19:06:54,632] [Log ] [3 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:54,636] [Log ] [3 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:06:54,639] [Log ] [3 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:06:54,642] [Log ] [3 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:06:54,646] [Log ] [3 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:06:54,655] [Log ] [3 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:06:54,660] [Log ] [3 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 35 msec
[2016-01-28 19:06:54,665] [Log ] [3 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:06:54,668] [Log ] [3 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:06:54,672] [Log ] [3 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 50 msec
[2016-01-28 19:06:54,712] [Log ] [3 ] [INFO ] - Controller: StartTimeShifting TV3 HD 3505
[2016-01-28 19:06:54,716] [Log ] [3 ] [INFO ] - Controller: epg stop
[2016-01-28 19:06:54,719] [Log ] [3 ] [INFO ] - Controller: find free card for channel TV3 HD
[2016-01-28 19:06:54,721] [Log ] [3 ] [INFO ] - Controller: find card for channel TV3 HD
[2016-01-28 19:06:54,725] [Log ] [3 ] [INFO ] - Controller: got 1 tuning details for TV3 HD
[2016-01-28 19:06:54,728] [Log ] [3 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:54,731] [Log ] [3 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:06:54,734] [Log ] [3 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:06:54,738] [Log ] [3 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:06:54,741] [Log ] [3 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:06:54,744] [Log ] [3 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 22 msec
[2016-01-28 19:06:54,746] [Log ] [3 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:06:54,749] [Log ] [3 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 30 msec
[2016-01-28 19:06:54,754] [Log ] [3 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=8, tuningdetails=DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:54,757] [Log ] [3 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:06:54,760] [Log ] [3 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:06:54,763] [Log ] [3 ] [INFO ] - Controller: try max 1 of 1 cards for timeshifting
[2016-01-28 19:06:54,766] [Log ] [3 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartZapChannel
[2016-01-28 19:06:54,769] [Log ] [3 ] [DEBUG] - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3505, ticket=8, tunestate=Tuning, stopstate=Idle
[2016-01-28 19:06:54,772] [Log ] [3 ] [INFO ] - card: CardTune 4 TV3 HD (S) Hometown:4:-1
[2016-01-28 19:06:54,775] [Log ] [3 ] [INFO ] - card: Tune on card 4 to subchannel TV3 HD (S)
[2016-01-28 19:06:54,778] [Log ] [3 ] [DEBUG] - card: user: Hometown:4:0 tune DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:54,786] [Log ] [3 ] [DEBUG] - card: to different transponder
[2016-01-28 19:06:54,789] [Log ] [3 ] [INFO ] - FreeSubChannel MD: freeing sub channel : 0
[2016-01-28 19:06:54,792] [Log ] [3 ] [INFO ] - mdplug: FreeChannel TV4 HD
[2016-01-28 19:06:54,795] [Log ] [3 ] [INFO ] - mdplug: usage counter for channel 'TV4 HD' is zero
[2016-01-28 19:06:54,798] [Log ] [3 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2016-01-28 19:06:54,801] [Log ] [3 ] [INFO ] - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
[2016-01-28 19:06:54,804] [Log ] [3 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2016-01-28 19:06:54,807] [Log ] [3 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:54,810] [Log ] [3 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:54,812] [Log ] [3 ] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2016-01-28 19:06:54,815] [Log ] [3 ] [INFO ] - dvbs:channel modulation is set to Mod8Psk
[2016-01-28 19:06:54,818] [Log ] [3 ] [INFO ] - dvbs:channel FECRate is set to Rate3_4
[2016-01-28 19:06:54,821] [Log ] [3 ] [DEBUG] - Turbosight: set tone state, burst = ToneBurst, 22 kHz = Off
[2016-01-28 19:06:54,826] [Log ] [3 ] [DEBUG] - Turbosight: burst result = success
[2016-01-28 19:06:54,830] [Log ] [3 ] [DEBUG] - Turbosight: 22 kHz result = success
[2016-01-28 19:06:54,833] [Log ] [3 ] [INFO ] - Turbosight: Set DVB-S2
[2016-01-28 19:06:54,936] [Log ] [3 ] [INFO ] - dvb:Submiting tunerequest Channel:TV3 HD (S) subChannel:0
[2016-01-28 19:06:54,940] [Log ] [3 ] [INFO ] - dvb:using existing subchannel:0
[2016-01-28 19:06:54,944] [Log ] [3 ] [INFO ] - dvb:Submit tunerequest size:1 new:0
[2016-01-28 19:06:54,948] [Log ] [3 ] [INFO ] - subch:0 OnBeforeTune
[2016-01-28 19:06:54,952] [Log ] [3 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest
[2016-01-28 19:06:55,144] [Log ] [3 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest
[2016-01-28 19:06:55,149] [Log ] [3 ] [INFO ] - subch:0 OnAfterTune
[2016-01-28 19:06:55,153] [Log ] [3 ] [INFO ] - RunGraph
[2016-01-28 19:06:55,157] [Log ] [3 ] [INFO ] - dvb: LockInOnSignal ok
[2016-01-28 19:06:55,161] [Log ] [3 ] [INFO ] - subch:0 OnGraphStart
[2016-01-28 19:06:55,165] [Log ] [3 ] [INFO ] - subch:0 Graph already running - WaitForPMT
[2016-01-28 19:06:55,169] [Log ] [3 ] [INFO ] - subch:0 SetupPmtGrabber:pid 18A sid:115E
[2016-01-28 19:06:55,173] [Log ] [3 ] [INFO ] - subch:0 set pmt grabber pmt:18A sid:115E
[2016-01-28 19:06:55,177] [Log ] [3 ] [INFO ] - subch:0 set ca grabber
[2016-01-28 19:06:55,181] [Log ] [3 ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2016-01-28 19:06:55,184] [Log ] [3 ] [DEBUG] - WaitForPMT: Waiting for PMT 18A
[2016-01-28 19:06:55,187] [Log ] [29 ] [INFO ] - subch:OnCaReceived()
[2016-01-28 19:06:55,346] [Log ] [29 ] [INFO ] - subch:0 OnPMTReceived() pmt:18A ran:True dynamic:False
[2016-01-28 19:06:55,350] [Log ] [3 ] [DEBUG] - WaitForPMT: Found PMT after 0,1660091 seconds.
[2016-01-28 19:06:55,354] [Log ] [3 ] [INFO ] - subch:0 SendPmt:CA found after 0 seconds
[2016-01-28 19:06:55,358] [Log ] [3 ] [INFO ] - subch:0 SendPmt:115E 115E FFFFFFFF 1C
[2016-01-28 19:06:55,362] [Log ] [3 ] [INFO ] - Decode pmt
[2016-01-28 19:06:55,366] [Log ] [3 ] [INFO ] - descr1 len:6 9 4 b 0 fb 76
[2016-01-28 19:06:55,370] [Log ] [3 ] [INFO ] - Set descriptor data with length 7
[2016-01-28 19:06:55,374] [Log ] [3 ] [INFO ] - Set descriptor data with length 6
[2016-01-28 19:06:55,378] [Log ] [3 ] [INFO ] - subch:0 SendPMT version:28 len:53 4446
[2016-01-28 19:06:55,382] [Log ] [3 ] [DEBUG] - Turbosight: send PMT to CAM, list action = Only, command = Descrambling
[2016-01-28 19:06:55,387] [Log ] [3 ] [DEBUG] - Turbosight: CAM not available
[2016-01-28 19:06:55,391] [Log ] [3 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:06:55,393] [Log ] [3 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:06:55,396] [Log ] [3 ] [INFO ] - subch:0 cam flags:False
[2016-01-28 19:06:55,399] [Log ] [3 ] [INFO ] - subch:0 SetMpegPidMapping
[2016-01-28 19:06:55,401] [Log ] [3 ] [INFO ] - subch:0 pid:819 pcr
[2016-01-28 19:06:55,404] [Log ] [3 ] [INFO ] - subch:0 pid:18A pmt
[2016-01-28 19:06:55,407] [Log ] [3 ] [INFO ] - subch:0 pid:18BD teletext type:6
[2016-01-28 19:06:55,410] [Log ] [3 ] [INFO ] - subch:0 map pid:18BD teletext type:6
[2016-01-28 19:06:55,412] [Log ] [3 ] [INFO ] - subch:0 pid:819 video type:H.264
[2016-01-28 19:06:55,415] [Log ] [3 ] [INFO ] - subch:0 map pid:819 video type:H.264
[2016-01-28 19:06:55,418] [Log ] [3 ] [INFO ] - subch:0 pid:D14 audio lang:swe type:AC3
[2016-01-28 19:06:55,421] [Log ] [3 ] [INFO ] - subch:0 map pid:D14 audio lang:swe type:AC3
[2016-01-28 19:06:55,423] [Log ] [3 ] [INFO ] - ecm len:6 9 4 B 0 FB 76
[2016-01-28 19:06:55,426] [Log ] [3 ] [INFO ] - emm len:6 9 4 B 0 E0 30
[2016-01-28 19:06:55,429] [Log ] [3 ] [INFO ] - Number of HWPIDS that needs to be sent to tuner :11
[2016-01-28 19:06:55,432] [Log ] [3 ] [INFO ] - mdplug: SetChannel nr of currently decoding channels 0.
[2016-01-28 19:06:55,434] [Log ] [3 ] [INFO ] - mdplug: SetChannel starting decryption on channel 'TV3 HD (S)' using plugin slot 1 of 1 avail.
[2016-01-28 19:06:55,437] [Log ] [3 ] [INFO ] - emm len:6 9 4 B 0 E0 30
[2016-01-28 19:06:55,440] [Log ] [3 ] klzzwxh:10000 - EMM #0 CA:0xB00 EMM:0x30 ID:0x0
klzzwxh:10001 klzzwxh:10002 klzzwxh:10003 klzzwxh:10004 - ecm len:6 9 4 B 0 FB 76
klzzwxh:10005 klzzwxh:10006 klzzwxh:10007 klzzwxh:10008 - ECM #0 CA:0xB00 ECM:0x1B76 ID:0x0
klzzwxh:10009 klzzwxh:10010 klzzwxh:10011 klzzwxh:10012 - mdplug: tp_id:24(0x18) sid:4446(0x115E) pmt_id:394(0x18A)
klzzwxh:10013 klzzwxh:10014 klzzwxh:10015 klzzwxh:10016 - mdplug: #0 CA_typ:2816(0xB00) ECM:7030(0x1B76) EMM:0x30 provider:0(0x0)
klzzwxh:10017 klzzwxh:10018 klzzwxh:10019 klzzwxh:10020 - mdplug: Send channel change to MDAPI filter Ca_Id:0 CA_Nr:1 ECM_PID:7030(0x1B76)
klzzwxh:10021 klzzwxh:10022 klzzwxh:10023 klzzwxh:10024 - subch:0 stop tif
klzzwxh:10025 klzzwxh:10026 klzzwxh:10027 klzzwxh:10028 - WaitForPmt: PMT handling took 0,1070063 seconds.
klzzwxh:10029 klzzwxh:10030 klzzwxh:10031 klzzwxh:10032 - card: Tuner locked: True
klzzwxh:10033 klzzwxh:10034 klzzwxh:10035 klzzwxh:10036 - klzzwxh:10043klzzwxh:10042klzzwxh:10041klzzwxh:10040klzzwxh:10039klzzwxh:10038klzzwxh:10037
[2016-01-28 19:06:55,478] [Log ] [3 ] [INFO ] - ** SIGNAL LEVEL: 94, SIGNAL QUALITY: 82
[2016-01-28 19:06:55,481] [Log ] [3 ] [INFO ] - *******
[2016-01-28 19:06:55,483] [Log ] [3 ] [DEBUG] - card: tuned user: Hometown subchannel: 0
[2016-01-28 19:06:55,486] [Log ] [3 ] [INFO ] - user:Hometown add
[2016-01-28 19:06:55,490] [Log ] [3 ] [INFO ] - card2:Hometown 4 0
[2016-01-28 19:06:55,494] [Log ] [3 ] [DEBUG] - Timeshifting started - Recordings=0 TimeShiftingActive=True
[2016-01-28 19:06:55,496] [Log ] [3 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartTimeShifting
[2016-01-28 19:06:55,499] [Log ] [3 ] [INFO ] - Controller: epg stop
[2016-01-28 19:06:55,502] [Log ] [3 ] [INFO ] - card: StartTimeShifting 4 C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:06:55,505] [Log ] [3 ] [INFO ] - card: CAM enabled : True
[2016-01-28 19:06:55,508] [Log ] [3 ] [INFO ] - card: WaitForFile - waiting _eventAudio & _eventVideo
[2016-01-28 19:06:56,064] [Log ] [29 ] [INFO ] - PID seen - type = Video
[2016-01-28 19:06:56,070] [Log ] [29 ] [INFO ] - audioVideoEventHandler Video
[2016-01-28 19:06:56,074] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:56
[2016-01-28 19:06:56,078] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:56
[2016-01-28 19:06:56,082] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:56
[2016-01-28 19:06:56,086] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:56
[2016-01-28 19:06:56,090] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:56
[2016-01-28 19:06:56,111] [Log ] [29 ] [INFO ] - PID seen - type = Audio
[2016-01-28 19:06:56,116] [Log ] [29 ] [INFO ] - audioVideoEventHandler Audio
[2016-01-28 19:06:56,120] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:56
[2016-01-28 19:06:56,124] [Log ] [3 ] [INFO ] - card: WaitForFile - video and audio are seen after 0,6120357 seconds
[2016-01-28 19:06:56,128] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:56
[2016-01-28 19:06:56,132] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:56
[2016-01-28 19:06:56,136] [Log ] [3 ] [INFO ] - Controller: StartTimeShifting started on card:4 to C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:06:56,140] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:56
[2016-01-28 19:06:56,143] [Log ] [3 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=8, tuningdetails=DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:06:56,146] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:56
[2016-01-28 19:06:56,148] [Log ] [3 ] [INFO ] - Controller: Hometown 4 0
[2016-01-28 19:06:56,152] [Log ] [3 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndZapChannel
[2016-01-28 19:06:56,155] [Log ] [3 ] [INFO ] - control2:Hometown 4 0
[2016-01-28 19:06:56,159] [Log ] [19 ] [DEBUG] - Controller: DoSetChannelStates for 1033 channels
[2016-01-28 19:06:56,165] [Log ] [19 ] [INFO ] - ChannelStates.GetAllTimeshiftingAndRecordingChannels took 0 msec
[2016-01-28 19:06:57,600] [Log ] [19 ] [INFO ] - ChannelStates.DoSetChannelStates took 1442 msec
[2016-01-28 19:07:00,026] [Log ] [3 ] [INFO ] - Controller: TimeShiftingWouldUseCard TV4 HD 3476
[2016-01-28 19:07:00,029] [Log ] [3 ] [INFO ] - Controller: find free card for channel TV4 HD
[2016-01-28 19:07:00,032] [Log ] [3 ] [INFO ] - Controller: find card for channel TV4 HD
[2016-01-28 19:07:00,042] [Log ] [3 ] [INFO ] - Controller: got 1 tuning details for TV4 HD
[2016-01-28 19:07:00,046] [Log ] [3 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:00,051] [Log ] [3 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:07:00,055] [Log ] [3 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:07:00,060] [Log ] [3 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:07:00,063] [Log ] [3 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:07:00,067] [Log ] [3 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:07:00,073] [Log ] [3 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 40 msec
[2016-01-28 19:07:00,086] [Log ] [3 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:07:00,090] [Log ] [3 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:07:00,093] [Log ] [3 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 63 msec
[2016-01-28 19:07:00,145] [Log ] [33 ] [INFO ] - Controller: StartTimeShifting TV4 HD 3476
[2016-01-28 19:07:00,148] [Log ] [33 ] [INFO ] - Controller: epg stop
[2016-01-28 19:07:00,151] [Log ] [33 ] [INFO ] - Controller: find free card for channel TV4 HD
[2016-01-28 19:07:00,154] [Log ] [33 ] [INFO ] - Controller: find card for channel TV4 HD
[2016-01-28 19:07:00,158] [Log ] [33 ] [INFO ] - Controller: got 1 tuning details for TV4 HD
[2016-01-28 19:07:00,161] [Log ] [33 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:00,164] [Log ] [33 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:07:00,167] [Log ] [33 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:07:00,170] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:07:00,173] [Log ] [33 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:07:00,176] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 22 msec
[2016-01-28 19:07:00,179] [Log ] [33 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:07:00,182] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 30 msec
[2016-01-28 19:07:00,187] [Log ] [33 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=9, tuningdetails=DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:00,190] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:07:00,193] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:07:00,196] [Log ] [33 ] [INFO ] - Controller: try max 1 of 1 cards for timeshifting
[2016-01-28 19:07:00,199] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartZapChannel
[2016-01-28 19:07:00,202] [Log ] [33 ] [DEBUG] - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3476, ticket=9, tunestate=Tuning, stopstate=Idle
[2016-01-28 19:07:00,205] [Log ] [33 ] [INFO ] - card: CardTune 4 TV4 HD Hometown:4:-1
[2016-01-28 19:07:00,208] [Log ] [33 ] [INFO ] - card: Tune on card 4 to subchannel TV4 HD
[2016-01-28 19:07:00,211] [Log ] [33 ] [DEBUG] - card: user: Hometown:4:0 tune DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:00,219] [Log ] [33 ] [DEBUG] - card: to different transponder
[2016-01-28 19:07:00,223] [Log ] [33 ] [INFO ] - FreeSubChannel MD: freeing sub channel : 0
[2016-01-28 19:07:00,225] [Log ] [33 ] [INFO ] - mdplug: FreeChannel TV3 HD (S)
[2016-01-28 19:07:00,228] [Log ] [33 ] [INFO ] - mdplug: usage counter for channel 'TV3 HD (S)' is zero
[2016-01-28 19:07:00,231] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2016-01-28 19:07:00,234] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
[2016-01-28 19:07:00,237] [Log ] [33 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2016-01-28 19:07:00,240] [Log ] [33 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:00,242] [Log ] [33 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:00,245] [Log ] [33 ] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2016-01-28 19:07:00,248] [Log ] [33 ] [INFO ] - dvbs:channel modulation is set to Mod8Psk
[2016-01-28 19:07:00,251] [Log ] [33 ] [INFO ] - dvbs:channel FECRate is set to Rate3_4
[2016-01-28 19:07:00,253] [Log ] [33 ] [DEBUG] - Turbosight: set tone state, burst = ToneBurst, 22 kHz = Off
[2016-01-28 19:07:00,258] [Log ] [33 ] [DEBUG] - Turbosight: burst result = success
[2016-01-28 19:07:00,262] [Log ] [33 ] [DEBUG] - Turbosight: 22 kHz result = success
[2016-01-28 19:07:00,265] [Log ] [33 ] [INFO ] - Turbosight: Set DVB-S2
[2016-01-28 19:07:00,369] [Log ] [33 ] [INFO ] - dvb:Submiting tunerequest Channel:TV4 HD subChannel:0
[2016-01-28 19:07:00,373] [Log ] [33 ] [INFO ] - dvb:using existing subchannel:0
[2016-01-28 19:07:00,377] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest size:1 new:0
[2016-01-28 19:07:00,381] [Log ] [33 ] [INFO ] - subch:0 OnBeforeTune
[2016-01-28 19:07:00,385] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest
[2016-01-28 19:07:00,577] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest
[2016-01-28 19:07:00,582] [Log ] [33 ] [INFO ] - subch:0 OnAfterTune
[2016-01-28 19:07:00,586] [Log ] [33 ] [INFO ] - RunGraph
[2016-01-28 19:07:00,591] [Log ] [33 ] [INFO ] - dvb: LockInOnSignal ok
[2016-01-28 19:07:00,595] [Log ] [33 ] [INFO ] - subch:0 OnGraphStart
[2016-01-28 19:07:00,599] [Log ] [33 ] [INFO ] - subch:0 Graph already running - WaitForPMT
[2016-01-28 19:07:00,603] [Log ] [33 ] [INFO ] - subch:0 SetupPmtGrabber:pid 4F sid:57D
[2016-01-28 19:07:00,607] [Log ] [33 ] [INFO ] - subch:0 set pmt grabber pmt:4F sid:57D
[2016-01-28 19:07:00,611] [Log ] [33 ] [INFO ] - subch:0 set ca grabber
[2016-01-28 19:07:00,613] [Log ] [33 ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2016-01-28 19:07:00,616] [Log ] [33 ] [DEBUG] - WaitForPMT: Waiting for PMT 4F
[2016-01-28 19:07:00,746] [Log ] [29 ] [INFO ] - subch:0 OnPMTReceived() pmt:4F ran:True dynamic:False
[2016-01-28 19:07:00,750] [Log ] [33 ] [DEBUG] - WaitForPMT: Found PMT after 0,1340076 seconds.
[2016-01-28 19:07:00,754] [Log ] [33 ] [INFO ] - subch:0 SendPmt:CA found after 0 seconds
[2016-01-28 19:07:00,758] [Log ] [33 ] [INFO ] - subch:0 SendPmt:57D 57D FFFFFFFF 14
[2016-01-28 19:07:00,762] [Log ] [33 ] [INFO ] - Decode pmt
[2016-01-28 19:07:00,767] [Log ] [33 ] [INFO ] - descr1 len:6 9 4 b 0 fb d0
[2016-01-28 19:07:00,771] [Log ] [33 ] [INFO ] - Set descriptor data with length 6
[2016-01-28 19:07:00,775] [Log ] [33 ] [INFO ] - Set descriptor data with length 7
[2016-01-28 19:07:00,779] [Log ] [33 ] [INFO ] - subch:0 SendPMT version:20 len:53 1405
[2016-01-28 19:07:00,783] [Log ] [33 ] [DEBUG] - Turbosight: send PMT to CAM, list action = Only, command = Descrambling
[2016-01-28 19:07:00,787] [Log ] [33 ] [DEBUG] - Turbosight: CAM not available
[2016-01-28 19:07:00,791] [Log ] [33 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:07:00,794] [Log ] [33 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:07:00,796] [Log ] [33 ] [INFO ] - subch:0 cam flags:False
[2016-01-28 19:07:00,799] [Log ] [33 ] [INFO ] - subch:0 SetMpegPidMapping
[2016-01-28 19:07:00,802] [Log ] [33 ] [INFO ] - subch:0 pid:417 pcr
[2016-01-28 19:07:00,805] [Log ] [33 ] [INFO ] - subch:0 pid:4F pmt
[2016-01-28 19:07:00,807] [Log ] [33 ] [INFO ] - subch:0 pid:417 video type:H.264
[2016-01-28 19:07:00,810] [Log ] [33 ] [INFO ] - subch:0 map pid:417 video type:H.264
[2016-01-28 19:07:00,813] [Log ] [33 ] [INFO ] - subch:0 pid:BE7 audio lang:swe type:AC3
[2016-01-28 19:07:00,816] [Log ] [33 ] [INFO ] - subch:0 map pid:BE7 audio lang:swe type:AC3
[2016-01-28 19:07:00,819] [Log ] [33 ] [INFO ] - subch:0 pid:179A teletext type:6
[2016-01-28 19:07:00,821] [Log ] [33 ] [INFO ] - subch:0 map pid:179A teletext type:6
[2016-01-28 19:07:00,824] [Log ] [33 ] [INFO ] - ecm len:6 9 4 B 0 FB D0
[2016-01-28 19:07:00,827] [Log ] [33 ] [INFO ] - emm len:6 9 4 B 0 E0 30
[2016-01-28 19:07:00,830] [Log ] [33 ] [INFO ] - Number of HWPIDS that needs to be sent to tuner :11
[2016-01-28 19:07:00,833] [Log ] [33 ] [INFO ] - mdplug: SetChannel nr of currently decoding channels 0.
[2016-01-28 19:07:00,836] [Log ] [33 ] [INFO ] - mdplug: SetChannel starting decryption on channel 'TV4 HD' using plugin slot 1 of 1 avail.
[2016-01-28 19:07:00,838] [Log ] [33 ] [INFO ] - emm len:6 9 4 B 0 E0 30
[2016-01-28 19:07:00,841] [Log ] [33 ] [INFO ] - EMM #0 CA:0xB00 EMM:0x30 ID:0x0
[2016-01-28 19:07:00,844] [Log ] [33 ] [INFO ] - ecm len:6 9 4 B 0 FB D0
[2016-01-28 19:07:00,847] [Log ] [33 ] [INFO ] - ECM #0 CA:0xB00 ECM:0x1BD0 ID:0x0
[2016-01-28 19:07:00,849] [Log ] [33 ] [INFO ] - mdplug: tp_id:14(0xE) sid:1405(0x57D) pmt_id:79(0x4F)
[2016-01-28 19:07:00,852] [Log ] [33 ] [INFO ] - mdplug: #0 CA_typ:2816(0xB00) ECM:7120(0x1BD0) EMM:0x30 provider:0(0x0)
[2016-01-28 19:07:00,856] [Log ] [33 ] [INFO ] - mdplug: Send channel change to MDAPI filter Ca_Id:0 CA_Nr:1 ECM_PID:7120(0x1BD0)
[2016-01-28 19:07:00,858] [Log ] [33 ] [INFO ] - subch:0 stop tif
[2016-01-28 19:07:00,861] [Log ] [33 ] [DEBUG] - WaitForPmt: PMT handling took 0,1070055 seconds.
[2016-01-28 19:07:00,870] [Log ] [33 ] [DEBUG] - card: Tuner locked: True
[2016-01-28 19:07:00,873] [Log ] [33 ] [INFO ] - *******
[2016-01-28 19:07:00,875] [Log ] [33 ] [INFO ] - ** SIGNAL LEVEL: 95, SIGNAL QUALITY: 83
[2016-01-28 19:07:00,878] [Log ] [33 ] [INFO ] - *******
[2016-01-28 19:07:00,881] [Log ] [33 ] [DEBUG] - card: tuned user: Hometown subchannel: 0
[2016-01-28 19:07:00,883] [Log ] [33 ] [INFO ] - user:Hometown add
[2016-01-28 19:07:00,887] [Log ] [33 ] [INFO ] - card2:Hometown 4 0
[2016-01-28 19:07:00,891] [Log ] [33 ] [DEBUG] - Timeshifting started - Recordings=0 TimeShiftingActive=True
[2016-01-28 19:07:00,894] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartTimeShifting
[2016-01-28 19:07:00,897] [Log ] [33 ] [INFO ] - Controller: epg stop
[2016-01-28 19:07:00,901] [Log ] [33 ] [INFO ] - card: StartTimeShifting 4 C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:07:00,904] [Log ] [33 ] [INFO ] - card: CAM enabled : True
[2016-01-28 19:07:00,907] [Log ] [33 ] [INFO ] - card: WaitForFile - waiting _eventAudio & _eventVideo
[2016-01-28 19:07:01,483] [Log ] [29 ] [INFO ] - PID seen - type = Video
[2016-01-28 19:07:01,488] [Log ] [29 ] [INFO ] - audioVideoEventHandler Video
[2016-01-28 19:07:01,492] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:01
[2016-01-28 19:07:01,496] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:01
[2016-01-28 19:07:01,500] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:01
[2016-01-28 19:07:01,504] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:01
[2016-01-28 19:07:01,508] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:01
[2016-01-28 19:07:01,587] [Log ] [29 ] [INFO ] - PID seen - type = Audio
[2016-01-28 19:07:01,591] [Log ] [29 ] [INFO ] - audioVideoEventHandler Audio
[2016-01-28 19:07:01,595] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:01
[2016-01-28 19:07:01,599] [Log ] [33 ] [INFO ] - card: WaitForFile - video and audio are seen after 0,6880404 seconds
[2016-01-28 19:07:01,603] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:01
[2016-01-28 19:07:01,607] [Log ] [33 ] [INFO ] - Controller: StartTimeShifting started on card:4 to C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:07:01,611] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:01
[2016-01-28 19:07:01,615] [Log ] [33 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=9, tuningdetails=DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:01,619] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:01
[2016-01-28 19:07:01,623] [Log ] [33 ] [INFO ] - Controller: Hometown 4 0
[2016-01-28 19:07:01,627] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:01
[2016-01-28 19:07:01,631] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndZapChannel
[2016-01-28 19:07:01,634] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:01
[2016-01-28 19:07:01,636] [Log ] [33 ] [INFO ] - control2:Hometown 4 0
[2016-01-28 19:07:01,641] [Log ] [19 ] [DEBUG] - Controller: DoSetChannelStates for 1033 channels
[2016-01-28 19:07:01,647] [Log ] [19 ] [INFO ] - ChannelStates.GetAllTimeshiftingAndRecordingChannels took 0 msec
[2016-01-28 19:07:03,133] [Log ] [19 ] [INFO ] - ChannelStates.DoSetChannelStates took 1492 msec
[2016-01-28 19:07:05,453] [Log ] [33 ] [INFO ] - Controller: TimeShiftingWouldUseCard Kanal 5 HD 3099
[2016-01-28 19:07:05,457] [Log ] [33 ] [INFO ] - Controller: find free card for channel Kanal 5 HD
[2016-01-28 19:07:05,464] [Log ] [33 ] [INFO ] - Controller: find card for channel Kanal 5 HD
[2016-01-28 19:07:05,472] [Log ] [33 ] [INFO ] - Controller: got 1 tuning details for Kanal 5 HD
[2016-01-28 19:07:05,477] [Log ] [33 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:05,480] [Log ] [33 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:07:05,483] [Log ] [33 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:07:05,487] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:07:05,492] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:07:05,498] [Log ] [33 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:07:05,502] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 38 msec
[2016-01-28 19:07:05,512] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:07:05,515] [Log ] [33 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:07:05,518] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 61 msec
[2016-01-28 19:07:05,547] [Log ] [3 ] [INFO ] - Controller: StartTimeShifting Kanal 5 HD 3099
[2016-01-28 19:07:05,551] [Log ] [3 ] [INFO ] - Controller: epg stop
[2016-01-28 19:07:05,554] [Log ] [3 ] [INFO ] - Controller: find free card for channel Kanal 5 HD
[2016-01-28 19:07:05,556] [Log ] [3 ] [INFO ] - Controller: find card for channel Kanal 5 HD
[2016-01-28 19:07:05,560] [Log ] [3 ] [INFO ] - Controller: got 1 tuning details for Kanal 5 HD
[2016-01-28 19:07:05,563] [Log ] [3 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:05,566] [Log ] [3 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:07:05,568] [Log ] [3 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:07:05,572] [Log ] [3 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:07:05,575] [Log ] [3 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:07:05,577] [Log ] [3 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 21 msec
[2016-01-28 19:07:05,580] [Log ] [3 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:07:05,583] [Log ] [3 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 29 msec
[2016-01-28 19:07:05,588] [Log ] [3 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=10, tuningdetails=DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:05,591] [Log ] [3 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:07:05,593] [Log ] [3 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:07:05,596] [Log ] [3 ] [INFO ] - Controller: try max 1 of 1 cards for timeshifting
[2016-01-28 19:07:05,599] [Log ] [3 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartZapChannel
[2016-01-28 19:07:05,602] [Log ] [3 ] [DEBUG] - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3099, ticket=10, tunestate=Tuning, stopstate=Idle
[2016-01-28 19:07:05,605] [Log ] [3 ] [INFO ] - card: CardTune 4 Kanal 5 HD (S) Hometown:4:-1
[2016-01-28 19:07:05,608] [Log ] [3 ] [INFO ] - card: Tune on card 4 to subchannel Kanal 5 HD (S)
[2016-01-28 19:07:05,611] [Log ] [3 ] [DEBUG] - card: user: Hometown:4:0 tune DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:05,619] [Log ] [3 ] [DEBUG] - card: to different transponder
[2016-01-28 19:07:05,622] [Log ] [3 ] [INFO ] - FreeSubChannel MD: freeing sub channel : 0
[2016-01-28 19:07:05,625] [Log ] [3 ] [INFO ] - mdplug: FreeChannel TV4 HD
[2016-01-28 19:07:05,628] [Log ] [3 ] [INFO ] - mdplug: usage counter for channel 'TV4 HD' is zero
[2016-01-28 19:07:05,630] [Log ] [3 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2016-01-28 19:07:05,633] [Log ] [3 ] [INFO ] - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
[2016-01-28 19:07:05,636] [Log ] [3 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2016-01-28 19:07:05,639] [Log ] [3 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:05,641] [Log ] [3 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:05,644] [Log ] [3 ] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2016-01-28 19:07:05,647] [Log ] [3 ] [INFO ] - dvbs:channel modulation is set to Mod8Psk
[2016-01-28 19:07:05,650] [Log ] [3 ] [INFO ] - dvbs:channel FECRate is set to Rate3_4
[2016-01-28 19:07:05,652] [Log ] [3 ] [DEBUG] - Turbosight: set tone state, burst = ToneBurst, 22 kHz = Off
[2016-01-28 19:07:05,657] [Log ] [3 ] [DEBUG] - Turbosight: burst result = success
[2016-01-28 19:07:05,661] [Log ] [3 ] [DEBUG] - Turbosight: 22 kHz result = success
[2016-01-28 19:07:05,664] [Log ] [3 ] [INFO ] - Turbosight: Set DVB-S2
[2016-01-28 19:07:05,768] [Log ] [3 ] [INFO ] - dvb:Submiting tunerequest Channel:Kanal 5 HD (S) subChannel:0
[2016-01-28 19:07:05,772] [Log ] [3 ] [INFO ] - dvb:using existing subchannel:0
[2016-01-28 19:07:05,776] [Log ] [3 ] [INFO ] - dvb:Submit tunerequest size:1 new:0
[2016-01-28 19:07:05,780] [Log ] [3 ] [INFO ] - subch:0 OnBeforeTune
[2016-01-28 19:07:05,784] [Log ] [3 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest
[2016-01-28 19:07:05,976] [Log ] [3 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest
[2016-01-28 19:07:05,981] [Log ] [3 ] [INFO ] - subch:0 OnAfterTune
[2016-01-28 19:07:05,985] [Log ] [3 ] [INFO ] - RunGraph
[2016-01-28 19:07:05,989] [Log ] [3 ] [INFO ] - dvb: LockInOnSignal ok
[2016-01-28 19:07:05,993] [Log ] [3 ] [INFO ] - subch:0 OnGraphStart
[2016-01-28 19:07:05,997] [Log ] [3 ] [INFO ] - subch:0 Graph already running - WaitForPMT
[2016-01-28 19:07:06,001] [Log ] [3 ] [INFO ] - subch:0 SetupPmtGrabber:pid 132 sid:1A91
[2016-01-28 19:07:06,006] [Log ] [3 ] [INFO ] - subch:0 set pmt grabber pmt:132 sid:1A91
[2016-01-28 19:07:06,010] [Log ] [3 ] [INFO ] - subch:0 set ca grabber
[2016-01-28 19:07:06,013] [Log ] [3 ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2016-01-28 19:07:06,015] [Log ] [3 ] [DEBUG] - WaitForPMT: Waiting for PMT 132
[2016-01-28 19:07:06,127] [Log ] [29 ] [INFO ] - subch:0 OnPMTReceived() pmt:132 ran:True dynamic:False
[2016-01-28 19:07:06,131] [Log ] [3 ] [DEBUG] - WaitForPMT: Found PMT after 0,1160079 seconds.
[2016-01-28 19:07:06,135] [Log ] [3 ] [INFO ] - subch:0 SendPmt:CA found after 0 seconds
[2016-01-28 19:07:06,139] [Log ] [3 ] [INFO ] - subch:0 SendPmt:1A91 1A91 FFFFFFFF 12
[2016-01-28 19:07:06,143] [Log ] [3 ] [INFO ] - Decode pmt
[2016-01-28 19:07:06,147] [Log ] [3 ] [INFO ] - descr1 len:6 9 4 b 0 fb c0
[2016-01-28 19:07:06,151] [Log ] [3 ] [INFO ] - Set descriptor data with length 6
[2016-01-28 19:07:06,155] [Log ] [3 ] [INFO ] - Set descriptor data with length 7
[2016-01-28 19:07:06,159] [Log ] [3 ] [INFO ] - subch:0 SendPMT version:18 len:50 6801
[2016-01-28 19:07:06,162] [Log ] [3 ] [DEBUG] - Turbosight: send PMT to CAM, list action = Only, command = Descrambling
[2016-01-28 19:07:06,165] [Log ] [3 ] [DEBUG] - Turbosight: CAM not available
[2016-01-28 19:07:06,168] [Log ] [3 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:07:06,170] [Log ] [3 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:07:06,173] [Log ] [3 ] [INFO ] - subch:0 cam flags:False
[2016-01-28 19:07:06,176] [Log ] [3 ] [INFO ] - subch:0 SetMpegPidMapping
[2016-01-28 19:07:06,178] [Log ] [3 ] [INFO ] - subch:0 pid:4E7 pcr
[2016-01-28 19:07:06,181] [Log ] [3 ] [INFO ] - subch:0 pid:132 pmt
[2016-01-28 19:07:06,184] [Log ] [3 ] [INFO ] - subch:0 pid:4E7 video type:H.264
[2016-01-28 19:07:06,186] [Log ] [3 ] [INFO ] - subch:0 map pid:4E7 video type:H.264
[2016-01-28 19:07:06,189] [Log ] [3 ] [INFO ] - subch:0 pid:CB7 audio lang:swe type:MPEG-2
[2016-01-28 19:07:06,192] [Log ] [3 ] [INFO ] - subch:0 map pid:CB7 audio lang:swe type:MPEG-2
[2016-01-28 19:07:06,194] [Log ] [3 ] [INFO ] - subch:0 pid:18A6 teletext type:6
[2016-01-28 19:07:06,197] [Log ] [3 ] [INFO ] - subch:0 map pid:18A6 teletext type:6
[2016-01-28 19:07:06,200] [Log ] [3 ] [INFO ] - ecm len:6 9 4 B 0 FB C0
[2016-01-28 19:07:06,203] [Log ] [3 ] [INFO ] - emm len:6 9 4 B 0 E0 30
[2016-01-28 19:07:06,205] [Log ] [3 ] [INFO ] - Number of HWPIDS that needs to be sent to tuner :11
[2016-01-28 19:07:06,208] [Log ] [3 ] [INFO ] - mdplug: SetChannel nr of currently decoding channels 0.
[2016-01-28 19:07:06,211] [Log ] [3 ] [INFO ] - mdplug: SetChannel starting decryption on channel 'Kanal 5 HD (S)' using plugin slot 1 of 1 avail.
[2016-01-28 19:07:06,214] [Log ] [3 ] [INFO ] - emm len:6 9 4 B 0 E0 30
[2016-01-28 19:07:06,217] [Log ] [3 ] [INFO ] - EMM #0 CA:0xB00 EMM:0x30 ID:0x0
[2016-01-28 19:07:06,219] [Log ] [3 ] [INFO ] - ecm len:6 9 4 B 0 FB C0
[2016-01-28 19:07:06,222] [Log ] [3 ] [INFO ] - ECM #0 CA:0xB00 ECM:0x1BC0 ID:0x0
[2016-01-28 19:07:06,225] [Log ] [3 ] [INFO ] - mdplug: tp_id:67(0x43) sid:6801(0x1A91) pmt_id:306(0x132)
[2016-01-28 19:07:06,227] [Log ] [3 ] [INFO ] - mdplug: #0 CA_typ:2816(0xB00) ECM:7104(0x1BC0) EMM:0x30 provider:0(0x0)
[2016-01-28 19:07:06,231] [Log ] [3 ] [INFO ] - mdplug: Send channel change to MDAPI filter Ca_Id:0 CA_Nr:1 ECM_PID:7104(0x1BC0)
[2016-01-28 19:07:06,234] [Log ] [3 ] [INFO ] - subch:0 stop tif
[2016-01-28 19:07:06,237] [Log ] [3 ] [DEBUG] - WaitForPmt: PMT handling took 0,1020054 seconds.
[2016-01-28 19:07:06,239] [Log ] [29 ] [INFO ] - subch:OnCaReceived()
[2016-01-28 19:07:06,245] [Log ] [3 ] [DEBUG] - card: Tuner locked: True
[2016-01-28 19:07:06,248] [Log ] [3 ] [INFO ] - *******
[2016-01-28 19:07:06,251] [Log ] [3 ] [INFO ] - ** SIGNAL LEVEL: 95, SIGNAL QUALITY: 82
[2016-01-28 19:07:06,253] [Log ] [3 ] [INFO ] - *******
[2016-01-28 19:07:06,256] [Log ] [3 ] [DEBUG] - card: tuned user: Hometown subchannel: 0
[2016-01-28 19:07:06,259] [Log ] [3 ] [INFO ] - user:Hometown add
[2016-01-28 19:07:06,263] [Log ] [3 ] [INFO ] - card2:Hometown 4 0
[2016-01-28 19:07:06,266] [Log ] [3 ] [DEBUG] - Timeshifting started - Recordings=0 TimeShiftingActive=True
[2016-01-28 19:07:06,269] [Log ] [3 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartTimeShifting
[2016-01-28 19:07:06,272] [Log ] [3 ] [INFO ] - Controller: epg stop
[2016-01-28 19:07:06,275] [Log ] [3 ] [INFO ] - card: StartTimeShifting 4 C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:07:06,278] [Log ] [3 ] [INFO ] - card: CAM enabled : True
[2016-01-28 19:07:06,281] [Log ] [3 ] [INFO ] - card: WaitForFile - waiting _eventAudio & _eventVideo
[2016-01-28 19:07:06,940] [Log ] [29 ] [INFO ] - PID seen - type = Video
[2016-01-28 19:07:06,944] [Log ] [29 ] [INFO ] - audioVideoEventHandler Video
[2016-01-28 19:07:06,948] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:06
[2016-01-28 19:07:06,952] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:06
[2016-01-28 19:07:06,956] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:06
[2016-01-28 19:07:06,960] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:06
[2016-01-28 19:07:06,964] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:06
[2016-01-28 19:07:07,044] [Log ] [29 ] [INFO ] - PID seen - type = Audio
[2016-01-28 19:07:07,048] [Log ] [29 ] [INFO ] - audioVideoEventHandler Audio
[2016-01-28 19:07:07,052] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:07
[2016-01-28 19:07:07,056] [Log ] [3 ] [INFO ] - card: WaitForFile - video and audio are seen after 0,7710441 seconds
[2016-01-28 19:07:07,060] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:07
[2016-01-28 19:07:07,064] [Log ] [3 ] [INFO ] - Controller: StartTimeShifting started on card:4 to C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:07:07,068] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:07
[2016-01-28 19:07:07,072] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:07
[2016-01-28 19:07:07,076] [Log ] [3 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=10, tuningdetails=DVBS:tv:Telenor Kanal 5 HD (S) Freq:10778000 ONID:70 TSID:67 SID:6801 PMT:0x132 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:07,080] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:07
[2016-01-28 19:07:07,084] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:07
[2016-01-28 19:07:07,088] [Log ] [3 ] [INFO ] - Controller: Hometown 4 0
[2016-01-28 19:07:07,091] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:07
[2016-01-28 19:07:07,094] [Log ] [3 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndZapChannel
[2016-01-28 19:07:07,097] [Log ] [3 ] [INFO ] - control2:Hometown 4 0
[2016-01-28 19:07:07,102] [Log ] [38 ] [DEBUG] - Controller: DoSetChannelStates for 1033 channels
[2016-01-28 19:07:07,109] [Log ] [38 ] [INFO ] - ChannelStates.GetAllTimeshiftingAndRecordingChannels took 0 msec
[2016-01-28 19:07:08,656] [Log ] [38 ] [INFO ] - ChannelStates.DoSetChannelStates took 1553 msec
[2016-01-28 19:07:11,596] [Log ] [33 ] [INFO ] - Controller: TimeShiftingWouldUseCard TV6 3086
[2016-01-28 19:07:11,599] [Log ] [33 ] [INFO ] - Controller: find free card for channel TV6
[2016-01-28 19:07:11,602] [Log ] [33 ] [INFO ] - Controller: find card for channel TV6
[2016-01-28 19:07:11,606] [Log ] [33 ] [INFO ] - Controller: got 1 tuning details for TV6
[2016-01-28 19:07:11,609] [Log ] [33 ] [INFO ] - Controller: channel #1 DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
[2016-01-28 19:07:11,616] [Log ] [33 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:07:11,621] [Log ] [33 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:07:11,629] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:07:11,634] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:07:11,637] [Log ] [33 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:07:11,640] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 38 msec
[2016-01-28 19:07:11,643] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:07:11,650] [Log ] [33 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:07:11,655] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 55 msec
[2016-01-28 19:07:11,682] [Log ] [33 ] [INFO ] - Controller: StartTimeShifting TV6 3086
[2016-01-28 19:07:11,685] [Log ] [33 ] [INFO ] - Controller: epg stop
[2016-01-28 19:07:11,688] [Log ] [33 ] [INFO ] - Controller: find free card for channel TV6
[2016-01-28 19:07:11,691] [Log ] [33 ] [INFO ] - Controller: find card for channel TV6
[2016-01-28 19:07:11,694] [Log ] [33 ] [INFO ] - Controller: got 1 tuning details for TV6
[2016-01-28 19:07:11,698] [Log ] [33 ] [INFO ] - Controller: channel #1 DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
[2016-01-28 19:07:11,701] [Log ] [33 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:07:11,704] [Log ] [33 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:07:11,707] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:07:11,710] [Log ] [33 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:07:11,713] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 22 msec
[2016-01-28 19:07:11,716] [Log ] [33 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:07:11,719] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 31 msec
[2016-01-28 19:07:11,724] [Log ] [33 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=11, tuningdetails=DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
[2016-01-28 19:07:11,727] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:07:11,731] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:07:11,734] [Log ] [33 ] [INFO ] - Controller: try max 1 of 1 cards for timeshifting
[2016-01-28 19:07:11,737] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartZapChannel
[2016-01-28 19:07:11,740] [Log ] [33 ] [DEBUG] - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3086, ticket=11, tunestate=Tuning, stopstate=Idle
[2016-01-28 19:07:11,744] [Log ] [33 ] [INFO ] - card: CardTune 4 TV6 Hometown:4:-1
[2016-01-28 19:07:11,747] [Log ] [33 ] [INFO ] - card: Tune on card 4 to subchannel TV6
[2016-01-28 19:07:11,750] [Log ] [33 ] [DEBUG] - card: user: Hometown:4:0 tune DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
[2016-01-28 19:07:11,758] [Log ] [33 ] [DEBUG] - card: to different transponder
[2016-01-28 19:07:11,761] [Log ] [33 ] [INFO ] - FreeSubChannel MD: freeing sub channel : 0
[2016-01-28 19:07:11,764] [Log ] [33 ] [INFO ] - mdplug: FreeChannel Kanal 5 HD (S)
[2016-01-28 19:07:11,767] [Log ] [33 ] [INFO ] - mdplug: usage counter for channel 'Kanal 5 HD (S)' is zero
[2016-01-28 19:07:11,770] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2016-01-28 19:07:11,773] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
[2016-01-28 19:07:11,776] [Log ] [33 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2016-01-28 19:07:11,778] [Log ] [33 ] [INFO ] - dvbs: Tune:DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
[2016-01-28 19:07:11,781] [Log ] [33 ] [INFO ] - dvbs: Tune:DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
[2016-01-28 19:07:11,784] [Log ] [33 ] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2016-01-28 19:07:11,787] [Log ] [33 ] [INFO ] - dvbs:channel modulation is set to ModQpsk
[2016-01-28 19:07:11,790] [Log ] [33 ] [INFO ] - dvbs:channel FECRate is set to Rate3_4
[2016-01-28 19:07:11,793] [Log ] [33 ] [DEBUG] - Turbosight: set tone state, burst = DataBurst, 22 kHz = On
[2016-01-28 19:07:11,797] [Log ] [33 ] [DEBUG] - Turbosight: burst result = success
[2016-01-28 19:07:11,801] [Log ] [33 ] [DEBUG] - Turbosight: 22 kHz result = success
[2016-01-28 19:07:11,804] [Log ] [33 ] [INFO ] - Turbosight: Set DVB-S2
[2016-01-28 19:07:11,908] [Log ] [33 ] [INFO ] - dvb:Submiting tunerequest Channel:TV6 subChannel:0
[2016-01-28 19:07:11,912] [Log ] [33 ] [INFO ] - dvb:using existing subchannel:0
[2016-01-28 19:07:11,916] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest size:1 new:0
[2016-01-28 19:07:11,920] [Log ] [33 ] [INFO ] - subch:0 OnBeforeTune
[2016-01-28 19:07:11,924] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest
[2016-01-28 19:07:12,116] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest
[2016-01-28 19:07:12,121] [Log ] [33 ] [INFO ] - subch:0 OnAfterTune
[2016-01-28 19:07:12,125] [Log ] [33 ] [INFO ] - RunGraph
[2016-01-28 19:07:12,129] [Log ] [33 ] [INFO ] - dvb: LockInOnSignal ok
[2016-01-28 19:07:12,133] [Log ] [33 ] [INFO ] - subch:0 OnGraphStart
[2016-01-28 19:07:12,137] [Log ] [33 ] [INFO ] - subch:0 Graph already running - WaitForPMT
[2016-01-28 19:07:12,141] [Log ] [33 ] [INFO ] - subch:0 SetupPmtGrabber:pid 488 sid:488
[2016-01-28 19:07:12,145] [Log ] [33 ] [INFO ] - subch:0 set pmt grabber pmt:488 sid:488
[2016-01-28 19:07:12,149] [Log ] [33 ] [INFO ] - subch:0 set ca grabber
[2016-01-28 19:07:12,153] [Log ] [33 ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2016-01-28 19:07:12,157] [Log ] [33 ] [DEBUG] - WaitForPMT: Waiting for PMT 488
[2016-01-28 19:07:12,199] [Log ] [29 ] [INFO ] - subch:OnCaReceived()
[2016-01-28 19:07:12,227] [Log ] [29 ] [INFO ] - subch:0 OnPMTReceived() pmt:488 ran:True dynamic:False
[2016-01-28 19:07:12,231] [Log ] [33 ] [DEBUG] - WaitForPMT: Found PMT after 0,0740044 seconds.
[2016-01-28 19:07:12,235] [Log ] [33 ] [INFO ] - subch:0 SendPmt:CA found after 0 seconds
[2016-01-28 19:07:12,239] [Log ] [33 ] [INFO ] - subch:0 SendPmt:488 488 FFFFFFFF 11
[2016-01-28 19:07:12,243] [Log ] [33 ] [INFO ] - Decode pmt
[2016-01-28 19:07:12,247] [Log ] [33 ] [INFO ] - descr2 pid:489 len:6 9 4 9 f e4 8d
[2016-01-28 19:07:12,251] [Log ] [33 ] [INFO ] - descr2 pid:489 len:6 9 4 9 3e e0 98
[2016-01-28 19:07:12,255] [Log ] [33 ] [INFO ] - descr2 pid:489 len:6 9 4 9 40 e1 92
[2016-01-28 19:07:12,259] [Log ] [33 ] [INFO ] - Set descriptor data with length 7
[2016-01-28 19:07:12,263] [Log ] [33 ] [INFO ] - Set descriptor data with length 6
[2016-01-28 19:07:12,267] [Log ] [33 ] [INFO ] - descr2 pid:48A len:6 9 4 9 f e4 8d
[2016-01-28 19:07:12,271] [Log ] [33 ] [INFO ] - descr2 pid:48A len:6 9 4 9 3e e0 98
[2016-01-28 19:07:12,275] [Log ] [33 ] [INFO ] - descr2 pid:48A len:6 9 4 9 40 e1 92
[2016-01-28 19:07:12,279] [Log ] [33 ] [INFO ] - Set descriptor data with length 6
[2016-01-28 19:07:12,283] [Log ] [33 ] [INFO ] - descr2 pid:48B len:6 9 4 9 f e4 8d
[2016-01-28 19:07:12,287] [Log ] [33 ] [INFO ] - descr2 pid:48B len:6 9 4 9 3e e0 98
[2016-01-28 19:07:12,291] [Log ] [33 ] [INFO ] - descr2 pid:48B len:6 9 4 9 40 e1 92
[2016-01-28 19:07:12,295] [Log ] [33 ] [INFO ] - subch:0 SendPMT version:17 len:109 1160
[2016-01-28 19:07:12,299] [Log ] [33 ] [DEBUG] - Turbosight: send PMT to CAM, list action = Only, command = Descrambling
[2016-01-28 19:07:12,303] [Log ] [33 ] [DEBUG] - Turbosight: CAM not available
[2016-01-28 19:07:12,307] [Log ] [33 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:07:12,311] [Log ] [33 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:07:12,314] [Log ] [33 ] [INFO ] - subch:0 cam flags:False
[2016-01-28 19:07:12,316] [Log ] [33 ] [INFO ] - subch:0 SetMpegPidMapping
[2016-01-28 19:07:12,319] [Log ] [33 ] [INFO ] - subch:0 pid:489 pcr
[2016-01-28 19:07:12,322] [Log ] [33 ] [INFO ] - subch:0 pid:488 pmt
[2016-01-28 19:07:12,325] [Log ] [33 ] [INFO ] - subch:0 pid:489 video type:MPEG-2
[2016-01-28 19:07:12,327] [Log ] [33 ] [INFO ] - subch:0 map pid:489 video type:MPEG-2
[2016-01-28 19:07:12,330] [Log ] [33 ] [INFO ] - subch:0 pid:48E teletext type:6
[2016-01-28 19:07:12,333] [Log ] [33 ] [INFO ] - subch:0 map pid:48E teletext type:6
[2016-01-28 19:07:12,335] [Log ] [33 ] [INFO ] - subch:0 pid:48A audio lang:swe type:MPEG-1
[2016-01-28 19:07:12,338] [Log ] [33 ] [INFO ] - subch:0 map pid:48A audio lang:swe type:MPEG-1
[2016-01-28 19:07:12,341] [Log ] [33 ] [INFO ] - subch:0 pid:48B audio lang:syn type:MPEG-1
[2016-01-28 19:07:12,344] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 F E4 8D
[2016-01-28 19:07:12,346] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 3E E0 98
[2016-01-28 19:07:12,349] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 40 E1 92
[2016-01-28 19:07:12,352] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 F E4 8D
[2016-01-28 19:07:12,355] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 3E E0 98
[2016-01-28 19:07:12,357] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 40 E1 92
[2016-01-28 19:07:12,360] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 F E4 8D
[2016-01-28 19:07:12,363] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 3E E0 98
[2016-01-28 19:07:12,366] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 40 E1 92
[2016-01-28 19:07:12,368] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 F E0 C0
[2016-01-28 19:07:12,371] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 3E E0 C1
[2016-01-28 19:07:12,374] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 40 E0 C2
[2016-01-28 19:07:12,377] [Log ] [33 ] [INFO ] - Number of HWPIDS that needs to be sent to tuner :16
[2016-01-28 19:07:12,380] [Log ] [33 ] [INFO ] - mdplug: SetChannel nr of currently decoding channels 0.
[2016-01-28 19:07:12,382] [Log ] [33 ] [INFO ] - mdplug: SetChannel starting decryption on channel 'TV6' using plugin slot 1 of 1 avail.
[2016-01-28 19:07:12,385] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 F E0 C0
[2016-01-28 19:07:12,388] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 3E E0 C1
[2016-01-28 19:07:12,391] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 40 E0 C2
[2016-01-28 19:07:12,393] [Log ] [33 ] [INFO ] - EMM #0 CA:0x90F EMM:0xC0 ID:0x0
[2016-01-28 19:07:12,396] [Log ] [33 ] [INFO ] - EMM #1 CA:0x93E EMM:0xC1 ID:0x0
[2016-01-28 19:07:12,399] [Log ] [33 ] [INFO ] - EMM #2 CA:0x940 EMM:0xC2 ID:0x0
[2016-01-28 19:07:12,401] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 F E4 8D
[2016-01-28 19:07:12,404] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 3E E0 98
[2016-01-28 19:07:12,407] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 40 E1 92
[2016-01-28 19:07:12,410] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 F E4 8D
[2016-01-28 19:07:12,412] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 3E E0 98
[2016-01-28 19:07:12,415] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 40 E1 92
[2016-01-28 19:07:12,418] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 F E4 8D
[2016-01-28 19:07:12,421] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 3E E0 98
[2016-01-28 19:07:12,423] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 40 E1 92
[2016-01-28 19:07:12,426] [Log ] [33 ] [INFO ] - ECM #0 CA:0x90F ECM:0x48D ID:0x0
[2016-01-28 19:07:12,429] [Log ] [33 ] [INFO ] - ECM #1 CA:0x93E ECM:0x98 ID:0x0
[2016-01-28 19:07:12,432] [Log ] [33 ] [INFO ] - ECM #2 CA:0x940 ECM:0x192 ID:0x0
[2016-01-28 19:07:12,435] [Log ] [33 ] [INFO ] - mdplug: tp_id:3(0x3) sid:1160(0x488) pmt_id:1160(0x488)
[2016-01-28 19:07:12,437] [Log ] [33 ] [INFO ] - mdplug: #0 CA_typ:2319(0x90F) ECM:1165(0x48D) EMM:0xC0 provider:0(0x0)
[2016-01-28 19:07:12,440] [Log ] [33 ] [INFO ] - mdplug: #1 CA_typ:2366(0x93E) ECM:152(0x98) EMM:0xC1 provider:0(0x0)
[2016-01-28 19:07:12,443] [Log ] [33 ] [INFO ] - mdplug: #2 CA_typ:2368(0x940) ECM:402(0x192) EMM:0xC2 provider:0(0x0)
[2016-01-28 19:07:12,446] [Log ] [33 ] [INFO ] - mdplug: Send channel change to MDAPI filter Ca_Id:0 CA_Nr:3 ECM_PID:1165(0x48D)
[2016-01-28 19:07:12,449] [Log ] [33 ] [INFO ] - subch:0 stop tif
[2016-01-28 19:07:12,452] [Log ] [33 ] [DEBUG] - WaitForPmt: PMT handling took 0,2170126 seconds.
[2016-01-28 19:07:12,460] [Log ] [33 ] [DEBUG] - card: Tuner locked: True
[2016-01-28 19:07:12,464] [Log ] [33 ] [INFO ] - *******
[2016-01-28 19:07:12,466] [Log ] [33 ] [INFO ] - ** SIGNAL LEVEL: 94, SIGNAL QUALITY: 80
[2016-01-28 19:07:12,469] [Log ] [33 ] [INFO ] - *******
[2016-01-28 19:07:12,472] [Log ] [33 ] [DEBUG] - card: tuned user: Hometown subchannel: 0
[2016-01-28 19:07:12,474] [Log ] [33 ] [INFO ] - user:Hometown add
[2016-01-28 19:07:12,479] [Log ] [33 ] [INFO ] - card2:Hometown 4 0
[2016-01-28 19:07:12,482] [Log ] [33 ] [DEBUG] - Timeshifting started - Recordings=0 TimeShiftingActive=True
[2016-01-28 19:07:12,485] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartTimeShifting
[2016-01-28 19:07:12,488] [Log ] [33 ] [INFO ] - Controller: epg stop
[2016-01-28 19:07:12,491] [Log ] [33 ] [INFO ] - card: StartTimeShifting 4 C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:07:12,494] [Log ] [33 ] [INFO ] - card: CAM enabled : True
[2016-01-28 19:07:12,497] [Log ] [33 ] [INFO ] - card: WaitForFile - waiting _eventAudio & _eventVideo
[2016-01-28 19:07:14,428] [Log ] [29 ] [INFO ] - PID seen - type = Audio
[2016-01-28 19:07:14,433] [Log ] [29 ] [INFO ] - audioVideoEventHandler Audio
[2016-01-28 19:07:14,437] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,441] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,445] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,449] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,453] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,505] [Log ] [29 ] [INFO ] - PID seen - type = Video
[2016-01-28 19:07:14,509] [Log ] [29 ] [INFO ] - audioVideoEventHandler Video
[2016-01-28 19:07:14,513] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,517] [Log ] [33 ] [INFO ] - card: WaitForFile - video and audio are seen after 2,0161166 seconds
[2016-01-28 19:07:14,521] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,525] [Log ] [33 ] [INFO ] - Controller: StartTimeShifting started on card:4 to C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:07:14,529] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,532] [Log ] [33 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=11, tuningdetails=DVBS:tv:Viasat TV6 Freq:12054000 ONID:86 TSID:3 SID:1160 PMT:0x488 FTA:False LCN:10000 SymbolRate:27500 Modulation:ModQpsk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleB band:Universal Pilot:NotDefined RollOff:NotDefined
[2016-01-28 19:07:14,535] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,538] [Log ] [33 ] [INFO ] - Controller: Hometown 4 0
[2016-01-28 19:07:14,541] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,543] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndZapChannel
[2016-01-28 19:07:14,546] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,549] [Log ] [33 ] [INFO ] - control2:Hometown 4 0
[2016-01-28 19:07:14,551] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,555] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,560] [Log ] [19 ] [DEBUG] - Controller: DoSetChannelStates for 1033 channels
[2016-01-28 19:07:14,569] [Log ] [19 ] [INFO ] - ChannelStates.GetAllTimeshiftingAndRecordingChannels took 0 msec
[2016-01-28 19:07:14,574] [Log ] [29 ] [INFO ] - PID seen - type = Audio
[2016-01-28 19:07:14,577] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,586] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,589] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,591] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:14,594] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:07:14
[2016-01-28 19:07:16,077] [Log ] [19 ] [INFO ] - ChannelStates.DoSetChannelStates took 1524 msec
[2016-01-28 19:07:20,512] [Log ] [33 ] [INFO ] - Controller: TimeShiftingWouldUseCard TV12 HD 3121
[2016-01-28 19:07:20,518] [Log ] [33 ] [INFO ] - Controller: find free card for channel TV12 HD
[2016-01-28 19:07:20,522] [Log ] [33 ] [INFO ] - Controller: find card for channel TV12 HD
[2016-01-28 19:07:20,529] [Log ] [33 ] [INFO ] - Controller: got 1 tuning details for TV12 HD
[2016-01-28 19:07:20,532] [Log ] [33 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV12 HD Freq:10903000 ONID:70 TSID:69 SID:7092 PMT:0x1BC0 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:20,535] [Log ] [33 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:07:20,538] [Log ] [33 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:07:20,542] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:07:20,545] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:07:20,549] [Log ] [33 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:07:20,552] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 29 msec
[2016-01-28 19:07:20,554] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:07:20,558] [Log ] [33 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:07:20,562] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 43 msec
[2016-01-28 19:07:20,593] [Log ] [33 ] [INFO ] - Controller: StartTimeShifting TV12 HD 3121
[2016-01-28 19:07:20,596] [Log ] [33 ] [INFO ] - Controller: epg stop
[2016-01-28 19:07:20,599] [Log ] [33 ] [INFO ] - Controller: find free card for channel TV12 HD
[2016-01-28 19:07:20,602] [Log ] [33 ] [INFO ] - Controller: find card for channel TV12 HD
[2016-01-28 19:07:20,605] [Log ] [33 ] [INFO ] - Controller: got 1 tuning details for TV12 HD
[2016-01-28 19:07:20,609] [Log ] [33 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV12 HD Freq:10903000 ONID:70 TSID:69 SID:7092 PMT:0x1BC0 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:20,611] [Log ] [33 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:07:20,614] [Log ] [33 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:07:20,618] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:07:20,621] [Log ] [33 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:07:20,623] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 21 msec
[2016-01-28 19:07:20,626] [Log ] [33 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:07:20,629] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 29 msec
[2016-01-28 19:07:20,634] [Log ] [33 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=12, tuningdetails=DVBS:tv:Telenor TV12 HD Freq:10903000 ONID:70 TSID:69 SID:7092 PMT:0x1BC0 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:20,637] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:07:20,640] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:07:20,643] [Log ] [33 ] [INFO ] - Controller: try max 1 of 1 cards for timeshifting
[2016-01-28 19:07:20,646] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartZapChannel
[2016-01-28 19:07:20,649] [Log ] [33 ] [DEBUG] - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3121, ticket=12, tunestate=Tuning, stopstate=Idle
[2016-01-28 19:07:20,652] [Log ] [33 ] [INFO ] - card: CardTune 4 TV12 HD Hometown:4:-1
[2016-01-28 19:07:20,655] [Log ] [33 ] [INFO ] - card: Tune on card 4 to subchannel TV12 HD
[2016-01-28 19:07:20,658] [Log ] [33 ] [DEBUG] - card: user: Hometown:4:0 tune DVBS:tv:Telenor TV12 HD Freq:10903000 ONID:70 TSID:69 SID:7092 PMT:0x1BC0 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:20,666] [Log ] [33 ] [DEBUG] - card: to different transponder
[2016-01-28 19:07:20,669] [Log ] [33 ] [INFO ] - FreeSubChannel MD: freeing sub channel : 0
[2016-01-28 19:07:20,672] [Log ] [33 ] [INFO ] - mdplug: FreeChannel TV6
[2016-01-28 19:07:20,675] [Log ] [33 ] [INFO ] - mdplug: usage counter for channel 'TV6' is zero
[2016-01-28 19:07:20,678] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2016-01-28 19:07:20,682] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
[2016-01-28 19:07:20,685] [Log ] [33 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2016-01-28 19:07:20,688] [Log ] [33 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV12 HD Freq:10903000 ONID:70 TSID:69 SID:7092 PMT:0x1BC0 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:20,691] [Log ] [33 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV12 HD Freq:10903000 ONID:70 TSID:69 SID:7092 PMT:0x1BC0 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:20,693] [Log ] [33 ] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2016-01-28 19:07:20,696] [Log ] [33 ] [INFO ] - dvbs:channel modulation is set to Mod8Psk
[2016-01-28 19:07:20,699] [Log ] [33 ] [INFO ] - dvbs:channel FECRate is set to Rate3_4
[2016-01-28 19:07:20,701] [Log ] [33 ] [DEBUG] - Turbosight: set tone state, burst = ToneBurst, 22 kHz = Off
[2016-01-28 19:07:20,706] [Log ] [33 ] [DEBUG] - Turbosight: burst result = success
[2016-01-28 19:07:20,710] [Log ] [33 ] [DEBUG] - Turbosight: 22 kHz result = success
[2016-01-28 19:07:20,713] [Log ] [33 ] [INFO ] - Turbosight: Set DVB-S2
[2016-01-28 19:07:20,817] [Log ] [33 ] [INFO ] - dvb:Submiting tunerequest Channel:TV12 HD subChannel:0
[2016-01-28 19:07:20,821] [Log ] [33 ] [INFO ] - dvb:using existing subchannel:0
[2016-01-28 19:07:20,825] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest size:1 new:0
[2016-01-28 19:07:20,828] [Log ] [33 ] [INFO ] - subch:0 OnBeforeTune
[2016-01-28 19:07:20,832] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest
[2016-01-28 19:07:23,409] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest
[2016-01-28 19:07:23,414] [Log ] [33 ] [INFO ] - subch:0 OnAfterTune
[2016-01-28 19:07:23,418] [Log ] [33 ] [INFO ] - RunGraph
[2016-01-28 19:07:23,422] [Log ] [33 ] [INFO ] - dvb: LockInOnSignal waiting 20ms
[2016-01-28 19:07:23,447] [Log ] [33 ] [INFO ] - dvb: LockInOnSignal waiting 20ms
[2016-01-28 19:07:23,471] [Log ] [33 ] [INFO ] - dvb: LockInOnSignal waiting 20ms
[2016-01-28 19:07:23,496] [Log ] [33 ] [INFO ] - dvb: LockInOnSignal waiting 20ms
[2016-01-28 19:07:23,521] [Log ] [33 ] [INFO ] - dvb: LockInOnSignal waiting 20ms
[2016-01-28 19:07:25,457] [Log ] [33 ] [INFO ] - dvb: LockInOnSignal could not lock onto channel - no signal or bad signal
[2016-01-28 19:07:25,461] [Log ] [33 ] [INFO ] - FreeSubChannel MD: tried to free non existing sub channel : 0
[2016-01-28 19:07:25,465] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2016-01-28 19:07:25,469] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
[2016-01-28 19:07:25,473] [Log ] [33 ] [INFO ] - card2:Hometown 4 0
[2016-01-28 19:07:25,478] [Log ] [33 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=12, tuningdetails=DVBS:tv:Telenor TV12 HD Freq:10903000 ONID:70 TSID:69 SID:7092 PMT:0x1BC0 FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearV InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:07:25,482] [Log ] [33 ] [INFO ] - Controller: Hometown 4 0
[2016-01-28 19:07:25,486] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndZapChannel
[2016-01-28 19:07:25,490] [Log ] [33 ] [DEBUG] - Timeshifting stopped - Recordings=0 TimeShiftingActive=False
[2016-01-28 19:07:25,494] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndTimeShifting
[2016-01-28 19:07:25,498] [Log ] [33 ] [INFO ] - Controller: StopTimeShifting 4
[2016-01-28 19:07:25,503] [Log ] [33 ] [DEBUG] - CardTuner.RequestCardStopReservation: placed reservation with id=13, user=Hometown
[2016-01-28 19:07:25,609] [Log ] [33 ] [DEBUG] - CardTuner.Stop: ticket id=13, found=True
[2016-01-28 19:07:25,613] [Log ] [33 ] [INFO ] - Stop cardid=4, ticket=13, tunestate=Idle, stopstate=Stopping
[2016-01-28 19:07:25,617] [Log ] [33 ] [INFO ] - card TBS 6982 DVBS/S2 Tuner B: StopTimeShifting user:Hometown sub:0
[2016-01-28 19:07:25,620] [Log ] [33 ] [DEBUG] - card not IDLE - removing user: Hometown
[2016-01-28 19:07:25,625] [Log ] [33 ] [DEBUG] - usermanagement.RemoveUser: Hometown, subch: 0 of 1, card: 4
[2016-01-28 19:07:25,629] [Log ] [33 ] [INFO ] - user:Hometown remove
[2016-01-28 19:07:25,633] [Log ] [33 ] [INFO ] - subch:0-0 tswriter StopTimeshifting...
[2016-01-28 19:07:25,637] [Log ] [33 ] [INFO ] - FreeSubChannel MD: tried to free non existing sub channel : 0
[2016-01-28 19:07:25,641] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2016-01-28 19:07:25,645] [Log ] [33 ] [INFO ] - DVB subch:0 Decompose()
[2016-01-28 19:07:25,649] [Log ] [33 ] [INFO ] - FreeSubChannel CA: freeing sub channel : 0
[2016-01-28 19:07:25,653] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel : no subchannels present, pausing graph
[2016-01-28 19:07:25,657] [Log ] [33 ] [INFO ] - dvb:StopGraph called
[2016-01-28 19:07:25,660] [Log ] [33 ] [INFO ] - tvcard:FreeAllSubChannels
[2016-01-28 19:07:25,663] [Log ] [33 ] [INFO ] - mdplug: FreeAllChannels
[2016-01-28 19:07:25,665] [Log ] [33 ] [INFO ] - dvb:StopGraph
[2016-01-28 19:07:25,717] [Log ] [33 ] [INFO ] - debug: IMediaControl stopped! hr = 0x0 :)
[2016-01-28 19:07:25,721] [Log ] [TS_File_Cleanup] [INFO ] - card: delete timeshift files C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:07:25,724] [Log ] [33 ] [INFO ] - dvb:StopGraph called
[2016-01-28 19:07:25,727] [Log ] [33 ] [INFO ] - tvcard:FreeAllSubChannels
[2016-01-28 19:07:25,730] [Log ] [TS_File_Cleanup] [INFO ] - card: trying to delete C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts.tsbuffer
[2016-01-28 19:07:25,733] [Log ] [33 ] [INFO ] - mdplug: FreeAllChannels
[2016-01-28 19:07:25,736] [Log ] [33 ] [INFO ] - dvb:StopGraph filterstate already stopped, returning.
[2016-01-28 19:07:25,738] [Log ] [33 ] [INFO ] - user:Hometown remove
[2016-01-28 19:07:25,741] [Log ] [33 ] [DEBUG] - CardReservation.RemoveStopTicket: removed STOP reservation with id=13
[2016-01-28 19:07:25,744] [Log ] [33 ] [INFO ] - Controller:Timeshifting stopped on card:4
[2016-01-28 19:07:25,746] [Log ] [33 ] [INFO ] - RTSP: remove stream stream4.0
[2016-01-28 19:07:25,752] [Log ] [33 ] [INFO ] - Controller: epg start
[2016-01-28 19:07:25,811] [Log ] [19 ] [DEBUG] - Controller: DoSetChannelStates for 1033 channels
[2016-01-28 19:07:25,814] [Log ] [33 ] [INFO ] - Controller: Timeshifting failed, no more cards available.
[2016-01-28 19:07:25,817] [Log ] [19 ] [INFO ] - ChannelStates.DoSetChannelStates took 3 msec
[2016-01-28 19:07:25,820] [Log ] [33 ] [INFO ] - Controller: epg start
[2016-01-28 19:07:30,735] [Log ] [TS_File_Cleanup] [INFO ] - card: delete timeshift files C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:07:30,740] [Log ] [TS_File_Cleanup] [INFO ] - card: trying to delete C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts.tsbuffer
[2016-01-28 19:07:30,744] [Log ] [TS_File_Cleanup] [INFO ] - card: deleted file C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts.tsbuffer
[2016-01-28 19:07:30,748] [Log ] [TS_File_Cleanup] [INFO ] - card: trying to delete C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts.tsbuffer1.ts
[2016-01-28 19:07:30,760] [Log ] [TS_File_Cleanup] [INFO ] - card: deleted file C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts.tsbuffer1.ts
[2016-01-28 19:07:53,101] [Log ] [22 ] [INFO ] - Not the time to fetch remote file yet
[2016-01-28 19:08:15,988] [Log ] [33 ] [INFO ] - Controller: find free card for channel TV4 HD
[2016-01-28 19:08:15,991] [Log ] [33 ] [INFO ] - Controller: find card for channel TV4 HD
[2016-01-28 19:08:15,995] [Log ] [33 ] [INFO ] - Controller: got 1 tuning details for TV4 HD
[2016-01-28 19:08:15,998] [Log ] [33 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:16,001] [Log ] [33 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:08:16,003] [Log ] [33 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:08:16,007] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:08:16,010] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:08:16,013] [Log ] [33 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:08:16,015] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 24 msec
[2016-01-28 19:08:16,018] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:08:16,021] [Log ] [33 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:08:16,023] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 35 msec
[2016-01-28 19:08:16,027] [Log ] [33 ] [INFO ] - Controller: TimeShiftingWouldUseCard TV4 HD 3476
[2016-01-28 19:08:16,030] [Log ] [33 ] [INFO ] - Controller: find free card for channel TV4 HD
[2016-01-28 19:08:16,033] [Log ] [33 ] [INFO ] - Controller: find card for channel TV4 HD
[2016-01-28 19:08:16,036] [Log ] [33 ] [INFO ] - Controller: got 1 tuning details for TV4 HD
[2016-01-28 19:08:16,039] [Log ] [33 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:16,042] [Log ] [33 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:08:16,045] [Log ] [33 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:08:16,048] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:08:16,051] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:08:16,054] [Log ] [33 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:08:16,056] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 23 msec
[2016-01-28 19:08:16,059] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:08:16,062] [Log ] [33 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:08:16,064] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 34 msec
[2016-01-28 19:08:16,067] [Log ] [33 ] [DEBUG] - CiMenuSupported called cardid 4
[2016-01-28 19:08:16,070] [Log ] [33 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:08:16,073] [Log ] [33 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:08:16,075] [Log ] [33 ] [DEBUG] - CiMenuSupported card TBS 6982 DVBS/S2 Tuner B supported: False
[2016-01-28 19:08:16,078] [Log ] [33 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:08:16,081] [Log ] [33 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:08:16,085] [Log ] [33 ] [INFO ] - Controller: StartTimeShifting TV4 HD 3476
[2016-01-28 19:08:16,089] [Log ] [33 ] [INFO ] - Controller: epg stop
[2016-01-28 19:08:16,092] [Log ] [33 ] [INFO ] - Controller: find free card for channel TV4 HD
[2016-01-28 19:08:16,094] [Log ] [33 ] [INFO ] - Controller: find card for channel TV4 HD
[2016-01-28 19:08:16,098] [Log ] [33 ] [INFO ] - Controller: got 1 tuning details for TV4 HD
[2016-01-28 19:08:16,101] [Log ] [33 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:16,104] [Log ] [33 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:08:16,106] [Log ] [33 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:08:16,110] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:08:16,113] [Log ] [33 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:08:16,115] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 20 msec
[2016-01-28 19:08:16,118] [Log ] [33 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:08:16,121] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 28 msec
[2016-01-28 19:08:16,125] [Log ] [33 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=14, tuningdetails=DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:16,128] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:08:16,131] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:08:16,134] [Log ] [33 ] [INFO ] - Controller: try max 1 of 1 cards for timeshifting
[2016-01-28 19:08:16,136] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartZapChannel
[2016-01-28 19:08:16,139] [Log ] [33 ] [DEBUG] - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3476, ticket=14, tunestate=Tuning, stopstate=Idle
[2016-01-28 19:08:16,142] [Log ] [33 ] [INFO ] - card: CardTune 4 TV4 HD Hometown:4:-1
[2016-01-28 19:08:16,145] [Log ] [33 ] [INFO ] - card: Tune on card 4 to subchannel TV4 HD
[2016-01-28 19:08:16,148] [Log ] [33 ] [DEBUG] - card: user: Hometown:4:-1 tune DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:16,155] [Log ] [33 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2016-01-28 19:08:16,158] [Log ] [33 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:16,161] [Log ] [33 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:16,163] [Log ] [33 ] [INFO ] - dvb:GetNewSubChannel:0 #0
[2016-01-28 19:08:16,166] [Log ] [33 ] [INFO ] - TvDvbChannel ctor new subchIndex:0
[2016-01-28 19:08:16,169] [Log ] [33 ] [INFO ] - card: AddTuneEvent card: 4 / subch: 0
[2016-01-28 19:08:16,172] [Log ] [33 ] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2016-01-28 19:08:16,174] [Log ] [33 ] [INFO ] - dvbs:channel modulation is set to Mod8Psk
[2016-01-28 19:08:16,177] [Log ] [33 ] [INFO ] - dvbs:channel FECRate is set to Rate3_4
[2016-01-28 19:08:16,180] [Log ] [33 ] [DEBUG] - Turbosight: set tone state, burst = ToneBurst, 22 kHz = Off
[2016-01-28 19:08:16,184] [Log ] [33 ] [DEBUG] - Turbosight: burst result = success
[2016-01-28 19:08:16,188] [Log ] [33 ] [DEBUG] - Turbosight: 22 kHz result = success
[2016-01-28 19:08:16,191] [Log ] [33 ] [INFO ] - Turbosight: Set DVB-S2
[2016-01-28 19:08:16,295] [Log ] [33 ] [INFO ] - dvb:Submiting tunerequest Channel:TV4 HD subChannel:0
[2016-01-28 19:08:16,299] [Log ] [33 ] [INFO ] - dvb:using existing subchannel:0
[2016-01-28 19:08:16,303] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest size:1 new:0
[2016-01-28 19:08:16,307] [Log ] [33 ] [INFO ] - subch:0 OnBeforeTune
[2016-01-28 19:08:16,311] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest
[2016-01-28 19:08:16,314] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest
[2016-01-28 19:08:16,318] [Log ] [33 ] [INFO ] - subch:0 OnAfterTune
[2016-01-28 19:08:16,323] [Log ] [33 ] [INFO ] - RunGraph
[2016-01-28 19:08:16,327] [Log ] [33 ] [INFO ] - subch:0 OnGraphStart
[2016-01-28 19:08:16,330] [Log ] [33 ] [INFO ] - dvb: RunGraph
[2016-01-28 19:08:16,556] [Log ] [33 ] [INFO ] - dvb: LockInOnSignal ok
[2016-01-28 19:08:16,561] [Log ] [33 ] [INFO ] - subch:0 OnGraphStarted
[2016-01-28 19:08:16,565] [Log ] [33 ] [INFO ] - subch:0 SetupPmtGrabber:pid 4F sid:57D
[2016-01-28 19:08:16,569] [Log ] [33 ] [INFO ] - subch:0 set pmt grabber pmt:4F sid:57D
[2016-01-28 19:08:16,572] [Log ] [33 ] [INFO ] - subch:0 set ca grabber
[2016-01-28 19:08:16,575] [Log ] [33 ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2016-01-28 19:08:16,577] [Log ] [33 ] [DEBUG] - WaitForPMT: Waiting for PMT 4F
[2016-01-28 19:08:26,581] [Log ] [33 ] [DEBUG] - WaitForPMT: Timed out waiting for PMT after 10,0035791 seconds. Increase the PMT timeout value?
[2016-01-28 19:08:26,585] [Log ] [33 ] [DEBUG] - Setting to 0 to search for new PMT.
[2016-01-28 19:08:26,589] [Log ] [33 ] [INFO ] - subch:0 SetupPmtGrabber:pid 0 sid:57D
[2016-01-28 19:08:26,593] [Log ] [33 ] [INFO ] - subch:0 set pmt grabber pmt:0 sid:57D
[2016-01-28 19:08:26,597] [Log ] [33 ] [INFO ] - subch:0 set ca grabber
[2016-01-28 19:08:26,601] [Log ] [33 ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2016-01-28 19:08:26,604] [Log ] [33 ] [DEBUG] - WaitForPMT: Waiting for PMT 0
[2016-01-28 19:08:36,608] [Log ] [33 ] [DEBUG] - WaitForPMT: Timed out waiting for PMT after 10,0045784 seconds. Increase the PMT timeout value?
[2016-01-28 19:08:36,612] [Log ] [33 ] [DEBUG] - Setting to 0 to search for new PMT.
[2016-01-28 19:08:36,616] [Log ] [33 ] [INFO ] - FreeSubChannel MD: tried to free non existing sub channel : 0
[2016-01-28 19:08:36,620] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2016-01-28 19:08:36,624] [Log ] [33 ] [INFO ] - DVB subch:0 Decompose()
[2016-01-28 19:08:36,628] [Log ] [33 ] [INFO ] - FreeSubChannel CA: freeing sub channel : 0
[2016-01-28 19:08:36,632] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel : no subchannels present, pausing graph
[2016-01-28 19:08:36,635] [Log ] [33 ] [INFO ] - dvb:StopGraph called
[2016-01-28 19:08:36,639] [Log ] [33 ] [INFO ] - tvcard:FreeAllSubChannels
[2016-01-28 19:08:36,642] [Log ] [33 ] [INFO ] - mdplug: FreeAllChannels
[2016-01-28 19:08:36,644] [Log ] [33 ] [INFO ] - dvb:StopGraph
[2016-01-28 19:08:36,703] [Log ] [33 ] [INFO ] - debug: IMediaControl stopped! hr = 0x0 :)
[2016-01-28 19:08:36,707] [Log ] [33 ] [INFO ] - card2:Hometown 4 -1
[2016-01-28 19:08:36,710] [Log ] [33 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=14, tuningdetails=DVBS:tv:Telenor TV4 HD Freq:10934000 ONID:70 TSID:14 SID:1405 PMT:0x4F FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:36,713] [Log ] [33 ] [INFO ] - card: SignalTuneEvent card: 4 / subch: 0
[2016-01-28 19:08:36,716] [Log ] [33 ] [INFO ] - Controller: Hometown 4 -1
[2016-01-28 19:08:36,719] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndZapChannel
[2016-01-28 19:08:36,722] [Log ] [33 ] [INFO ] - Controller: Timeshifting failed, no more cards available.
[2016-01-28 19:08:36,725] [Log ] [33 ] [INFO ] - Controller: epg start
[2016-01-28 19:08:46,027] [Log ] [4 ] [INFO ] - Controller: find free card for channel TV3 HD
[2016-01-28 19:08:46,030] [Log ] [4 ] [INFO ] - Controller: find card for channel TV3 HD
[2016-01-28 19:08:46,035] [Log ] [4 ] [INFO ] - Controller: got 1 tuning details for TV3 HD
[2016-01-28 19:08:46,038] [Log ] [4 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:46,041] [Log ] [4 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:08:46,043] [Log ] [4 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:08:46,047] [Log ] [4 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:08:46,050] [Log ] [4 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:08:46,053] [Log ] [4 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:08:46,055] [Log ] [4 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 24 msec
[2016-01-28 19:08:46,058] [Log ] [4 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:08:46,061] [Log ] [4 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:08:46,063] [Log ] [4 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 36 msec
[2016-01-28 19:08:46,066] [Log ] [4 ] [INFO ] - Controller: TimeShiftingWouldUseCard TV3 HD 3505
[2016-01-28 19:08:46,070] [Log ] [4 ] [INFO ] - Controller: find free card for channel TV3 HD
[2016-01-28 19:08:46,072] [Log ] [4 ] [INFO ] - Controller: find card for channel TV3 HD
[2016-01-28 19:08:46,076] [Log ] [4 ] [INFO ] - Controller: got 1 tuning details for TV3 HD
[2016-01-28 19:08:46,079] [Log ] [4 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:46,082] [Log ] [4 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:08:46,084] [Log ] [4 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:08:46,088] [Log ] [4 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:08:46,091] [Log ] [4 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:08:46,093] [Log ] [4 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:08:46,096] [Log ] [4 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 23 msec
[2016-01-28 19:08:46,099] [Log ] [4 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:08:46,101] [Log ] [4 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:08:46,104] [Log ] [4 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 34 msec
[2016-01-28 19:08:46,107] [Log ] [4 ] [DEBUG] - CiMenuSupported called cardid 4
[2016-01-28 19:08:46,110] [Log ] [4 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:08:46,112] [Log ] [4 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:08:46,115] [Log ] [4 ] [DEBUG] - CiMenuSupported card TBS 6982 DVBS/S2 Tuner B supported: False
[2016-01-28 19:08:46,118] [Log ] [4 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:08:46,120] [Log ] [4 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:08:46,124] [Log ] [4 ] [INFO ] - Controller: StartTimeShifting TV3 HD 3505
[2016-01-28 19:08:46,127] [Log ] [4 ] [INFO ] - Controller: epg stop
[2016-01-28 19:08:46,129] [Log ] [4 ] [INFO ] - Controller: find free card for channel TV3 HD
[2016-01-28 19:08:46,132] [Log ] [4 ] [INFO ] - Controller: find card for channel TV3 HD
[2016-01-28 19:08:46,135] [Log ] [4 ] [INFO ] - Controller: got 1 tuning details for TV3 HD
[2016-01-28 19:08:46,138] [Log ] [4 ] [INFO ] - Controller: channel #1 DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:46,141] [Log ] [4 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:08:46,144] [Log ] [4 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:08:46,147] [Log ] [4 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:08:46,150] [Log ] [4 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:08:46,153] [Log ] [4 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 20 msec
[2016-01-28 19:08:46,155] [Log ] [4 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:08:46,158] [Log ] [4 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 28 msec
[2016-01-28 19:08:46,162] [Log ] [4 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=15, tuningdetails=DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:46,165] [Log ] [4 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:08:46,168] [Log ] [4 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:08:46,171] [Log ] [4 ] [INFO ] - Controller: try max 1 of 1 cards for timeshifting
[2016-01-28 19:08:46,174] [Log ] [4 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartZapChannel
[2016-01-28 19:08:46,176] [Log ] [4 ] [DEBUG] - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3505, ticket=15, tunestate=Tuning, stopstate=Idle
[2016-01-28 19:08:46,179] [Log ] [4 ] [INFO ] - card: CardTune 4 TV3 HD (S) Hometown:4:-1
[2016-01-28 19:08:46,182] [Log ] [4 ] [INFO ] - card: Tune on card 4 to subchannel TV3 HD (S)
[2016-01-28 19:08:46,185] [Log ] [4 ] [DEBUG] - card: user: Hometown:4:-1 tune DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:46,192] [Log ] [4 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2016-01-28 19:08:46,195] [Log ] [4 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:46,198] [Log ] [4 ] [INFO ] - dvbs: Tune:DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:46,201] [Log ] [4 ] [INFO ] - dvb:GetNewSubChannel:0 #0
[2016-01-28 19:08:46,204] [Log ] [4 ] [INFO ] - TvDvbChannel ctor new subchIndex:0
[2016-01-28 19:08:46,206] [Log ] [4 ] [INFO ] - card: AddTuneEvent card: 4 / subch: 0
[2016-01-28 19:08:46,209] [Log ] [4 ] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2016-01-28 19:08:46,212] [Log ] [4 ] [INFO ] - dvbs:channel modulation is set to Mod8Psk
[2016-01-28 19:08:46,214] [Log ] [4 ] [INFO ] - dvbs:channel FECRate is set to Rate3_4
[2016-01-28 19:08:46,217] [Log ] [4 ] [DEBUG] - Turbosight: set tone state, burst = ToneBurst, 22 kHz = Off
[2016-01-28 19:08:46,222] [Log ] [4 ] [DEBUG] - Turbosight: burst result = success
[2016-01-28 19:08:46,226] [Log ] [4 ] [DEBUG] - Turbosight: 22 kHz result = success
[2016-01-28 19:08:46,228] [Log ] [4 ] [INFO ] - Turbosight: Set DVB-S2
[2016-01-28 19:08:46,332] [Log ] [4 ] [INFO ] - dvb:Submiting tunerequest Channel:TV3 HD (S) subChannel:0
[2016-01-28 19:08:46,336] [Log ] [4 ] [INFO ] - dvb:using existing subchannel:0
[2016-01-28 19:08:46,340] [Log ] [4 ] [INFO ] - dvb:Submit tunerequest size:1 new:0
[2016-01-28 19:08:46,344] [Log ] [4 ] [INFO ] - subch:0 OnBeforeTune
[2016-01-28 19:08:46,347] [Log ] [4 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest
[2016-01-28 19:08:46,351] [Log ] [4 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest
[2016-01-28 19:08:46,355] [Log ] [4 ] [INFO ] - subch:0 OnAfterTune
[2016-01-28 19:08:46,359] [Log ] [4 ] [INFO ] - RunGraph
[2016-01-28 19:08:46,362] [Log ] [4 ] [INFO ] - subch:0 OnGraphStart
[2016-01-28 19:08:46,365] [Log ] [4 ] [INFO ] - dvb: RunGraph
[2016-01-28 19:08:48,974] [Log ] [4 ] [INFO ] - dvb: LockInOnSignal waiting 20ms
[2016-01-28 19:08:48,999] [Log ] [4 ] [INFO ] - dvb: LockInOnSignal waiting 20ms
[2016-01-28 19:08:49,023] [Log ] [4 ] [INFO ] - dvb: LockInOnSignal waiting 20ms
[2016-01-28 19:08:49,047] [Log ] [4 ] [INFO ] - dvb: LockInOnSignal waiting 20ms
[2016-01-28 19:08:49,072] [Log ] [4 ] [INFO ] - dvb: LockInOnSignal waiting 20ms
[2016-01-28 19:08:51,008] [Log ] [4 ] [INFO ] - dvb: LockInOnSignal could not lock onto channel - no signal or bad signal
[2016-01-28 19:08:51,012] [Log ] [4 ] [INFO ] - FreeSubChannel MD: tried to free non existing sub channel : 0
[2016-01-28 19:08:51,016] [Log ] [4 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2016-01-28 19:08:51,020] [Log ] [4 ] [INFO ] - DVB subch:0 Decompose()
[2016-01-28 19:08:51,024] [Log ] [4 ] [INFO ] - FreeSubChannel CA: freeing sub channel : 0
[2016-01-28 19:08:51,027] [Log ] [4 ] [INFO ] - tvcard:FreeSubChannel : no subchannels present, pausing graph
[2016-01-28 19:08:51,031] [Log ] [4 ] [INFO ] - dvb:StopGraph called
[2016-01-28 19:08:51,035] [Log ] [4 ] [INFO ] - tvcard:FreeAllSubChannels
[2016-01-28 19:08:51,039] [Log ] [4 ] [INFO ] - mdplug: FreeAllChannels
[2016-01-28 19:08:51,042] [Log ] [4 ] [INFO ] - dvb:StopGraph
[2016-01-28 19:08:51,151] [Log ] [4 ] [INFO ] - debug: IMediaControl stopped! hr = 0x0 :)
[2016-01-28 19:08:51,154] [Log ] [4 ] [INFO ] - card2:Hometown 4 -1
[2016-01-28 19:08:51,159] [Log ] [4 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=15, tuningdetails=DVBS:tv:Telenor TV3 HD (S) Freq:11293000 ONID:70 TSID:24 SID:4446 PMT:0x18A FTA:False LCN:10000 SymbolRate:25000 Modulation:Mod8Psk Polarisation:LinearH InnerFecRate:Rate3_4 DisEqc:SimpleA band:Universal Pilot:On RollOff:ThirtyFive
[2016-01-28 19:08:51,162] [Log ] [4 ] [INFO ] - card: SignalTuneEvent card: 4 / subch: 0
[2016-01-28 19:08:51,164] [Log ] [4 ] [INFO ] - Controller: Hometown 4 -1
[2016-01-28 19:08:51,167] [Log ] [4 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndZapChannel
[2016-01-28 19:08:51,170] [Log ] [4 ] [INFO ] - Controller: Timeshifting failed, no more cards available.
[2016-01-28 19:08:51,172] [Log ] [4 ] [INFO ] - Controller: epg start
[2016-01-28 19:08:53,101] [Log ] [40 ] [INFO ] - Not the time to fetch remote file yet
Most of all it is not MDAPI problem. With default settings MDAPI may only cause No Audio/Video error and with any settings it can't cause No signal error.
Hello,
I have almost the same issue.
When I change channel, randomly, MP freeze (client & server)
But if I kill MDAPI processes (from task manager), MDAPI restart automatically and it is not frozen anymore.
Here is the mdapi log.
We can see that the freeze occurs at 23:00:44 ACamd.dll : CPlugin::AddChannel
Hi, the log is incomplete, please archive all the log files in the directory and specify exact time when the frozen occurred
Hi
Sorry for the delay
Here are all the logs (mdapi, acamd, mediaportal and tuner)
Freeze occurs at 20/03/2016 14:43:53
I wait 2 minutes before killing mdapi exec's
Thanks !