- July 21, 2011
- 130
- 16
- Home Country
- United States of America
Good afternoon,
I'm breaking this off of another thread, since the issue I'm experiencing no longer seems to be related to the other topic ( https://forum.team-mediaportal.com/...e-when-using-spdif.118549/page-4#post-1050516 )
Anyway, so the issue is that at the end of a buffer file, the TV Server service will randomly quit creating more buffer files, causing the client PC to appear 'frozen' while watching TV. In the example below, it almost looks like the TV3BlasterPlugin caused this instance. Any thoughts as to why this would occur, or better ways to debug this?
As a first step, I am disabling the TVServerXBMC plugin I hardly use to see if things stabilize.
Thank you!
TVService.log:
[2014-01-05 13:16:24,349] [Log ] [30 ] [INFO ] - RTSP: add stream stream3.0 file:E:\Timeshift\live3-0.ts.tsbuffer
[2014-01-05 13:16:24,351] [Log ] [30 ] [INFO ] - Controller: StartTimeShifting started on card:3 to E:\Timeshift\live3-0.ts.tsbuffer
[2014-01-05 13:16:24,351] [Log ] [30 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=47, tuningdetails=tv:USAHD Freq:0 Channel:242 Country:United States Tuner:Cable Video:YRYBYInput1 AudioPDIFInput1
[2014-01-05 13:16:24,351] [Log ] [30 ] [INFO ] - Controller: ITX 3 0
[2014-01-05 13:16:24,352] [Log ] [30 ] [DEBUG] - TV3BlasterPlugin: Received TV Server Event "EndZapChannel"
[2014-01-05 13:16:24,352] [Log ] [30 ] [DEBUG] - TVServerXBMC: OnTvServerEvent: EndZapChannel
[2014-01-05 13:16:24,352] [Log ] [30 ] [DEBUG] - CardReservation.CancelCardReservation id=48
[2014-01-05 13:16:24,353] [Log ] [30 ] [INFO ] - control2:ITX 3 0
[2014-01-05 13:16:24,354] [Log ] [Channel state thread] [DEBUG] - Controller: DoSetChannelStates for 243 channels
[2014-01-05 13:16:24,357] [Log ] [30 ] [DEBUG] - CiMenuSupported called cardid 3
[2014-01-05 13:16:24,357] [Log ] [30 ] [DEBUG] - CiMenuSupported card Hauppauge HD PVR Crossbar supported: False
[2014-01-05 13:16:24,363] [Log ] [Channel state thread] [INFO ] - ChannelStates.GetAllTimeshiftingAndRecordingChannels took 0 msec
[2014-01-05 13:16:25,331] [Log ] [Channel state thread] [INFO ] - ChannelStates.DoSetChannelStates took 976 msec
[2014-01-05 13:21:07,069] [Log ] [30 ] [DEBUG] - TV3BlasterPlugin: Received TV Server Event "EndTimeShifting"
[2014-01-05 13:21:07,070] [Log ] [30 ] [DEBUG] - TVServerXBMC: OnTvServerEvent: EndTimeShifting
[2014-01-05 13:21:07,070] [Log ] [30 ] [INFO ] - Controller: StopTimeShifting 3
[2014-01-05 13:21:07,072] [Log ] [30 ] [DEBUG] - CardTuner.RequestCardStopReservation: placed reservation with id=49, user=ITX
[2014-01-05 13:21:07,172] [Log ] [30 ] [DEBUG] - CardTuner.Stop: ticket id=49, found=True
[2014-01-05 13:21:07,172] [Log ] [30 ] [INFO ] - Stop cardid=3, ticket=49, tunestate=Idle, stopstate=Stopping
[2014-01-05 13:21:07,172] [Log ] [30 ] [INFO ] - card Hauppauge HD PVR Crossbar: StopTimeShifting user:ITX sub:0
TSWriter.log:
[2014-01-05 13:16:24,339] [b2766a8] [14f4] - Recorder: TIMESHIFT Start 'E:\Timeshift\live3-0.ts.tsbuffer'
[2014-01-05 13:16:24,345] [b2766a8] [1260] - Recorder: TIMESHIFT start of audio detected
[2014-01-05 13:16:24,346] [b2766a8] [1260] - Recorder: TIMESHIFT start of video detected
[2014-01-05 13:16:24,379] [b2766a8] [1260] - Recorder: TIMESHIFT clear TS packet queue
[2014-01-05 13:16:24,379] [b2766a8] [1260] - CDiskRecorder::WriteToTimeshiftFile() - Reset write buffer throttle
[2014-01-05 13:16:24,379] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 376 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - Recorder: TIMESHIFT Info : Next broadcaster program clock reference rollover : 1 days 02:30:40 0
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 564 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 940 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 940 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 940 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 940 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 940 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 1880 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 1880 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 1880 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 1880 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 1880 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 3760 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 3760 bytes
[2014-01-05 13:16:24,394] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 3760 bytes
[2014-01-05 13:16:24,394] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 6016 bytes
[2014-01-05 13:16:24,394] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 7520 bytes
[2014-01-05 13:16:24,413] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 9400 bytes
[2014-01-05 13:16:24,413] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 15416 bytes
[2014-01-05 13:16:24,430] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 32336 bytes (max)
[2014-01-05 13:21:07,174] [b2766a8] [14f4] - Recorder: TIMESHIFT Stop 'E:\Timeshift\live3-0.ts.tsbuffer'
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - Recorder: TIMESHIFT Reset
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - CDiskRecorder::Reset() - Reset write buffer throttle
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - debug: DeleteChannel()
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del m_pVideoAnalyzer
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - analyzer: reset
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del m_pPmtGrabber
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del m_pRecorder
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del m_pTimeShifting
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del m_pTeletextGrabber
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del m_pCaGrabber
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del done...
[2014-01-05 13:21:07,177] [b2766a8] [14f4] - CMpTsFilter:ause()
[2014-01-05 13:21:07,177] [b2766a8] [14f4] - Pause filter...
[2014-01-05 13:21:07,177] [b2766a8] [14f4] - HRESULT = 0x0
[2014-01-05 13:21:09,972] [b2766a8] [14f4] - CMpTsFilter:top()
[2014-01-05 13:21:09,972] [b2766a8] [14f4] - Stop streaming...
I'm breaking this off of another thread, since the issue I'm experiencing no longer seems to be related to the other topic ( https://forum.team-mediaportal.com/...e-when-using-spdif.118549/page-4#post-1050516 )
Anyway, so the issue is that at the end of a buffer file, the TV Server service will randomly quit creating more buffer files, causing the client PC to appear 'frozen' while watching TV. In the example below, it almost looks like the TV3BlasterPlugin caused this instance. Any thoughts as to why this would occur, or better ways to debug this?
As a first step, I am disabling the TVServerXBMC plugin I hardly use to see if things stabilize.
Thank you!
TVService.log:
[2014-01-05 13:16:24,349] [Log ] [30 ] [INFO ] - RTSP: add stream stream3.0 file:E:\Timeshift\live3-0.ts.tsbuffer
[2014-01-05 13:16:24,351] [Log ] [30 ] [INFO ] - Controller: StartTimeShifting started on card:3 to E:\Timeshift\live3-0.ts.tsbuffer
[2014-01-05 13:16:24,351] [Log ] [30 ] [DEBUG] - CardReservation.RemoveTuneTicket: removed reservation with id=47, tuningdetails=tv:USAHD Freq:0 Channel:242 Country:United States Tuner:Cable Video:YRYBYInput1 AudioPDIFInput1
[2014-01-05 13:16:24,351] [Log ] [30 ] [INFO ] - Controller: ITX 3 0
[2014-01-05 13:16:24,352] [Log ] [30 ] [DEBUG] - TV3BlasterPlugin: Received TV Server Event "EndZapChannel"
[2014-01-05 13:16:24,352] [Log ] [30 ] [DEBUG] - TVServerXBMC: OnTvServerEvent: EndZapChannel
[2014-01-05 13:16:24,352] [Log ] [30 ] [DEBUG] - CardReservation.CancelCardReservation id=48
[2014-01-05 13:16:24,353] [Log ] [30 ] [INFO ] - control2:ITX 3 0
[2014-01-05 13:16:24,354] [Log ] [Channel state thread] [DEBUG] - Controller: DoSetChannelStates for 243 channels
[2014-01-05 13:16:24,357] [Log ] [30 ] [DEBUG] - CiMenuSupported called cardid 3
[2014-01-05 13:16:24,357] [Log ] [30 ] [DEBUG] - CiMenuSupported card Hauppauge HD PVR Crossbar supported: False
[2014-01-05 13:16:24,363] [Log ] [Channel state thread] [INFO ] - ChannelStates.GetAllTimeshiftingAndRecordingChannels took 0 msec
[2014-01-05 13:16:25,331] [Log ] [Channel state thread] [INFO ] - ChannelStates.DoSetChannelStates took 976 msec
[2014-01-05 13:21:07,069] [Log ] [30 ] [DEBUG] - TV3BlasterPlugin: Received TV Server Event "EndTimeShifting"
[2014-01-05 13:21:07,070] [Log ] [30 ] [DEBUG] - TVServerXBMC: OnTvServerEvent: EndTimeShifting
[2014-01-05 13:21:07,070] [Log ] [30 ] [INFO ] - Controller: StopTimeShifting 3
[2014-01-05 13:21:07,072] [Log ] [30 ] [DEBUG] - CardTuner.RequestCardStopReservation: placed reservation with id=49, user=ITX
[2014-01-05 13:21:07,172] [Log ] [30 ] [DEBUG] - CardTuner.Stop: ticket id=49, found=True
[2014-01-05 13:21:07,172] [Log ] [30 ] [INFO ] - Stop cardid=3, ticket=49, tunestate=Idle, stopstate=Stopping
[2014-01-05 13:21:07,172] [Log ] [30 ] [INFO ] - card Hauppauge HD PVR Crossbar: StopTimeShifting user:ITX sub:0
TSWriter.log:
[2014-01-05 13:16:24,339] [b2766a8] [14f4] - Recorder: TIMESHIFT Start 'E:\Timeshift\live3-0.ts.tsbuffer'
[2014-01-05 13:16:24,345] [b2766a8] [1260] - Recorder: TIMESHIFT start of audio detected
[2014-01-05 13:16:24,346] [b2766a8] [1260] - Recorder: TIMESHIFT start of video detected
[2014-01-05 13:16:24,379] [b2766a8] [1260] - Recorder: TIMESHIFT clear TS packet queue
[2014-01-05 13:16:24,379] [b2766a8] [1260] - CDiskRecorder::WriteToTimeshiftFile() - Reset write buffer throttle
[2014-01-05 13:16:24,379] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 376 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - Recorder: TIMESHIFT Info : Next broadcaster program clock reference rollover : 1 days 02:30:40 0
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 564 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 940 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 940 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 940 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 940 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 940 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 1880 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 1880 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 1880 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 1880 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 1880 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 3760 bytes
[2014-01-05 13:16:24,381] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 3760 bytes
[2014-01-05 13:16:24,394] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 3760 bytes
[2014-01-05 13:16:24,394] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 6016 bytes
[2014-01-05 13:16:24,394] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 7520 bytes
[2014-01-05 13:16:24,413] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 9400 bytes
[2014-01-05 13:16:24,413] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 15416 bytes
[2014-01-05 13:16:24,430] [b2766a8] [1260] - CDiskRecorder::Flush() - Throttle to 32336 bytes (max)
[2014-01-05 13:21:07,174] [b2766a8] [14f4] - Recorder: TIMESHIFT Stop 'E:\Timeshift\live3-0.ts.tsbuffer'
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - Recorder: TIMESHIFT Reset
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - CDiskRecorder::Reset() - Reset write buffer throttle
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - debug: DeleteChannel()
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del m_pVideoAnalyzer
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - analyzer: reset
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del m_pPmtGrabber
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del m_pRecorder
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del m_pTimeShifting
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del m_pTeletextGrabber
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del m_pCaGrabber
[2014-01-05 13:21:07,175] [b2766a8] [14f4] - del done...
[2014-01-05 13:21:07,177] [b2766a8] [14f4] - CMpTsFilter:ause()
[2014-01-05 13:21:07,177] [b2766a8] [14f4] - Pause filter...
[2014-01-05 13:21:07,177] [b2766a8] [14f4] - HRESULT = 0x0
[2014-01-05 13:21:09,972] [b2766a8] [14f4] - CMpTsFilter:top()
[2014-01-05 13:21:09,972] [b2766a8] [14f4] - Stop streaming...