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...
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.
If you would like to refer to this comment somewhere else in this project, copy and paste the following link:
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! 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📺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📺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📺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📺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📺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 ] - *******
[2016-01-28 19:06:11,330] [Log ] [27 ] [INFO ] - * SIGNAL LEVEL: 94, SIGNAL QUALITY: 82
[2016-01-28 19:06:11,330] [Log ] [27 ] [INFO ] - ********
[2016-01-28 19:06:11,330] [Log ] [27 ] [DEBUG] - card: tuned user: Hometown subchannel: 0
[2016-01-28 19:06:11,345] [Log ] [27 ] [INFO ] - user:Hometown add
[2016-01-28 19:06:11,345] [Log ] [27 ] [INFO ] - card2:Hometown 4 0
[2016-01-28 19:06:11,345] [Log ] [27 ] [INFO ] - Controller: delete timeshift files C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:06:11,345] [Log ] [27 ] [DEBUG] - Timeshifting started - Recordings=0 TimeShiftingActive=True
[2016-01-28 19:06:11,345] [Log ] [27 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartTimeShifting
[2016-01-28 19:06:11,345] [Log ] [27 ] [INFO ] - Controller: epg stop
[2016-01-28 19:06:11,361] [Log ] [27 ] [INFO ] - card: StartTimeShifting 4 C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:06:11,361] [Log ] [27 ] [INFO ] - card: CAM enabled : True
[2016-01-28 19:06:11,361] [Log ] [27 ] [INFO ] - subch:0 SetTimeShiftFileName:C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:06:11,361] [Log ] [27 ] [INFO ] - Set video / audio observer
[2016-01-28 19:06:11,361] [Log ] [27 ] [INFO ] - subch:0 SetTimeShiftFileName fill in pids
[2016-01-28 19:06:11,377] [Log ] [27 ] [INFO ] - subch:0-0 tswriter StartTimeshifting...
[2016-01-28 19:06:11,377] [Log ] [27 ] [INFO ] - card: WaitForFile - waiting _eventAudio & _eventVideo
[2016-01-28 19:06:13,674] [Log ] [29 ] [INFO ] - PID seen - type = Video
[2016-01-28 19:06:13,689] [Log ] [29 ] [INFO ] - audioVideoEventHandler Video
[2016-01-28 19:06:13,705] [Log ] [29 ] [INFO ] - PID seen - type = Audio
[2016-01-28 19:06:13,705] [Log ] [29 ] [INFO ] - audioVideoEventHandler Audio
[2016-01-28 19:06:13,720] [Log ] [27 ] [INFO ] - card: WaitForFile - video and audio are seen after 2,3437558 seconds
[2016-01-28 19:06:13,720] [Log ] [27 ] [INFO ] - user:Hometown card:4 sub:0 add stream:C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts.tsbuffer
[2016-01-28 19:06:13,736] [Log ] [27 ] [INFO ] - RTSP: add stream stream4.0 file:C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts.tsbuffer
[2016-01-28 19:06:13,752] [Log ] [27 ] [INFO ] - Controller: StartTimeShifting started on card:4 to C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts.tsbuffer
[2016-01-28 19:06:13,752] [Log ] [27 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=3, tuningdetails=DVBS📺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:13,752] [Log ] [27 ] [INFO ] - card: SignalTuneEvent card: 4 / subch: 0
[2016-01-28 19:06:13,752] [Log ] [27 ] [INFO ] - Controller: Hometown 4 0
[2016-01-28 19:06:13,752] [Log ] [27 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndZapChannel
[2016-01-28 19:06:13,767] [Log ] [27 ] [INFO ] - control2:Hometown 4 0
[2016-01-28 19:06:13,767] [Log ] [38 ] [DEBUG] - Controller: DoSetChannelStates for 1033 channels
[2016-01-28 19:06:13,767] [Log ] [27 ] [DEBUG] - CiMenuSupported called cardid 4
[2016-01-28 19:06:13,767] [Log ] [27 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:06:13,783] [Log ] [38 ] [INFO ] - ChannelStates.GetAllTimeshiftingAndRecordingChannels took 0 msec
[2016-01-28 19:06:13,783] [Log ] [27 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:06:13,783] [Log ] [27 ] [DEBUG] - CiMenuSupported card TBS 6982 DVBS/S2 Tuner B supported: False
[2016-01-28 19:06:13,783] [Log ] [27 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:06:13,783] [Log ] [27 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:06:15,944] [Log ] [38 ] [INFO ] - ChannelStates.DoSetChannelStates took 2171 msec
[2016-01-28 19:06:24,314] [Log ] [27 ] [INFO ] - Controller: TimeShiftingWouldUseCard Sjuan 3135
[2016-01-28 19:06:24,318] [Log ] [27 ] [INFO ] - Controller: find free card for channel Sjuan
[2016-01-28 19:06:24,322] [Log ] [27 ] [INFO ] - Controller: find card for channel Sjuan
[2016-01-28 19:06:24,326] [Log ] [27 ] [INFO ] - Controller: got 1 tuning details for Sjuan
[2016-01-28 19:06:24,329] [Log ] [27 ] [INFO ] - Controller: channel #1 DVBS📺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:24,333] [Log ] [27 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:06:24,335] [Log ] [27 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:06:24,339] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:06:24,348] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:06:24,353] [Log ] [27 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:06:24,363] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 41 msec
[2016-01-28 19:06:24,367] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:06:24,370] [Log ] [27 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:06:24,373] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 54 msec
[2016-01-28 19:06:24,441] [Log ] [27 ] [INFO ] - Controller: StartTimeShifting Sjuan 3135
[2016-01-28 19:06:24,444] [Log ] [27 ] [INFO ] - Controller: epg stop
[2016-01-28 19:06:24,447] [Log ] [27 ] [INFO ] - Controller: find free card for channel Sjuan
[2016-01-28 19:06:24,450] [Log ] [27 ] [INFO ] - Controller: find card for channel Sjuan
[2016-01-28 19:06:24,454] [Log ] [27 ] [INFO ] - Controller: got 1 tuning details for Sjuan
[2016-01-28 19:06:24,457] [Log ] [27 ] [INFO ] - Controller: channel #1 DVBS📺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:24,460] [Log ] [27 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:06:24,463] [Log ] [27 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:06:24,467] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:06:24,470] [Log ] [27 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:06:24,473] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 22 msec
[2016-01-28 19:06:24,476] [Log ] [27 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:06:24,478] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 31 msec
[2016-01-28 19:06:24,485] [Log ] [27 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=4, tuningdetails=DVBS📺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:24,488] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:06:24,491] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:06:24,494] [Log ] [27 ] [INFO ] - Controller: try max 1 of 1 cards for timeshifting
[2016-01-28 19:06:24,498] [Log ] [27 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartZapChannel
[2016-01-28 19:06:24,501] [Log ] [27 ] [DEBUG] - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3135, ticket=4, tunestate=Tuning, stopstate=Idle
[2016-01-28 19:06:24,504] [Log ] [27 ] [INFO ] - card: CardTune 4 Sjuan Hometown:4:-1
[2016-01-28 19:06:24,507] [Log ] [27 ] [INFO ] - card: Tune on card 4 to subchannel Sjuan
[2016-01-28 19:06:24,510] [Log ] [27 ] [DEBUG] - card: user: Hometown:4:0 tune DVBS📺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:24,518] [Log ] [27 ] [DEBUG] - card: to different transponder
[2016-01-28 19:06:24,521] [Log ] [27 ] [INFO ] - FreeSubChannel MD: freeing sub channel : 0
[2016-01-28 19:06:24,524] [Log ] [27 ] [INFO ] - mdplug: FreeChannel TV3 HD (S)
[2016-01-28 19:06:24,527] [Log ] [27 ] [INFO ] - mdplug: usage counter for channel 'TV3 HD (S)' is zero
[2016-01-28 19:06:24,530] [Log ] [27 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2016-01-28 19:06:24,533] [Log ] [27 ] [INFO ] - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
[2016-01-28 19:06:24,535] [Log ] [27 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2016-01-28 19:06:24,538] [Log ] [27 ] [INFO ] - 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
[2016-01-28 19:06:24,541] [Log ] [27 ] [INFO ] - 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
[2016-01-28 19:06:24,544] [Log ] [27 ] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2016-01-28 19:06:24,547] [Log ] [27 ] [INFO ] - dvbs:channel modulation is set to ModNotSet
[2016-01-28 19:06:24,549] [Log ] [27 ] [INFO ] - dvbs:channel FECRate is set to Rate7_8
[2016-01-28 19:06:24,552] [Log ] [27 ] [DEBUG] - Turbosight: set tone state, burst = ToneBurst, 22 kHz = Off
[2016-01-28 19:06:24,557] [Log ] [27 ] [DEBUG] - Turbosight: burst result = success
[2016-01-28 19:06:24,561] [Log ] [27 ] [DEBUG] - Turbosight: 22 kHz result = success
[2016-01-28 19:06:24,564] [Log ] [27 ] [INFO ] - Turbosight: Set DVB-S2
[2016-01-28 19:06:24,668] [Log ] [27 ] [INFO ] - dvb:Submiting tunerequest Channel:Sjuan subChannel:0
[2016-01-28 19:06:24,672] [Log ] [27 ] [INFO ] - dvb:using existing subchannel:0
[2016-01-28 19:06:24,676] [Log ] [27 ] [INFO ] - dvb:Submit tunerequest size:1 new:0
[2016-01-28 19:06:24,680] [Log ] [27 ] [INFO ] - subch:0 OnBeforeTune
[2016-01-28 19:06:24,685] [Log ] [27 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest
[2016-01-28 19:06:24,970] [Log ] [27 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest
[2016-01-28 19:06:24,975] [Log ] [27 ] [INFO ] - subch:0 OnAfterTune
[2016-01-28 19:06:24,979] [Log ] [27 ] [INFO ] - RunGraph
[2016-01-28 19:06:24,983] [Log ] [27 ] [INFO ] - dvb: LockInOnSignal ok
[2016-01-28 19:06:24,987] [Log ] [27 ] [INFO ] - subch:0 OnGraphStart
[2016-01-28 19:06:24,991] [Log ] [27 ] [INFO ] - subch:0 Graph already running - WaitForPMT
[2016-01-28 19:06:24,995] [Log ] [27 ] [INFO ] - subch:0 SetupPmtGrabber:pid AC sid:83C
[2016-01-28 19:06:24,999] [Log ] [27 ] [INFO ] - subch:0 set pmt grabber pmt:AC sid:83C
[2016-01-28 19:06:25,002] [Log ] [27 ] [INFO ] - subch:0 set ca grabber
[2016-01-28 19:06:25,005] [Log ] [27 ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2016-01-28 19:06:25,008] [Log ] [27 ] [DEBUG] - WaitForPMT: Waiting for PMT AC
[2016-01-28 19:06:25,116] [Log ] [29 ] [INFO ] - subch:0 OnPMTReceived() pmt:AC ran:True dynamic:False
[2016-01-28 19:06:25,121] [Log ] [27 ] [DEBUG] - WaitForPMT: Found PMT after 0,1130067 seconds.
[2016-01-28 19:06:25,125] [Log ] [27 ] [INFO ] - subch:0 SendPmt:CA found after 0 seconds
[2016-01-28 19:06:25,129] [Log ] [27 ] [INFO ] - subch:0 SendPmt:83C 83C FFFFFFFF 2
[2016-01-28 19:06:25,133] [Log ] [27 ] [INFO ] - Decode pmt
[2016-01-28 19:06:25,137] [Log ] [27 ] [INFO ] - descr1 len:6 9 4 b 0 fc 26
[2016-01-28 19:06:25,141] [Log ] [27 ] [INFO ] - Set descriptor data with length 6
[2016-01-28 19:06:25,145] [Log ] [27 ] [INFO ] - Set descriptor data with length 7
[2016-01-28 19:06:25,149] [Log ] [27 ] [INFO ] - subch:0 SendPMT version:2 len:50 2108
[2016-01-28 19:06:25,152] [Log ] [27 ] [DEBUG] - Turbosight: send PMT to CAM, list action = Only, command = Descrambling
[2016-01-28 19:06:25,155] [Log ] [27 ] [DEBUG] - Turbosight: CAM not available
[2016-01-28 19:06:25,158] [Log ] [27 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:06:25,160] [Log ] [27 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:06:25,164] [Log ] [27 ] [INFO ] - subch:0 cam flags:False
[2016-01-28 19:06:25,167] [Log ] [27 ] [INFO ] - subch:0 SetMpegPidMapping
[2016-01-28 19:06:25,170] [Log ] [27 ] [INFO ] - subch:0 pid:479 pcr
[2016-01-28 19:06:25,172] [Log ] [27 ] [INFO ] - subch:0 pid:AC pmt
[2016-01-28 19:06:25,175] [Log ] [27 ] [INFO ] - subch:0 pid:479 video type:MPEG-2
[2016-01-28 19:06:25,178] [Log ] [27 ] [INFO ] - subch:0 map pid:479 video type:MPEG-2
[2016-01-28 19:06:25,181] [Log ] [27 ] [INFO ] - subch:0 pid:C44 audio lang:swe type:MPEG-2
[2016-01-28 19:06:25,183] [Log ] [27 ] [INFO ] - subch:0 map pid:C44 audio lang:swe type:MPEG-2
[2016-01-28 19:06:25,186] [Log ] [27 ] [INFO ] - subch:0 pid:179F teletext type:6
[2016-01-28 19:06:25,189] [Log ] [27 ] [INFO ] - subch:0 map pid:179F teletext type:6
[2016-01-28 19:06:25,192] [Log ] [27 ] [INFO ] - ecm len:6 9 4 B 0 FC 26
[2016-01-28 19:06:25,196] [Log ] [27 ] [INFO ] - emm len:6 9 4 B 0 E0 30
[2016-01-28 19:06:25,199] [Log ] [27 ] [INFO ] - Number of HWPIDS that needs to be sent to tuner :11
[2016-01-28 19:06:25,202] [Log ] [27 ] [INFO ] - mdplug: SetChannel nr of currently decoding channels 0.
[2016-01-28 19:06:25,204] [Log ] [27 ] [INFO ] - mdplug: SetChannel starting decryption on channel 'Sjuan' using plugin slot 1 of 1 avail.
[2016-01-28 19:06:25,207] [Log ] [27 ] [INFO ] - emm len:6 9 4 B 0 E0 30
[2016-01-28 19:06:25,210] [Log ] [27 ] [INFO ] - EMM #0 CA:0xB00 EMM:0x30 ID:0x0
[2016-01-28 19:06:25,212] [Log ] [27 ] [INFO ] - ecm len:6 9 4 B 0 FC 26
[2016-01-28 19:06:25,215] [Log ] [27 ] [INFO ] - ECM #0 CA:0xB00 ECM:0x1C26 ID:0x0
[2016-01-28 19:06:25,218] [Log ] [27 ] [INFO ] - mdplug: tp_id:27(0x1B) sid:2108(0x83C) pmt_id:172(0xAC)
[2016-01-28 19:06:25,221] [Log ] [27 ] [INFO ] - mdplug: #0 CA_typ:2816(0xB00) ECM:7206(0x1C26) EMM:0x30 provider:0(0x0)
[2016-01-28 19:06:25,224] [Log ] [27 ] [INFO ] - mdplug: Send channel change to MDAPI filter Ca_Id:0 CA_Nr:1 ECM_PID:7206(0x1C26)
[2016-01-28 19:06:25,227] [Log ] [27 ] [INFO ] - subch:0 stop tif
[2016-01-28 19:06:25,230] [Log ] [27 ] [DEBUG] - WaitForPmt: PMT handling took 0,1050063 seconds.
[2016-01-28 19:06:25,238] [Log ] [27 ] [DEBUG] - card: Tuner locked: True
[2016-01-28 19:06:25,241] [Log ] [27 ] [INFO ] - ********
[2016-01-28 19:06:25,244] [Log ] [27 ] [INFO ] - SIGNAL LEVEL: 94, SIGNAL QUALITY: 82
[2016-01-28 19:06:25,246] [Log ] [27 ] [INFO ] - ********
[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📺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📺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📺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📺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📺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 ] - ********
[2016-01-28 19:06:34,440] [Log ] [27 ] [INFO ] - SIGNAL LEVEL: 95, SIGNAL QUALITY: 82
[2016-01-28 19:06:34,443] [Log ] [27 ] [INFO ] - ********
[2016-01-28 19:06:34,446] [Log ] [27 ] [DEBUG] - card: tuned user: Hometown subchannel: 0
[2016-01-28 19:06:34,449] [Log ] [27 ] [INFO ] - user:Hometown add
[2016-01-28 19:06:34,453] [Log ] [27 ] [INFO ] - card2:Hometown 4 0
[2016-01-28 19:06:34,456] [Log ] [27 ] [DEBUG] - Timeshifting started - Recordings=0 TimeShiftingActive=True
[2016-01-28 19:06:34,460] [Log ] [27 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartTimeShifting
[2016-01-28 19:06:34,463] [Log ] [27 ] [INFO ] - Controller: epg stop
[2016-01-28 19:06:34,466] [Log ] [27 ] [INFO ] - card: StartTimeShifting 4 C:\ProgramData\Team MediaPortal\MediaPortal TV Server\timeshiftbuffer\live4-0.ts
[2016-01-28 19:06:34,469] [Log ] [27 ] [INFO ] - card: CAM enabled : True
[2016-01-28 19:06:34,472] [Log ] [27 ] [INFO ] - card: WaitForFile - waiting _eventAudio & _eventVideo
[2016-01-28 19:06:34,987] [Log ] [29 ] [INFO ] - PID seen - type = Video
[2016-01-28 19:06:34,992] [Log ] [29 ] [INFO ] - audioVideoEventHandler Video
[2016-01-28 19:06:34,996] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:34
[2016-01-28 19:06:35,000] [Log ] [29 ] [INFO ] - video last seen at 2016-01-28 19:06:35
[2016-01-28 19:06:35,054] [Log ] [29 ] [INFO ] - PID seen - type = Audio
[2016-01-28 19:06:35,058] [Log ] [29 ] [INFO ] - audioVideoEventHandler Audio
[2016-01-28 19:06:35,062] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:35
[2016-01-28 19:06:35,066] [Log ] [27 ] [INFO ] - card: WaitForFile - video and audio are seen after 0,5900344 seconds
[2016-01-28 19:06:35,070] [Log ] [29 ] [INFO ] - audio last seen at 2016-01-28 19:06:35
[2016-01-28 19:06:35,074] [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:35,079] [Log ] [27 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=5, tuningdetails=DVBS📺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:35,082] [Log ] [27 ] [INFO ] - Controller: Hometown 4 0
[2016-01-28 19:06:35,085] [Log ] [27 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndZapChannel
[2016-01-28 19:06:35,088] [Log ] [27 ] [INFO ] - control2:Hometown 4 0
[2016-01-28 19:06:35,092] [Log ] [38 ] [DEBUG] - Controller: DoSetChannelStates for 1033 channels
[2016-01-28 19:06:35,099] [Log ] [38 ] [INFO ] - ChannelStates.GetAllTimeshiftingAndRecordingChannels took 0 msec
[2016-01-28 19:06:36,609] [Log ] [38 ] [INFO ] - ChannelStates.DoSetChannelStates took 1515 msec
[2016-01-28 19:06:39,869] [Log ] [27 ] [INFO ] - Controller: TimeShiftingWouldUseCard TV6 3086
[2016-01-28 19:06:39,873] [Log ] [27 ] [INFO ] - Controller: find free card for channel TV6
[2016-01-28 19:06:39,880] [Log ] [27 ] [INFO ] - Controller: find card for channel TV6
[2016-01-28 19:06:39,896] [Log ] [27 ] [INFO ] - Controller: got 1 tuning details for TV6
[2016-01-28 19:06:39,901] [Log ] [27 ] [INFO ] - Controller: channel #1 DVBS📺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:39,904] [Log ] [27 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:06:39,907] [Log ] [27 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:06:39,915] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:06:39,920] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:06:39,930] [Log ] [27 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:06:39,934] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 53 msec
[2016-01-28 19:06:39,937] [Log ] [27 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:06:39,940] [Log ] [27 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:06:39,943] [Log ] [27 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 70 msec
[2016-01-28 19:06:39,982] [Log ] [33 ] [INFO ] - Controller: StartTimeShifting TV6 3086
[2016-01-28 19:06:39,985] [Log ] [33 ] [INFO ] - Controller: epg stop
[2016-01-28 19:06:39,988] [Log ] [33 ] [INFO ] - Controller: find free card for channel TV6
[2016-01-28 19:06:39,990] [Log ] [33 ] [INFO ] - Controller: find card for channel TV6
[2016-01-28 19:06:39,994] [Log ] [33 ] [INFO ] - Controller: got 1 tuning details for TV6
[2016-01-28 19:06:39,998] [Log ] [33 ] [INFO ] - Controller: channel #1 DVBS📺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:40,001] [Log ] [33 ] [INFO ] - Controller: card:1 type:RadioWebStream is disabled
[2016-01-28 19:06:40,003] [Log ] [33 ] [INFO ] - Controller: card:5 type:DvbS is disabled
[2016-01-28 19:06:40,007] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS can tune to channel
[2016-01-28 19:06:40,010] [Log ] [33 ] [INFO ] - Controller: found 1 card(s) for channel
[2016-01-28 19:06:40,013] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 22 msec
[2016-01-28 19:06:40,016] [Log ] [33 ] [INFO ] - Controller: found 1 free card(s)
[2016-01-28 19:06:40,019] [Log ] [33 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 30 msec
[2016-01-28 19:06:40,024] [Log ] [33 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=6, tuningdetails=DVBS📺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:40,027] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS users: 0
[2016-01-28 19:06:40,030] [Log ] [33 ] [INFO ] - Controller: card:4 type:DvbS is available
[2016-01-28 19:06:40,032] [Log ] [33 ] [INFO ] - Controller: try max 1 of 1 cards for timeshifting
[2016-01-28 19:06:40,036] [Log ] [33 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartZapChannel
[2016-01-28 19:06:40,038] [Log ] [33 ] [DEBUG] - CardReservationBase: tvcard=4, user=Hometown, dbChannel=3086, ticket=6, tunestate=Tuning, stopstate=Idle
[2016-01-28 19:06:40,042] [Log ] [33 ] [INFO ] - card: CardTune 4 TV6 Hometown:4:-1
[2016-01-28 19:06:40,045] [Log ] [33 ] [INFO ] - card: Tune on card 4 to subchannel TV6
[2016-01-28 19:06:40,049] [Log ] [33 ] [DEBUG] - card: user: Hometown:4:0 tune DVBS📺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:40,057] [Log ] [33 ] [DEBUG] - card: to different transponder
[2016-01-28 19:06:40,060] [Log ] [33 ] [INFO ] - FreeSubChannel MD: freeing sub channel : 0
[2016-01-28 19:06:40,063] [Log ] [33 ] [INFO ] - mdplug: FreeChannel Kanal 5 HD (S)
[2016-01-28 19:06:40,066] [Log ] [33 ] [INFO ] - mdplug: usage counter for channel 'Kanal 5 HD (S)' is zero
[2016-01-28 19:06:40,069] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0
[2016-01-28 19:06:40,072] [Log ] [33 ] [INFO ] - tvcard:FreeSubChannel :0 - is timeshifting (skipped)
[2016-01-28 19:06:40,075] [Log ] [33 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events
[2016-01-28 19:06:40,077] [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:06:40,081] [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:06:40,084] [Log ] [33 ] [INFO ] - LNB low:9750 hi:10600 switch:11700
[2016-01-28 19:06:40,087] [Log ] [33 ] [INFO ] - dvbs:channel modulation is set to ModQpsk
[2016-01-28 19:06:40,089] [Log ] [33 ] [INFO ] - dvbs:channel FECRate is set to Rate3_4
[2016-01-28 19:06:40,092] [Log ] [33 ] [DEBUG] - Turbosight: set tone state, burst = DataBurst, 22 kHz = On
[2016-01-28 19:06:40,097] [Log ] [33 ] [DEBUG] - Turbosight: burst result = success
[2016-01-28 19:06:40,101] [Log ] [33 ] [DEBUG] - Turbosight: 22 kHz result = success
[2016-01-28 19:06:40,104] [Log ] [33 ] [INFO ] - Turbosight: Set DVB-S2
[2016-01-28 19:06:40,208] [Log ] [33 ] [INFO ] - dvb:Submiting tunerequest Channel:TV6 subChannel:0
[2016-01-28 19:06:40,212] [Log ] [33 ] [INFO ] - dvb:using existing subchannel:0
[2016-01-28 19:06:40,216] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest size:1 new:0
[2016-01-28 19:06:40,220] [Log ] [33 ] [INFO ] - subch:0 OnBeforeTune
[2016-01-28 19:06:40,224] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest
[2016-01-28 19:06:41,159] [Log ] [33 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest
[2016-01-28 19:06:41,164] [Log ] [33 ] [INFO ] - subch:0 OnAfterTune
[2016-01-28 19:06:41,168] [Log ] [33 ] [INFO ] - RunGraph
[2016-01-28 19:06:41,172] [Log ] [33 ] [INFO ] - dvb: LockInOnSignal ok
[2016-01-28 19:06:41,176] [Log ] [33 ] [INFO ] - subch:0 OnGraphStart
[2016-01-28 19:06:41,180] [Log ] [33 ] [INFO ] - subch:0 Graph already running - WaitForPMT
[2016-01-28 19:06:41,184] [Log ] [33 ] [INFO ] - subch:0 SetupPmtGrabber:pid 488 sid:488
[2016-01-28 19:06:41,189] [Log ] [33 ] [INFO ] - subch:0 set pmt grabber pmt:488 sid:488
[2016-01-28 19:06:41,193] [Log ] [33 ] [INFO ] - subch:0 set ca grabber
[2016-01-28 19:06:41,197] [Log ] [33 ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time
[2016-01-28 19:06:41,201] [Log ] [33 ] [DEBUG] - WaitForPMT: Waiting for PMT 488
[2016-01-28 19:06:41,204] [Log ] [29 ] [INFO ] - subch:OnCaReceived()
[2016-01-28 19:06:41,230] [Log ] [29 ] [INFO ] - subch:0 OnPMTReceived() pmt:488 ran:True dynamic:False
[2016-01-28 19:06:41,233] [Log ] [33 ] [DEBUG] - WaitForPMT: Found PMT after 0,0320016 seconds.
[2016-01-28 19:06:41,236] [Log ] [33 ] [INFO ] - subch:0 SendPmt:CA found after 0 seconds
[2016-01-28 19:06:41,238] [Log ] [33 ] [INFO ] - subch:0 SendPmt:488 488 FFFFFFFF 11
[2016-01-28 19:06:41,241] [Log ] [33 ] [INFO ] - Decode pmt
[2016-01-28 19:06:41,244] [Log ] [33 ] [INFO ] - descr2 pid:489 len:6 9 4 9 f e4 8d
[2016-01-28 19:06:41,246] [Log ] [33 ] [INFO ] - descr2 pid:489 len:6 9 4 9 3e e0 98
[2016-01-28 19:06:41,249] [Log ] [33 ] [INFO ] - descr2 pid:489 len:6 9 4 9 40 e1 92
[2016-01-28 19:06:41,252] [Log ] [33 ] [INFO ] - Set descriptor data with length 7
[2016-01-28 19:06:41,255] [Log ] [33 ] [INFO ] - Set descriptor data with length 6
[2016-01-28 19:06:41,257] [Log ] [33 ] [INFO ] - descr2 pid:48A len:6 9 4 9 f e4 8d
[2016-01-28 19:06:41,260] [Log ] [33 ] [INFO ] - descr2 pid:48A len:6 9 4 9 3e e0 98
[2016-01-28 19:06:41,263] [Log ] [33 ] [INFO ] - descr2 pid:48A len:6 9 4 9 40 e1 92
[2016-01-28 19:06:41,266] [Log ] [33 ] [INFO ] - Set descriptor data with length 6
[2016-01-28 19:06:41,268] [Log ] [33 ] [INFO ] - descr2 pid:48B len:6 9 4 9 f e4 8d
[2016-01-28 19:06:41,271] [Log ] [33 ] [INFO ] - descr2 pid:48B len:6 9 4 9 3e e0 98
[2016-01-28 19:06:41,274] [Log ] [33 ] [INFO ] - descr2 pid:48B len:6 9 4 9 40 e1 92
[2016-01-28 19:06:41,276] [Log ] [33 ] [INFO ] - subch:0 SendPMT version:17 len:109 1160
[2016-01-28 19:06:41,279] [Log ] [33 ] [DEBUG] - Turbosight: send PMT to CAM, list action = Only, command = Descrambling
[2016-01-28 19:06:41,282] [Log ] [33 ] [DEBUG] - Turbosight: CAM not available
[2016-01-28 19:06:41,284] [Log ] [33 ] [DEBUG] - Turbosight: is CAM ready
[2016-01-28 19:06:41,287] [Log ] [33 ] [DEBUG] - Turbosight: interface not opened
[2016-01-28 19:06:41,290] [Log ] [33 ] [INFO ] - subch:0 cam flags:False
[2016-01-28 19:06:41,293] [Log ] [33 ] [INFO ] - subch:0 SetMpegPidMapping
[2016-01-28 19:06:41,295] [Log ] [33 ] [INFO ] - subch:0 pid:489 pcr
[2016-01-28 19:06:41,298] [Log ] [33 ] [INFO ] - subch:0 pid:488 pmt
[2016-01-28 19:06:41,301] [Log ] [33 ] [INFO ] - subch:0 pid:489 video type:MPEG-2
[2016-01-28 19:06:41,303] [Log ] [33 ] [INFO ] - subch:0 map pid:489 video type:MPEG-2
[2016-01-28 19:06:41,306] [Log ] [33 ] [INFO ] - subch:0 pid:48E teletext type:6
[2016-01-28 19:06:41,309] [Log ] [33 ] [INFO ] - subch:0 map pid:48E teletext type:6
[2016-01-28 19:06:41,311] [Log ] [33 ] [INFO ] - subch:0 pid:48A audio lang:swe type:MPEG-1
[2016-01-28 19:06:41,314] [Log ] [33 ] [INFO ] - subch:0 map pid:48A audio lang:swe type:MPEG-1
[2016-01-28 19:06:41,317] [Log ] [33 ] [INFO ] - subch:0 pid:48B audio lang:syn type:MPEG-1
[2016-01-28 19:06:41,319] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 F E4 8D
[2016-01-28 19:06:41,322] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 3E E0 98
[2016-01-28 19:06:41,325] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 40 E1 92
[2016-01-28 19:06:41,328] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 F E4 8D
[2016-01-28 19:06:41,330] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 3E E0 98
[2016-01-28 19:06:41,333] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 40 E1 92
[2016-01-28 19:06:41,336] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 F E4 8D
[2016-01-28 19:06:41,339] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 3E E0 98
[2016-01-28 19:06:41,341] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 40 E1 92
[2016-01-28 19:06:41,344] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 F E0 C0
[2016-01-28 19:06:41,347] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 3E E0 C1
[2016-01-28 19:06:41,350] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 40 E0 C2
[2016-01-28 19:06:41,352] [Log ] [33 ] [INFO ] - Number of HWPIDS that needs to be sent to tuner :16
[2016-01-28 19:06:41,356] [Log ] [33 ] [INFO ] - mdplug: SetChannel nr of currently decoding channels 0.
[2016-01-28 19:06:41,358] [Log ] [33 ] [INFO ] - mdplug: SetChannel starting decryption on channel 'TV6' using plugin slot 1 of 1 avail.
[2016-01-28 19:06:41,361] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 F E0 C0
[2016-01-28 19:06:41,364] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 3E E0 C1
[2016-01-28 19:06:41,367] [Log ] [33 ] [INFO ] - emm len:6 9 4 9 40 E0 C2
[2016-01-28 19:06:41,369] [Log ] [33 ] [INFO ] - EMM #0 CA:0x90F EMM:0xC0 ID:0x0
[2016-01-28 19:06:41,372] [Log ] [33 ] [INFO ] - EMM #1 CA:0x93E EMM:0xC1 ID:0x0
[2016-01-28 19:06:41,375] [Log ] [33 ] [INFO ] - EMM #2 CA:0x940 EMM:0xC2 ID:0x0
[2016-01-28 19:06:41,378] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 F E4 8D
[2016-01-28 19:06:41,381] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 3E E0 98
[2016-01-28 19:06:41,383] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 40 E1 92
[2016-01-28 19:06:41,386] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 F E4 8D
[2016-01-28 19:06:41,389] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 3E E0 98
[2016-01-28 19:06:41,391] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 40 E1 92
[2016-01-28 19:06:41,394] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 F E4 8D
[2016-01-28 19:06:41,397] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 3E E0 98
[2016-01-28 19:06:41,400] [Log ] [33 ] [INFO ] - ecm len:6 9 4 9 40 E1 92
[2016-01-28 19:06:41,402] [Log ] [33 ] [INFO ] - ECM #0 CA:0x90F ECM:0x48D ID:0x0
[2016-01-28 19:06:41,405] [Log ] [33 ] [INFO ] - ECM #1 CA:0x93E ECM:0x98 ID:0x0
[2016-01-28 19:06:41,408] [Log ] [33 ] [INFO ] - ECM #2 CA:0x940 ECM:0x192 ID:0x0
[2016-01-28 19:06:41,410] [Log ] [33 ] [INFO ] - mdplug: tp_id:3(0x3) sid:1160(0x488) pmt_id:1160(0x488)
[2016-01-28 19:06:41,413] [Log ] [33 ] [INFO ] - mdplug: #0 CA_typ:2319(0x90F) ECM:1165(0x48D) EMM:0xC0 provider:0(0x0)
[2016-01-28 19:06:41,416] [Log ] [33 ] [INFO ] - mdplug: #1 CA_typ:2366(0x93E) ECM:152(0x98) EMM:0xC1 provider:0(0x0)
[2016-01-28 19:06:41,418] [Log ] [33 ] [INFO ] - mdplug: #2 CA_typ:2368(0x940) ECM:402(0x192) EMM:0xC2 provider:0(0x0)
[2016-01-28 19:06:41,422] [Log ] [33 ] [INFO ] - mdplug: Send channel change to MDAPI filter Ca_Id:0 CA_Nr:3 ECM_PID:1165(0x48D)
[2016-01-28 19:06:41,425] [Log ] [33 ] [INFO ] - subch:0 stop tif
[2016-01-28 19:06:41,428] [Log ] [33 ] [DEBUG] - WaitForPmt: PMT handling took 0,1920112 seconds.
[2016-01-28 19:06:41,436] [Log ] [33 ] [DEBUG] - card: Tuner locked: True
[2016-01-28 19:06:41,439] [Log ] [33 ] [INFO ] - ********
[2016-01-28 19:06:41,442] [Log ] [33 ] [INFO ] - SIGNAL LEVEL: 94, SIGNAL QUALITY: 80
[2016-01-28 19:06:41,444] [Log ] [33 ] [INFO ] - ********
[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📺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📺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📺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📺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📺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 ] - ********
[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 ] - ********
[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📺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📺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📺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📺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📺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 ] [INFO ] - EMM #0 CA:0xB00 EMM:0x30 ID:0x0
[2016-01-28 19:06:55,443] [Log ] [3 ] [INFO ] - ecm len:6 9 4 B 0 FB 76
[2016-01-28 19:06:55,445] [Log ] [3 ] [INFO ] - ECM #0 CA:0xB00 ECM:0x1B76 ID:0x0
[2016-01-28 19:06:55,448] [Log ] [3 ] [INFO ] - mdplug: tp_id:24(0x18) sid:4446(0x115E) pmt_id:394(0x18A)
[2016-01-28 19:06:55,451] [Log ] [3 ] [INFO ] - mdplug: #0 CA_typ:2816(0xB00) ECM:7030(0x1B76) EMM:0x30 provider:0(0x0)
[2016-01-28 19:06:55,454] [Log ] [3 ] [INFO ] - mdplug: Send channel change to MDAPI filter Ca_Id:0 CA_Nr:1 ECM_PID:7030(0x1B76)
[2016-01-28 19:06:55,457] [Log ] [3 ] [INFO ] - subch:0 stop tif
[2016-01-28 19:06:55,461] [Log ] [3 ] [DEBUG] - WaitForPmt: PMT handling took 0,1070063 seconds.
[2016-01-28 19:06:55,472] [Log ] [3 ] [DEBUG] - card: Tuner locked: True
[2016-01-28 19:06:55,475] [Log ] [3 ] [INFO ] - ********
[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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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📺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 !