[2015-12-13 14:47:13,385] [Log ] [18 ] [DEBUG] - TVServerKodi: New Connection! Starting handler thread for client.192.168.1.8:61360 [2015-12-13 14:47:13,391] [Log ] [18 ] [DEBUG] - TVServerKodi: Waiting for clients... [2015-12-13 14:47:13,391] [Log ] [21 ] [DEBUG] - TVServerKodi: connection accepted from XBMC PVR addon [2015-12-13 14:47:13,407] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetCardSettings [2015-12-13 14:47:13,470] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetBackendName [2015-12-13 14:47:13,470] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetVersion [2015-12-13 14:47:13,538] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: ListRadioChannels [2015-12-13 14:47:13,685] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: ListRadioGroups [2015-12-13 14:47:13,691] [Log ] [21 ] [DEBUG] - RemoteControl: TCP connect took : 1 [2015-12-13 14:47:13,807] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: ListTVChannels [2015-12-13 14:47:14,138] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: ListGroups [2015-12-13 14:47:14,154] [Log ] [21 ] [DEBUG] - RemoteControl: TCP connect took : 1 [2015-12-13 14:47:14,170] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: ListSchedules [2015-12-13 14:47:14,170] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: ListRecordings [2015-12-13 14:47:14,191] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:14,191] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:14,207] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:14,223] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:14,238] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:14,238] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:14,254] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:14,254] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:17,223] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:17,239] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:17,254] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:17,254] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:17,270] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:17,270] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:17,289] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:17,291] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:18,854] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetEPG [2015-12-13 14:47:18,869] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetEPG [2015-12-13 14:47:18,869] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetEPG [2015-12-13 14:47:18,891] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetEPG [2015-12-13 14:47:18,891] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetEPG [2015-12-13 14:47:18,954] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: ListSchedules [2015-12-13 14:47:18,954] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: ListRecordings [2015-12-13 14:47:20,270] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:20,292] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:20,292] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:20,307] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:20,307] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:20,323] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:20,323] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:20,323] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:23,339] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:23,339] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:23,339] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:23,355] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:23,355] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:23,355] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:23,355] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:23,355] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:26,055] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: TimeshiftChannel [2015-12-13 14:47:26,055] [Log ] [21 ] [INFO ] - TVServerKodi: Start timeshift for channel 93 for user 'XBMCpvrclient3 [2015-12-13 14:47:26,070] [Log ] [21 ] [INFO ] - Controller: StartTimeShifting Antena 2 93 [2015-12-13 14:47:26,070] [Log ] [21 ] [INFO ] - Controller: epg stop [2015-12-13 14:47:26,089] [EPG ] [21 ] [INFO ] - EPG: grabber stopped.. [2015-12-13 14:47:26,093] [Log ] [21 ] [INFO ] - Controller: find free card for channel Antena 2 [2015-12-13 14:47:26,093] [Log ] [21 ] [INFO ] - Controller: find card for channel Antena 2 [2015-12-13 14:47:26,093] [Log ] [21 ] [INFO ] - Controller: got 1 tuning details for Antena 2 [2015-12-13 14:47:26,108] [Log ] [21 ] [INFO ] - Controller: channel #1 DVBC:radio:SID Antena 2 Antena 2 Freq:362000 ONID:54 TSID:44 SID:1313 PMT:0x331 FTA:False LCN:10000 SymbolRate:6875 Modulation:Mod256Qam [2015-12-13 14:47:26,108] [Log ] [21 ] [INFO ] - Controller: card:1 type:RadioWebStream cannot tune to channel [2015-12-13 14:47:26,108] [Log ] [21 ] [INFO ] - Controller: card:2 type:DvbIP is disabled [2015-12-13 14:47:26,108] [Log ] [21 ] [INFO ] - Controller: card:3 type:DvbT is disabled [2015-12-13 14:47:26,108] [Log ] [21 ] [INFO ] - Controller: card:4 type:DvbC can tune to channel [2015-12-13 14:47:26,124] [Log ] [21 ] [INFO ] - Controller: card:5 type:DvbT is disabled [2015-12-13 14:47:26,124] [Log ] [21 ] [INFO ] - Controller: card:6 type:DvbC can tune to channel [2015-12-13 14:47:26,124] [Log ] [21 ] [INFO ] - Controller: found 2 card(s) for channel [2015-12-13 14:47:26,124] [Log ] [21 ] [INFO ] - AdvancedCardAllocation.GetAvailableCardsForChannel took 40 msec [2015-12-13 14:47:26,140] [Log ] [21 ] [INFO ] - Controller: found 2 free card(s) [2015-12-13 14:47:26,140] [Log ] [21 ] [INFO ] - AdvancedCardAllocation.GetFreeCardsForChannel took 51 msec [2015-12-13 14:47:26,140] [Log ] [21 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=4, tuningdetails=DVBC:radio:SID Antena 2 Antena 2 Freq:362000 ONID:54 TSID:44 SID:1313 PMT:0x331 FTA:False LCN:10000 SymbolRate:6875 Modulation:Mod256Qam [2015-12-13 14:47:26,140] [Log ] [21 ] [DEBUG] - CardReservationBase.RequestCardTuneReservation: placed reservation with id=5, tuningdetails=DVBC:radio:SID Antena 2 Antena 2 Freq:362000 ONID:54 TSID:44 SID:1313 PMT:0x331 FTA:False LCN:10000 SymbolRate:6875 Modulation:Mod256Qam [2015-12-13 14:47:26,155] [Log ] [21 ] [INFO ] - Controller: card:4 type:DvbC users: 0 [2015-12-13 14:47:26,155] [Log ] [21 ] [INFO ] - Controller: card:4 type:DvbC is available [2015-12-13 14:47:26,155] [Log ] [21 ] [INFO ] - Controller: card:6 type:DvbC users: 0 [2015-12-13 14:47:26,155] [Log ] [21 ] [INFO ] - Controller: card:6 type:DvbC is available [2015-12-13 14:47:26,171] [Log ] [21 ] [INFO ] - Controller: try max 2 of 2 cards for timeshifting [2015-12-13 14:47:26,171] [Log ] [21 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartZapChannel [2015-12-13 14:47:26,171] [Log ] [21 ] [DEBUG] - CardReservationBase: tvcard=4, user=XBMCpvrclient3, dbChannel=93, ticket=4, tunestate=Tuning, stopstate=Idle [2015-12-13 14:47:26,171] [Log ] [21 ] [INFO ] - card: CardTune 4 Antena 2 XBMCpvrclient3:4:-1 [2015-12-13 14:47:26,189] [Log ] [21 ] [INFO ] - card: Tune on card 4 to subchannel Antena 2 [2015-12-13 14:47:26,192] [Log ] [21 ] [DEBUG] - card: user: XBMCpvrclient3:4:-1 tune DVBC:radio:SID Antena 2 Antena 2 Freq:362000 ONID:54 TSID:44 SID:1313 PMT:0x331 FTA:False LCN:10000 SymbolRate:6875 Modulation:Mod256Qam [2015-12-13 14:47:26,192] [Log ] [21 ] [DEBUG] - TimeShifter.OnBeforeTune: resetting audio/video events [2015-12-13 14:47:26,192] [Log ] [21 ] [INFO ] - dvbc: Tune:DVBC:radio:SID Antena 2 Antena 2 Freq:362000 ONID:54 TSID:44 SID:1313 PMT:0x331 FTA:False LCN:10000 SymbolRate:6875 Modulation:Mod256Qam [2015-12-13 14:47:26,208] [Log ] [21 ] [INFO ] - dvb:Submiting tunerequest Channel:Antena 2 subChannel:-1 [2015-12-13 14:47:26,208] [Log ] [21 ] [INFO ] - dvb:Getting new subchannel [2015-12-13 14:47:26,208] [Log ] [21 ] [INFO ] - dvb:GetNewSubChannel:0 #0 [2015-12-13 14:47:26,208] [Log ] [21 ] [INFO ] - TvDvbChannel ctor new subchIndex:0 [2015-12-13 14:47:26,208] [Log ] [21 ] [INFO ] - card: AddTuneEvent card: 4 / subch: 0 [2015-12-13 14:47:26,224] [Log ] [21 ] [INFO ] - dvb:Submit tunerequest size:1 new:0 [2015-12-13 14:47:26,224] [Log ] [21 ] [INFO ] - subch:0 OnBeforeTune [2015-12-13 14:47:26,224] [Log ] [21 ] [INFO ] - dvb:Submit tunerequest calling put_TuneRequest [2015-12-13 14:47:26,224] [Log ] [21 ] [INFO ] - dvb:Submit tunerequest done calling put_TuneRequest [2015-12-13 14:47:26,239] [Log ] [21 ] [INFO ] - subch:0 OnAfterTune [2015-12-13 14:47:26,239] [Log ] [21 ] [INFO ] - RunGraph [2015-12-13 14:47:26,239] [Log ] [21 ] [INFO ] - subch:0 OnGraphStart [2015-12-13 14:47:26,239] [Log ] [21 ] [INFO ] - dvb: RunGraph [2015-12-13 14:47:26,371] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:26,423] [Log ] [21 ] [INFO ] - dvb: LockInOnSignal waiting 20ms [2015-12-13 14:47:26,455] [Log ] [21 ] [INFO ] - dvb: LockInOnSignal waiting 20ms [2015-12-13 14:47:26,486] [Log ] [21 ] [INFO ] - dvb: LockInOnSignal waiting 20ms [2015-12-13 14:47:26,524] [Log ] [21 ] [INFO ] - dvb: LockInOnSignal ok [2015-12-13 14:47:26,524] [Log ] [21 ] [INFO ] - subch:0 OnGraphStarted [2015-12-13 14:47:26,539] [Log ] [21 ] [INFO ] - subch:0 SetupPmtGrabber:pid 331 sid:521 [2015-12-13 14:47:26,539] [Log ] [21 ] [INFO ] - subch:0 set pmt grabber pmt:331 sid:521 [2015-12-13 14:47:26,555] [Log ] [21 ] [INFO ] - subch:0 set ca grabber [2015-12-13 14:47:26,555] [Log ] [21 ] [DEBUG] - TimeShifter.OnAfterTune: resetting audio/video time [2015-12-13 14:47:26,571] [Log ] [21 ] [DEBUG] - WaitForPMT: Waiting for PMT 331 [2015-12-13 14:47:26,571] [Log ] [9 ] [INFO ] - subch:OnCaReceived() [2015-12-13 14:47:26,592] [Log ] [9 ] [INFO ] - subch:0 OnPMTReceived() pmt:331 ran:True dynamic:False [2015-12-13 14:47:26,608] [Log ] [21 ] [DEBUG] - WaitForPMT: Found PMT after 0,0372275 seconds. [2015-12-13 14:47:26,608] [Log ] [21 ] [INFO ] - subch:0 SendPmt:CA found after 0 seconds [2015-12-13 14:47:26,608] [Log ] [21 ] [INFO ] - subch:0 SendPmt:521 521 FFFFFFFF C [2015-12-13 14:47:26,608] [Log ] [21 ] [INFO ] - Decode pmt [2015-12-13 14:47:26,608] [Log ] [21 ] [INFO ] - descr2 pid:1242 len:6 9 4 18 2 e4 4a [2015-12-13 14:47:26,623] [Log ] [21 ] [INFO ] - Set descriptor data with length 6 [2015-12-13 14:47:26,623] [Log ] [21 ] [INFO ] - subch:0 SendPMT version:12 len:33 1313 [2015-12-13 14:47:26,623] [Log ] [21 ] [INFO ] - subch:0 cam flags:True [2015-12-13 14:47:26,623] [Log ] [21 ] [INFO ] - subch:0 SetMpegPidMapping [2015-12-13 14:47:26,639] [Log ] [21 ] [INFO ] - subch:0 pid:1FFF pcr [2015-12-13 14:47:26,639] [Log ] [21 ] [INFO ] - subch:0 pid:331 pmt [2015-12-13 14:47:26,639] [Log ] [21 ] [INFO ] - subch:0 pid:1242 audio lang:por type:MPEG-2 [2015-12-13 14:47:26,639] [Log ] [21 ] [INFO ] - subch:0 map pid:1242 audio lang:por type:MPEG-2 [2015-12-13 14:47:26,955] [Log ] [21 ] [DEBUG] - card: Tuner locked: True [2015-12-13 14:47:26,970] [Log ] [21 ] [INFO ] - ************************************************** [2015-12-13 14:47:26,970] [Log ] [21 ] [INFO ] - ***** SIGNAL LEVEL: 50, SIGNAL QUALITY: 100 ***** [2015-12-13 14:47:26,970] [Log ] [21 ] [INFO ] - ************************************************** [2015-12-13 14:47:26,970] [Log ] [21 ] [DEBUG] - card: tuned user: XBMCpvrclient3 subchannel: 0 [2015-12-13 14:47:26,989] [Log ] [21 ] [INFO ] - user:XBMCpvrclient3 add [2015-12-13 14:47:26,992] [Log ] [21 ] [INFO ] - card2:XBMCpvrclient3 4 0 [2015-12-13 14:47:26,992] [Log ] [21 ] [INFO ] - Controller: delete timeshift files \\SVRMEDIA\timeshift\live4-0.ts [2015-12-13 14:47:27,008] [Log ] [21 ] [DEBUG] - TVServerKodi: OnTvServerEvent: StartTimeShifting [2015-12-13 14:47:27,008] [Log ] [21 ] [INFO ] - Controller: epg stop [2015-12-13 14:47:27,023] [Log ] [21 ] [INFO ] - card: StartTimeShifting 4 \\SVRMEDIA\timeshift\live4-0.ts [2015-12-13 14:47:27,023] [Log ] [21 ] [INFO ] - card: CAM enabled : True [2015-12-13 14:47:27,023] [Log ] [21 ] [INFO ] - subch:0 SetTimeShiftFileName:\\SVRMEDIA\timeshift\live4-0.ts [2015-12-13 14:47:27,023] [Log ] [21 ] [INFO ] - Set video / audio observer [2015-12-13 14:47:27,039] [Log ] [21 ] [INFO ] - subch:0 SetTimeShiftFileName fill in pids [2015-12-13 14:47:27,039] [Log ] [21 ] [INFO ] - subch:0-0 tswriter StartTimeshifting... [2015-12-13 14:47:27,039] [Log ] [21 ] [INFO ] - card: WaitForFile - waiting _eventAudio [2015-12-13 14:47:30,355] [Log ] [9 ] [INFO ] - PID seen - type = Audio [2015-12-13 14:47:30,371] [Log ] [9 ] [INFO ] - audioVideoEventHandler Audio [2015-12-13 14:47:30,371] [Log ] [21 ] [INFO ] - card: WaitForFile - audio is seen after 3,3315338 seconds [2015-12-13 14:47:30,393] [Log ] [21 ] [INFO ] - user:XBMCpvrclient3 card:4 sub:0 add stream:\\SVRMEDIA\timeshift\live4-0.ts.tsbuffer [2015-12-13 14:47:30,393] [Log ] [21 ] [INFO ] - RTSP: add stream stream4.0 file:\\SVRMEDIA\timeshift\live4-0.ts.tsbuffer [2015-12-13 14:47:30,424] [Log ] [21 ] [INFO ] - Controller: StartTimeShifting started on card:4 to \\SVRMEDIA\timeshift\live4-0.ts.tsbuffer [2015-12-13 14:47:30,424] [Log ] [21 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=4, tuningdetails=DVBC:radio:SID Antena 2 Antena 2 Freq:362000 ONID:54 TSID:44 SID:1313 PMT:0x331 FTA:False LCN:10000 SymbolRate:6875 Modulation:Mod256Qam [2015-12-13 14:47:30,424] [Log ] [21 ] [INFO ] - card: SignalTuneEvent card: 4 / subch: 0 [2015-12-13 14:47:30,424] [Log ] [21 ] [INFO ] - Controller: XBMCpvrclient3 4 0 [2015-12-13 14:47:30,440] [Log ] [21 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndZapChannel [2015-12-13 14:47:30,440] [Log ] [21 ] [DEBUG] - CardReservation.CancelCardReservation id=5 [2015-12-13 14:47:30,440] [Log ] [21 ] [INFO ] - control2:XBMCpvrclient3 4 0 [2015-12-13 14:47:30,455] [Log ] [21 ] [DEBUG] - TVServerKodi: Timeshift started for channel: 'Antena 2' on device 'Professional DVB Digital TV DVBC' [2015-12-13 14:47:30,471] [Log ] [21 ] [DEBUG] - TVServerKodi: TV Server returned 'rtsp://svrmedia:554/stream4.0' as timeshift URL and \\SVRMEDIA\timeshift\live4-0.ts.tsbuffer as timeshift file [2015-12-13 14:47:30,471] [Log ] [21 ] [DEBUG] - TVServerKodi: Remote server='svrmedia' [2015-12-13 14:47:30,471] [Log ] [21 ] [DEBUG] - TVServerKodi: StartTimeShifting took 4418 ms [2015-12-13 14:47:30,490] [Log ] [21 ] [DEBUG] - TVServerKodi: PlayChannel 93 => URL=rtsp://192.168.1.254/stream4.0 [2015-12-13 14:47:30,493] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:30,493] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:30,493] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:30,493] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:30,508] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:30,508] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:30,508] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:33,509] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:33,524] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:33,524] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:33,540] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:33,540] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:33,556] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:33,556] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:33,556] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:36,556] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:36,571] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace [2015-12-13 14:47:36,571] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:36,593] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetChannelCount [2015-12-13 14:47:36,593] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:36,593] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetScheduleCount [2015-12-13 14:47:36,609] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:36,609] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: GetRecordingCount [2015-12-13 14:47:37,288] [Log ] [21 ] [DEBUG] - TVServerKodi: Handling command: StopTimeshift [2015-12-13 14:47:37,294] [Log ] [21 ] [DEBUG] - TVServerKodi: OnTvServerEvent: EndTimeShifting [2015-12-13 14:47:37,294] [Log ] [21 ] [INFO ] - Controller: StopTimeShifting 4 [2015-12-13 14:47:37,309] [Log ] [21 ] [DEBUG] - CardTuner.RequestCardStopReservation: placed reservation with id=6, user=XBMCpvrclient3 [2015-12-13 14:47:37,424] [Log ] [21 ] [DEBUG] - CardTuner.Stop: ticket id=6, found=True [2015-12-13 14:47:37,424] [Log ] [21 ] [INFO ] - Stop cardid=4, ticket=6, tunestate=Idle, stopstate=Stopping [2015-12-13 14:47:37,424] [Log ] [21 ] [INFO ] - card Professional DVB Digital TV DVBC: StopTimeShifting user:XBMCpvrclient3 sub:0 [2015-12-13 14:47:37,440] [Log ] [21 ] [DEBUG] - card not IDLE - removing user: XBMCpvrclient3 [2015-12-13 14:47:37,455] [Log ] [21 ] [DEBUG] - usermanagement.RemoveUser: XBMCpvrclient3, subch: 0 of 1, card: 4 [2015-12-13 14:47:37,455] [Log ] [21 ] [INFO ] - user:XBMCpvrclient3 remove [2015-12-13 14:47:37,455] [Log ] [21 ] [INFO ] - subch:0-0 tswriter StopTimeshifting... [2015-12-13 14:47:37,471] [Log ] [21 ] [INFO ] - FreeSubChannel MD: freeing sub channel : 0 [2015-12-13 14:47:37,488] [Log ] [21 ] [INFO ] - mdplug: FreeChannel Antena 2 [2015-12-13 14:47:37,493] [Log ] [21 ] [INFO ] - mdplug: usage counter for channel 'Antena 2' is zero [2015-12-13 14:47:37,493] [Log ] [21 ] [INFO ] - tvcard:FreeSubChannel: subchannels count 1 subch#0 [2015-12-13 14:47:37,493] [Log ] [21 ] [INFO ] - DVB subch:0 Decompose() [2015-12-13 14:47:37,493] [Log ] [21 ] [INFO ] - FreeSubChannel CA: freeing sub channel : 0 [2015-12-13 14:47:37,509] [Log ] [21 ] [INFO ] - tvcard:FreeSubChannel : no subchannels present, pausing graph [2015-12-13 14:47:37,509] [Log ] [21 ] [INFO ] - dvb:StopGraph called [2015-12-13 14:47:37,509] [Log ] [21 ] [INFO ] - tvcard:FreeAllSubChannels [2015-12-13 14:47:37,509] [Log ] [21 ] [INFO ] - mdplug: FreeAllChannels [2015-12-13 14:47:37,525] [Log ] [21 ] [INFO ] - dvb:StopGraph [2015-12-13 14:47:37,525] [Log ] [21 ] [INFO ] - debug: IMediaControl stopped! hr = 0x0 :) [2015-12-13 14:47:37,525] [Log ] [21 ] [INFO ] - dvb:StopGraph called [2015-12-13 14:47:37,540] [Log ] [TS_File_Cleanup] [INFO ] - card: delete timeshift files \\SVRMEDIA\timeshift\live4-0.ts [2015-12-13 14:47:37,540] [Log ] [21 ] [INFO ] - tvcard:FreeAllSubChannels [2015-12-13 14:47:37,540] [Log ] [21 ] [INFO ] - mdplug: FreeAllChannels [2015-12-13 14:47:37,540] [Log ] [21 ] [INFO ] - dvb:StopGraph filterstate already stopped, returning. [2015-12-13 14:47:37,556] [Log ] [21 ] [INFO ] - user:XBMCpvrclient3 remove [2015-12-13 14:47:37,556] [Log ] [21 ] [DEBUG] - CardReservation.RemoveStopTicket: removed STOP reservation with id=6 [2015-12-13 14:47:37,556] [Log ] [21 ] [INFO ] - Controller:Timeshifting stopped on card:4 [2015-12-13 14:47:37,556] [Log ] [21 ] [INFO ] - RTSP: remove stream stream4.0 [2015-12-13 14:47:37,572] [Log ] [21 ] [INFO ] - Controller: epg start [2015-12-13 14:47:37,609] [EPG ] [21 ] [INFO ] - EPG: grabber initialized for 2 transponders.. [2015-12-13 14:47:39,610] [Log ] [28 ] [DEBUG] - TVServerKodi: Handling command: GetDriveSpace