- July 15, 2010
- 64
- 8
- Home Country
-
Scotland
Hi all. Yesterday we recently upgraded our router to a Billion BiPAC 7800N and now I seem to be having problems watching HD recordings that are still being recorded. I have no idea if the new router is related, but it isn't an issue I have noticed before now. That said, it is entirely possible that I simply didn't notice until now.
Watching anything directly on the TV server is fine. On the clients I can watch live TV (regardless of the resolution/format or whether it is being recorded) without a hitch. Likewise, recordings play fine on the clients as long as they are not currently being recorded. However, if a program is currently being recorded and I try to watch it on one of the clients from the recordings page (rather than simply tuning in that channel or selecting the appropriate TV stream) it is filled with continuity errors and so the picture breaks up and the sound "pops" maybe a few times a minute, similar to how it would play if the signal were poor. This only seems to be a problem with HD channels, although that may simply be due to the lower throughput requirements of SD recordings.
The problem affects two separate clients equally, so would seem to be either network related or something wrong with the TV server.
I have posted below an example of the TsReader.log from the primary client when playing back HD content currently being recorded:
If any other logs are required I can easily post them (the problem is fairly easy to reproduce, so logs from specific times shouldn't be difficult to get).
My setup is now somewhat different to that listed in my hardware page, as I upgraded it just before Christmas and haven't updated my page yet. I now have a multi-seat setup; the TV-server's specs are listed at the end of the post, while the primary client is as listed on my specs page, sans TV tuners. The second client isn't really used very much - it is a Dell M1530 laptop, with a 2.4GHz Core 2 Duo CPU, an nVidia GeForce 8600M GPU and 4 GB DDR2 RAM running Windows Vista Home Premium (32-bit).
Both the TV server and the primary client are connected via ethernet to a Netgear 100 Mbps ethernet switch, which is in turn connected to the router. (I have ordered a TP-link 1 Gbps switch to replace the Netgear, so if that is the cause somehow then it's not really a problem.) The laptop connects to the same network via 802.11n Wi-Fi.
TV-server specs:
Watching anything directly on the TV server is fine. On the clients I can watch live TV (regardless of the resolution/format or whether it is being recorded) without a hitch. Likewise, recordings play fine on the clients as long as they are not currently being recorded. However, if a program is currently being recorded and I try to watch it on one of the clients from the recordings page (rather than simply tuning in that channel or selecting the appropriate TV stream) it is filled with continuity errors and so the picture breaks up and the sound "pops" maybe a few times a minute, similar to how it would play if the signal were poor. This only seems to be a problem with HD channels, although that may simply be due to the lower throughput requirements of SD recordings.
The problem affects two separate clients equally, so would seem to be either network related or something wrong with the TV server.
I have posted below an example of the TsReader.log from the primary client when playing back HD content currently being recorded:
Code:
09-01-2013 23:31:16.723 [288c]--------------- v0.4.17a -------------------
09-01-2013 23:31:16.724 [288c]CTsReaderFilter::ctor
09-01-2013 23:31:16.724 [288c]CRTSPClient::Initialize()
09-01-2013 23:31:16.724 [288c]CRTSPClient::createClient()
09-01-2013 23:31:16.725 [288c]Slow motion video allowed during zapping
09-01-2013 23:31:16.725 [288c]Wait for seeking to eof - false - constructor
09-01-2013 23:31:16.725 [288c]SetRelaxedMode
09-01-2013 23:31:16.725 [288c]Relaxed discontinuities filtering
09-01-2013 23:31:16.726 [288c]CALLBACK SET
09-01-2013 23:31:16.726 [288c]SetRequestAudioChangeCallback SET
09-01-2013 23:31:16.727 [288c]CTsReaderFilter::Load()
09-01-2013 23:31:16.727 [288c]open rtsp:rtsp://MediaPortal:554/C5B1A8DB
09-01-2013 23:31:16.727 [288c]CRTSPClient::OpenStream()
09-01-2013 23:31:16.727 [288c]CRTSPClient::getSDPDescriptionFromURL()
09-01-2013 23:31:16.746 [288c]rangestart:0.000000 rangeend:34.147000
09-01-2013 23:31:16.751 [288c]Created receiver for video MP2T 62802 62803
09-01-2013 23:31:16.751 [288c]rtsp:increaseReceiveBufferTo to 2000000 for s:3996
09-01-2013 23:31:16.752 [288c]CRTSPClient::setupStreams()
09-01-2013 23:31:16.752 [288c]CRTSPClient::clientSetupSubsession()
09-01-2013 23:31:16.756 [288c]Setup video MP2T 62802 62803
09-01-2013 23:31:16.756 [288c]CMemorySink::ctor
09-01-2013 23:31:16.756 [288c]Created output sink:
09-01-2013 23:31:16.756 [288c]memorybuffer: Clear() 0
09-01-2013 23:31:16.757 [288c]memorybuffer: Clear() done
09-01-2013 23:31:16.757 [288c]memorybuffer: run:1 1
09-01-2013 23:31:16.757 [288c]memorybuffer: running:1
09-01-2013 23:31:16.757 [288c]CRTSPClient::Play from 0.000000 / 0.000000
09-01-2013 23:31:16.757 [288c]CRTSPClient::startPlayingStreams()
09-01-2013 23:31:16.758 [288c]CRTSPClient::clientStartPlayingSession()
09-01-2013 23:31:16.758 [288c]CRTSPClient::clientStartPlayingSession() play from 0.000 / 34.147
09-01-2013 23:31:16.762 [288c]Started playing session
09-01-2013 23:31:16.763 [288c]CRTSPClient::StartBufferThread
09-01-2013 23:31:16.763 [288c]CRTSPClient::StartBufferThread done
09-01-2013 23:31:16.763 [2d8c]CRTSPClient:: thread started:11660
09-01-2013 23:31:16.773 [288c]OnNewChannel: PAT change detected: -1->1
09-01-2013 23:31:16.773 [288c]demux:flushing
09-01-2013 23:31:16.773 [288c]demux:set hold audio:1
09-01-2013 23:31:16.773 [288c]demux:set hold video:1
09-01-2013 23:31:16.774 [288c]demux:set hold subtitle:1
09-01-2013 23:31:16.774 [288c]demux:flush audio
09-01-2013 23:31:16.774 [288c]demux:flush video
09-01-2013 23:31:16.774 [288c]demux:flush subtitle
09-01-2013 23:31:16.774 [288c]demux:set hold audio:0
09-01-2013 23:31:16.775 [288c]demux:set hold video:0
09-01-2013 23:31:16.775 [288c]demux:set hold subtitle:0
09-01-2013 23:31:16.775 [288c]New channel found (PAT/PMT/SDT changed)
09-01-2013 23:31:16.775 [288c] pcr pid: 30
09-01-2013 23:31:16.775 [288c] pmt pid: 20
09-01-2013 23:31:16.776 [288c] video pid: 30 type: H264
09-01-2013 23:31:16.776 [288c] audio pid: 40 language: deu type: MPEG1 - audio
09-01-2013 23:31:16.776 [288c] audio pid: 41 language: mis type: MPEG1 - audio
09-01-2013 23:31:16.776 [288c] audio pid: 42 language: mul type: MPEG1 - audio
09-01-2013 23:31:16.776 [288c] audio pid: 43 language: deu type: AC3
09-01-2013 23:31:16.777 [288c]Setting initial audio index to : 0
09-01-2013 23:31:16.777 [288c]OnRequestAudioChange()
09-01-2013 23:31:16.777 [288c]demux:Wait for Audio stream selection :1
09-01-2013 23:31:16.787 [288c]SetAudioStream : 3
09-01-2013 23:31:16.787 [288c]Old Audio -1, New Audio 129
09-01-2013 23:31:16.787 [288c]demux:Wait for Audio stream selection :0
09-01-2013 23:31:16.791 [288c]New Audio 129
09-01-2013 23:31:17.142 [288c]DeMultiplexer: First Gop parsed after new PAT: res=1280x720 AR=16:9 fps=50 isInterlaced=0
09-01-2013 23:31:17.143 [288c]DeMultiplexer: 30 video format changed: res=1280x720 aspectRatio=16:9 fps=50 isInterlaced=0
09-01-2013 23:31:17.143 [288c]DeMultiplexer: triggering OnVideoFormatChanged
09-01-2013 23:31:17.143 [288c]demux:flushing
09-01-2013 23:31:17.144 [288c]demux:set hold audio:1
09-01-2013 23:31:17.144 [288c]demux:set hold video:1
09-01-2013 23:31:17.144 [288c]demux:set hold subtitle:1
09-01-2013 23:31:17.144 [288c]demux:flush audio
09-01-2013 23:31:17.145 [288c]demux:flush video
09-01-2013 23:31:17.145 [288c]demux:flush subtitle
09-01-2013 23:31:17.145 [288c]demux:set hold audio:0
09-01-2013 23:31:17.145 [288c]demux:set hold video:0
09-01-2013 23:31:17.145 [288c]demux:set hold subtitle:0
09-01-2013 23:31:17.146 [288c]demux:Start() end1 BytesProcessed:639576
09-01-2013 23:31:17.146 [288c]memorybuffer: run:0 1
09-01-2013 23:31:17.146 [288c]memorybuffer: Clear() 8
09-01-2013 23:31:17.146 [288c]memorybuffer: Clear() done
09-01-2013 23:31:17.147 [288c]memorybuffer: running:0
09-01-2013 23:31:17.147 [288c]close rtsp:rtsp://MediaPortal:554/C5B1A8DB
09-01-2013 23:31:17.147 [288c]CRTSPClient:Stop
09-01-2013 23:31:17.147 [288c]CRTSPClient::StopBufferThread
09-01-2013 23:31:17.148 [2d8c]CRTSPClient:: thread stopped:11660
09-01-2013 23:31:17.148 [288c]CRTSPClient::StopBufferThread done
09-01-2013 23:31:17.148 [288c]CRTSPClient::shutdown()
09-01-2013 23:31:17.149 [288c]CRTSPClient::closeMediaSinks()
09-01-2013 23:31:17.149 [288c]CMemorySink::dtor
09-01-2013 23:31:17.149 [288c]CRTSPClient::tearDownStreams()
09-01-2013 23:31:17.149 [288c]CRTSPClient::clientTearDownSession()
09-01-2013 23:31:17.151 [288c]memorybuffer: Clear() 3
09-01-2013 23:31:17.152 [288c]memorybuffer: Clear() done
09-01-2013 23:31:17.152 [288c]CRTSPClient:Stop done
09-01-2013 23:31:17.387 [288c]aud:CompleteConnect()
09-01-2013 23:31:17.388 [288c]aud:CompleteConnect() done
09-01-2013 23:31:17.426 [288c]vid:CompleteConnect() FFDShow Video Decoder connected, fast sync enabled
09-01-2013 23:31:17.426 [288c]vid:CompleteConnect() done
09-01-2013 23:31:17.440 [288c]pin:CompleteConnect()
09-01-2013 23:31:17.441 [288c]pin:CompleteConnect() done
09-01-2013 23:31:17.441 [288c]sub:CompleteConnect() ok
09-01-2013 23:31:17.444 [288c]SUCCESS
09-01-2013 23:31:17.447 [288c]Setting Teletext TS packet callback
09-01-2013 23:31:17.447 [288c]Setting Teletext Event callback
09-01-2013 23:31:17.448 [288c]Setting Teletext Service Info callback
09-01-2013 23:31:17.450 [288c]SUCCESS
09-01-2013 23:31:17.481 [288c]CTsReaderFilter::Pause() - IsTimeShifting = 0 - state = 0
09-01-2013 23:31:17.482 [1d74]aud:OnThreadStartPlay(0.000000) 1.00
09-01-2013 23:31:17.483 [2a1c]vid:OnThreadStartPlay(0.000000) 1.00 0
09-01-2013 23:31:17.483 [2dc8]demux:set hold subtitle:0
09-01-2013 23:31:17.483 [288c] -- Pause() ->start rtsp from 0.000000
09-01-2013 23:31:17.484 [2dc8]sub:OnThreadStartPlay(0.000000)
09-01-2013 23:31:17.484 [288c]memorybuffer: Clear() 0
09-01-2013 23:31:17.484 [288c]memorybuffer: Clear() done
09-01-2013 23:31:17.484 [288c]demux:flushing
09-01-2013 23:31:17.485 [288c]demux:set hold audio:1
09-01-2013 23:31:17.485 [288c]demux:set hold video:1
09-01-2013 23:31:17.485 [288c]demux:set hold subtitle:1
09-01-2013 23:31:17.485 [288c]demux:flush audio
09-01-2013 23:31:17.486 [288c]demux:flush video
09-01-2013 23:31:17.486 [288c]demux:flush subtitle
09-01-2013 23:31:17.486 [288c]demux:set hold audio:0
09-01-2013 23:31:17.487 [288c]demux:set hold video:0
09-01-2013 23:31:17.487 [288c]demux:set hold subtitle:0
09-01-2013 23:31:17.487 [288c]memorybuffer: run:1 0
09-01-2013 23:31:17.487 [288c]memorybuffer: running:1
09-01-2013 23:31:17.487 [288c]CRTSPClient::Play from 0.000000 / 0.000000
09-01-2013 23:31:17.488 [288c]memorybuffer: Clear() 0
09-01-2013 23:31:17.488 [288c]memorybuffer: Clear() done
09-01-2013 23:31:17.488 [288c]CRTSPClient::Initialize()
09-01-2013 23:31:17.488 [288c]CRTSPClient::createClient()
09-01-2013 23:31:17.488 [288c]CRTSPClient::OpenStream()
09-01-2013 23:31:17.489 [288c]CRTSPClient::getSDPDescriptionFromURL()
09-01-2013 23:31:17.498 [288c]rangestart:0.000000 rangeend:34.937000
09-01-2013 23:31:17.502 [288c]Created receiver for video MP2T 60580 60581
09-01-2013 23:31:17.502 [288c]rtsp:increaseReceiveBufferTo to 2000000 for s:4100
09-01-2013 23:31:17.502 [288c]CRTSPClient::setupStreams()
09-01-2013 23:31:17.503 [288c]CRTSPClient::clientSetupSubsession()
09-01-2013 23:31:17.506 [288c]Setup video MP2T 60580 60581
09-01-2013 23:31:17.507 [288c]CMemorySink::ctor
09-01-2013 23:31:17.507 [288c]Created output sink:
09-01-2013 23:31:17.507 [288c]CRTSPClient::startPlayingStreams()
09-01-2013 23:31:17.508 [288c]CRTSPClient::clientStartPlayingSession()
09-01-2013 23:31:17.508 [288c]CRTSPClient::clientStartPlayingSession() play from 0.000 / 34.937
09-01-2013 23:31:17.510 [288c]Started playing session
09-01-2013 23:31:17.511 [288c]CRTSPClient::StartBufferThread
09-01-2013 23:31:17.511 [288c]CRTSPClient::StartBufferThread done
09-01-2013 23:31:17.511 [288c] -- Pause() ->rtsp started
09-01-2013 23:31:17.511 [1d08]CRTSPClient:: thread started:7432
09-01-2013 23:31:17.512 [288c]Timeshift 0, Recording 1, StartPCR 0.000000, EndPcr 34.147000, Duration 34.146000
09-01-2013 23:31:17.512 [288c]CTsReaderFilter::Pause() - END - state = 1
09-01-2013 23:31:17.512 [288c]filt:IID_IMediaSeeking()
09-01-2013 23:31:17.513 [283c]CTsReaderFilter::ThreadProc start()
09-01-2013 23:31:17.531 [288c]SetAudioStream : 3
09-01-2013 23:31:17.532 [288c]Old Audio 129, New Audio 129
09-01-2013 23:31:17.532 [288c]demux:Wait for Audio stream selection :0
09-01-2013 23:31:17.590 [288c]CTsReaderFilter::--SeekStart()-- LiveTv : 0, TimeShifting: 0 30.936 ( Abs 30.936000 / 35.937000 ), OnZap: 0, Force 0, ForceRC 0, Media changing 0
09-01-2013 23:31:17.618 [288c]demux:flush audio
09-01-2013 23:31:17.618 [288c]demux:flush video
09-01-2013 23:31:17.618 [288c]CTsReaderFilter:: Seek->stop rtsp
09-01-2013 23:31:17.618 [288c]CRTSPClient:Stop
09-01-2013 23:31:17.619 [288c]CRTSPClient::StopBufferThread
09-01-2013 23:31:17.620 [1d08]CRTSPClient:: thread stopped:7432
09-01-2013 23:31:17.620 [288c]CRTSPClient::StopBufferThread done
09-01-2013 23:31:17.620 [288c]CRTSPClient::shutdown()
09-01-2013 23:31:17.620 [288c]CRTSPClient::closeMediaSinks()
09-01-2013 23:31:17.621 [288c]CMemorySink::dtor
09-01-2013 23:31:17.621 [288c]CRTSPClient::tearDownStreams()
09-01-2013 23:31:17.621 [288c]CRTSPClient::clientTearDownSession()
09-01-2013 23:31:17.624 [288c]memorybuffer: Clear() 41
09-01-2013 23:31:17.625 [288c]memorybuffer: Clear() done
09-01-2013 23:31:17.625 [288c]CRTSPClient:Stop done
09-01-2013 23:31:17.625 [288c]CTsReaderFilter:: Seek->start client from 30.936000/ 35.936000
09-01-2013 23:31:17.626 [288c]memorybuffer: Clear() 0
09-01-2013 23:31:17.626 [288c]memorybuffer: Clear() done
09-01-2013 23:31:17.626 [288c]memorybuffer: run:1 1
09-01-2013 23:31:17.626 [288c]memorybuffer: running:1
09-01-2013 23:31:17.626 [288c]CRTSPClient::Play from 30.936001 / 35.936001
09-01-2013 23:31:17.627 [288c]memorybuffer: Clear() 0
09-01-2013 23:31:17.627 [288c]memorybuffer: Clear() done
09-01-2013 23:31:17.627 [288c]CRTSPClient::Initialize()
09-01-2013 23:31:17.628 [288c]CRTSPClient::createClient()
09-01-2013 23:31:17.628 [288c]CRTSPClient::OpenStream()
09-01-2013 23:31:17.628 [288c]CRTSPClient::getSDPDescriptionFromURL()
09-01-2013 23:31:17.639 [288c]rangestart:0.000000 rangeend:35.100000
09-01-2013 23:31:17.643 [288c]Created receiver for video MP2T 51976 51977
09-01-2013 23:31:17.644 [288c]rtsp:increaseReceiveBufferTo to 2000000 for s:4168
09-01-2013 23:31:17.644 [288c]CRTSPClient::setupStreams()
09-01-2013 23:31:17.644 [288c]CRTSPClient::clientSetupSubsession()
09-01-2013 23:31:17.649 [288c]Setup video MP2T 51976 51977
09-01-2013 23:31:17.649 [288c]CMemorySink::ctor
09-01-2013 23:31:17.649 [288c]Created output sink:
09-01-2013 23:31:17.649 [288c]CRTSPClient::startPlayingStreams()
09-01-2013 23:31:17.650 [288c]CRTSPClient::clientStartPlayingSession()
09-01-2013 23:31:17.650 [288c]CRTSPClient::clientStartPlayingSession() play from 30.000 / 35.100
09-01-2013 23:31:17.657 [288c]Started playing session
09-01-2013 23:31:17.658 [288c]CRTSPClient::StartBufferThread
09-01-2013 23:31:17.658 [288c]CRTSPClient::StartBufferThread done
09-01-2013 23:31:17.659 [288c]CTsReaderFilter:: Seek-->buffer empty, sleep(100ms)
09-01-2013 23:31:17.659 [2528]CRTSPClient:: thread started:9512
09-01-2013 23:31:17.759 [288c]CTsReaderFilter:: Rtsp seek :Timeshift 0, Recording 1, StartPCR 0.000000, EndPcr 35.937000, Duration 35.936000
09-01-2013 23:31:17.759 [1d74]aud:OnThreadStartPlay(30.936000) 1.00
09-01-2013 23:31:17.759 [288c]vid: SetStart, m_rtStart 30.936000
09-01-2013 23:31:17.760 [2a1c]vid:OnThreadStartPlay(30.936000) 1.00 0
09-01-2013 23:31:17.760 [288c]vid: UpdateFromSeek, m_rtStart 30.936000, m_dRateSeeking 1.000000
09-01-2013 23:31:17.760 [288c]CTsReaderFilter::--SeekStart()-- No new seek 30.936000 ( Abs 30.936000 / 35.937000 ) - Stream compensated: 0, OnZap: 0, Force 0, Media changing: 0
09-01-2013 23:31:17.761 [288c]CTsReaderFilter::--SeekStart()-- No new seek 30.936000 ( Abs 30.936000 / 35.937000 ) - Stream compensated: 0, OnZap: 0, Force 0, Media changing: 0
09-01-2013 23:31:17.990 [1d74] H.264 I-FRAME found 31.008000
09-01-2013 23:31:18.121 [1d74] H.264 First supposed '0' frame found. 31.008000
09-01-2013 23:31:19.091 [1d74]Audio Samples : 18, First : 30.075, Last : 31.355
09-01-2013 23:31:19.091 [1d74]Video Samples : 58, First : 31.008, Last : 32.148
09-01-2013 23:31:19.091 [1d74]Compensation : ( Rnd : 0 mS ) Audio pts ahead Video Pts ( Recover skipping Audio ) ....
09-01-2013 23:31:19.092 [1d74]aud:Compensation:0.072, Clock on start 0.000 m_rtStart:30936
09-01-2013 23:31:19.097 [1d74]aud:set discontinuity
09-01-2013 23:31:19.097 [1d74]Aud/Ref : 31.035, Late Compensated = 0.027 ( 0.027 A/V buffers=06/58), Clk : 0.000000, State 1
09-01-2013 23:31:19.101 [2a1c]vid:set discontinuity
09-01-2013 23:31:19.101 [2a1c]Vid/Ref : 31.008, Late I-frame(00), Compensated = 0.000 ( 0.000 A/V buffers=05/58), Clk : 0.000000, State 1, TsMeanDiff 0.000 ms
09-01-2013 23:31:19.111 [2a1c]Vid/Ref : 31.088, Late ?-frame(00), Compensated = 0.080 ( 0.080 A/V buffers=03/57), Clk : 0.000000, State 1, TsMeanDiff 0.000 ms
09-01-2013 23:31:19.112 [1d74]Aud/Ref : 31.195, Late Compensated = 0.187 ( 0.187 A/V buffers=04/57), Clk : 0.000000, State 1
09-01-2013 23:31:19.115 [2a1c]Vid/Ref : 31.048, Late ?-frame(00), Compensated = 0.040 ( 0.040 A/V buffers=03/56), Clk : 0.000000, State 1, TsMeanDiff 40.000 ms
09-01-2013 23:31:19.120 [2a1c]Vid/Ref : 31.028, Late ?-frame(00), Compensated = 0.020 ( 0.020 A/V buffers=03/55), Clk : 0.000000, State 1, TsMeanDiff 13.333 ms
09-01-2013 23:31:19.126 [2a1c]Vid/Ref : 31.068, Late ?-frame(00), Compensated = 0.060 ( 0.060 A/V buffers=03/54), Clk : 0.000000, State 1, TsMeanDiff 5.000 ms
09-01-2013 23:31:19.146 [2a1c]Vid/Ref : 31.168, Late ?-frame(00), Compensated = 0.160 ( 0.160 A/V buffers=03/53), Clk : 0.000000, State 1, TsMeanDiff 12.000 ms
09-01-2013 23:31:19.151 [2a1c]Vid/Ref : 31.128, Late ?-frame(00), Compensated = 0.120 ( 0.120 A/V buffers=03/52), Clk : 0.000000, State 1, TsMeanDiff 26.667 ms
09-01-2013 23:31:19.154 [2a1c]Vid/Ref : 31.108, Late ?-frame(00), Compensated = 0.100 ( 0.100 A/V buffers=03/51), Clk : 0.000000, State 1, TsMeanDiff 17.143 ms
09-01-2013 23:31:19.161 [2a1c]Vid/Ref : 31.148, Late ?-frame(00), Compensated = 0.140 ( 0.140 A/V buffers=03/50), Clk : 0.000000, State 1, TsMeanDiff 12.500 ms
09-01-2013 23:31:19.167 [2ad4]CTsReaderFilter::Run(8949.90) state 1 seeking 0
09-01-2013 23:31:19.168 [2ad4]CTsReaderFilter::Run(8949.90) state 2 -->done
09-01-2013 23:31:19.222 [2a1c]Vid/Ref : 31.248, Late ?-frame(00), Compensated = 0.240 ( 0.187 A/V buffers=03/49), Clk : 0.053000, State 2, TsMeanDiff 15.556 ms
09-01-2013 23:31:19.228 [2a1c]Vid/Ref : 31.208, Late ?-frame(00), Compensated = 0.200 ( 0.142 A/V buffers=03/48), Clk : 0.058000, State 2, TsMeanDiff 24.000 ms
09-01-2013 23:31:19.234 [2a1c]Vid/Ref : 31.188, Late ?-frame(00), Compensated = 0.180 ( 0.106 A/V buffers=03/47), Clk : 0.074000, State 2, TsMeanDiff 18.182 ms
09-01-2013 23:31:19.243 [2a1c]Vid/Ref : 31.228, Late ?-frame(00), Compensated = 0.220 ( 0.146 A/V buffers=03/46), Clk : 0.074000, State 2, TsMeanDiff 15.000 ms
09-01-2013 23:31:19.251 [2a1c]Vid/Ref : 31.328, Late ?-frame(00), Compensated = 0.320 ( 0.227 A/V buffers=03/45), Clk : 0.093000, State 2, TsMeanDiff 16.923 ms
09-01-2013 23:31:19.253 [1d74]aud:pDVBSubtitleFilter->SetTimeCompensation
09-01-2013 23:31:19.268 [2a1c]Vid/Ref : 31.288, Late ?-frame(00), Compensated = 0.280 ( 0.197 A/V buffers=02/44), Clk : 0.083000, State 2, TsMeanDiff 22.857 ms
09-01-2013 23:31:19.274 [2a1c]Vid/Ref : 31.268, Late ?-frame(00), Compensated = 0.260 ( 0.177 A/V buffers=02/43), Clk : 0.083000, State 2, TsMeanDiff 18.667 ms
09-01-2013 23:31:19.277 [2a1c]Vid/Ref : 31.308, Late ?-frame(00), Compensated = 0.300 ( 0.217 A/V buffers=02/42), Clk : 0.083000, State 2, TsMeanDiff 16.250 ms
09-01-2013 23:31:19.287 [2a1c]Vid/Ref : 31.408, Late ?-frame(00), Compensated = 0.400 ( 0.300 A/V buffers=01/41), Clk : 0.099917, State 2, TsMeanDiff 17.647 ms
09-01-2013 23:31:19.288 [1d74]Aud/Ref : 31.355, Late Compensated = 0.347 ( 0.247 A/V buffers=02/41), Clk : 0.099917, State 2
09-01-2013 23:31:19.292 [2a1c]Vid/Ref : 31.368, Late ?-frame(00), Compensated = 0.360 ( 0.260 A/V buffers=01/40), Clk : 0.099917, State 2, TsMeanDiff 22.222 ms
09-01-2013 23:31:19.308 [2a1c]Vid/Ref : 31.348, Late ?-frame(00), Compensated = 0.340 ( 0.221 A/V buffers=01/39), Clk : 0.118917, State 2, TsMeanDiff 18.947 ms
09-01-2013 23:31:19.336 [2a1c]Vid/Ref : 31.388, Late ?-frame(00), Compensated = 0.380 ( 0.227 A/V buffers=01/38), Clk : 0.153417, State 2, TsMeanDiff 17.000 ms
09-01-2013 23:31:19.353 [2a1c]Vid/Ref : 31.488, Late ?-frame(00), Compensated = 0.480 ( 0.324 A/V buffers=01/37), Clk : 0.156417, State 2, TsMeanDiff 18.095 ms
09-01-2013 23:31:19.370 [2a1c]Vid/Ref : 31.448, Late ?-frame(00), Compensated = 0.440 ( 0.264 A/V buffers=01/36), Clk : 0.176104, State 2, TsMeanDiff 21.818 ms
09-01-2013 23:31:19.403 [2a1c]Vid/Ref : 31.428, Late ?-frame(00), Compensated = 0.420 ( 0.190 A/V buffers=01/35), Clk : 0.230062, State 2, TsMeanDiff 19.130 ms
09-01-2013 23:31:19.420 [2a1c]Vid/Ref : 31.468, Late ?-frame(00), Compensated = 0.460 ( 0.212 A/V buffers=00/34), Clk : 0.248042, State 2, TsMeanDiff 17.500 ms
09-01-2013 23:31:19.437 [2a1c]Vid/Ref : 31.568, Late ?-frame(00), Compensated = 0.560 ( 0.308 A/V buffers=00/33), Clk : 0.252042, State 2, TsMeanDiff 18.400 ms
09-01-2013 23:31:19.450 [1d74]Aud/Ref : 31.515, Late Compensated = 0.507 ( 0.240 A/V buffers=02/40), Clk : 0.267042, State 2
09-01-2013 23:31:19.454 [2a1c]Vid/Ref : 31.528, Late ?-frame(00), Compensated = 0.520 ( 0.253 A/V buffers=01/40), Clk : 0.267042, State 2, TsMeanDiff 21.538 ms
09-01-2013 23:31:19.470 [2a1c]Vid/Ref : 31.508, Late ?-frame(00), Compensated = 0.500 ( 0.213 A/V buffers=01/39), Clk : 0.287062, State 2, TsMeanDiff 19.259 ms
09-01-2013 23:31:19.503 [2a1c]Vid/Ref : 31.548, Late ?-frame(00), Compensated = 0.540 ( 0.216 A/V buffers=01/38), Clk : 0.324167, State 2, TsMeanDiff 17.857 ms
09-01-2013 23:31:19.603 [1d74]Demux : Video to render 0.980 Sec
09-01-2013 23:31:20.416 [2a1c]Video Continuity error... a ( prev 7 )
09-01-2013 23:31:20.416 [2a1c]Audio Continuity error... e ( prev 7 )
09-01-2013 23:31:20.416 [2a1c]Demux : Video to render 0.137 Sec
09-01-2013 23:31:20.417 [2a1c]Demux : Video to render too late = 0.137 Sec, rendering will be paused for a while
09-01-2013 23:31:20.417 [2a1c]Video Continuity error... c ( prev f )
09-01-2013 23:31:20.417 [2a1c]Audio Continuity error... 9 ( prev f )
09-01-2013 23:31:20.418 [2a1c]Video Continuity error... 6 ( prev 6 )
09-01-2013 23:31:20.418 [2a1c]Audio Continuity error... 7 ( prev a )
09-01-2013 23:31:20.418 [2a1c]Video Continuity error... 1 ( prev 7 )
09-01-2013 23:31:20.419 [1d74]Audio Continuity error... a ( prev 7 )
09-01-2013 23:31:20.427 [1d74]Aud/Ref : 31.675, Late Compensated = 0.667 ( -0.572 A/V buffers=02/09), Clk : 1.238979, State 2
09-01-2013 23:31:20.452 [1d74]Aud/Ref : 31.995, Late Compensated = 0.987 ( -0.258 A/V buffers=02/14), Clk : 1.244979, State 2
09-01-2013 23:31:20.580 [1d74]Aud/Ref : 32.155, Late Compensated = 1.147 ( -0.114 A/V buffers=02/15), Clk : 1.260979, State 2
09-01-2013 23:31:22.426 [1d74]Video Continuity error... 8 ( prev a )
09-01-2013 23:31:22.426 [1d74]Audio Continuity error... c ( prev 7 )
09-01-2013 23:31:22.427 [1d74]Video Continuity error... 9 ( prev 3 )
09-01-2013 23:31:22.427 [1d74]Audio Continuity error... a ( prev c )
09-01-2013 23:31:22.427 [1d74]Video Continuity error... b ( prev 4 )
09-01-2013 23:31:22.427 [1d74]Audio Continuity error... 8 ( prev b )
09-01-2013 23:31:22.428 [1d74]Video Continuity error... 0 ( prev d )
09-01-2013 23:31:22.429 [1d74]Audio Continuity error... 0 ( prev 8 )
09-01-2013 23:31:22.456 [2a1c]Vid/Ref : 33.908, Late ?-frame(00), Compensated = 2.900 ( 0.019 A/V buffers=01/40), Clk : 2.881000, State 2, TsMeanDiff 21.250 ms
09-01-2013 23:31:24.425 [1d74]Video Continuity error... 4 ( prev 6 )
09-01-2013 23:31:24.425 [1d74]Audio Continuity error... d ( prev 2 )
09-01-2013 23:31:24.426 [1d74]Video Continuity error... 3 ( prev 6 )
09-01-2013 23:31:24.427 [1d74]Audio Continuity error... b ( prev e )
09-01-2013 23:31:24.427 [1d74]Video Continuity error... 7 ( prev b )
09-01-2013 23:31:24.427 [1d74]Audio Continuity error... 2 ( prev c )
09-01-2013 23:31:24.436 [1d74]Aud/Ref : 35.675, Late Compensated = 4.667 ( -0.196 A/V buffers=02/19), Clk : 4.863042, State 2
09-01-2013 23:31:34.366 [1d74]Video Continuity error... 7 ( prev 0 )
09-01-2013 23:31:34.366 [1d74]Audio Continuity error... 7 ( prev 5 )
09-01-2013 23:31:34.367 [1d74]Audio Continuity error... 3 ( prev 8 )
09-01-2013 23:31:34.367 [1d74]Video Continuity error... 5 ( prev 6 )
09-01-2013 23:31:36.425 [1d74]Video Continuity error... d ( prev f )
09-01-2013 23:31:36.425 [1d74]Audio Continuity error... 3 ( prev b )
09-01-2013 23:31:36.426 [1d74]Video Continuity error... 5 ( prev 3 )
09-01-2013 23:31:36.426 [1d74]Audio Continuity error... 1 ( prev 4 )
09-01-2013 23:31:36.426 [1d74]Video Continuity error... 6 ( prev 6 )
09-01-2013 23:31:36.427 [1d74]Audio Continuity error... f ( prev 2 )
09-01-2013 23:31:36.427 [1d74]Video Continuity error... f ( prev 1 )
09-01-2013 23:31:36.428 [1d74]Audio Continuity error... 6 ( prev f )
09-01-2013 23:31:36.436 [1d74]Aud/Ref : 47.675, Late Compensated = 16.667 ( -0.139 A/V buffers=02/23), Clk : 16.806000, State 2
09-01-2013 23:31:38.413 [1d74]Audio Continuity error... 1 ( prev e )
09-01-2013 23:31:38.413 [1d74]Video Continuity error... 6 ( prev 0 )
09-01-2013 23:31:38.413 [1d74]Video Continuity error... 8 ( prev f )
09-01-2013 23:31:38.414 [1d74]Audio Continuity error... f ( prev 2 )
09-01-2013 23:31:38.414 [1d74]Video Continuity error... 0 ( prev 3 )
09-01-2013 23:31:38.414 [1d74]Audio Continuity error... e ( prev f )
09-01-2013 23:31:38.415 [1d74]Video Continuity error... 7 ( prev 3 )
09-01-2013 23:31:38.421 [1d74]Aud/Ref : 49.755, Late Compensated = 18.747 ( -0.181 A/V buffers=01/14), Clk : 18.927958, State 2
09-01-2013 23:31:38.430 [1d74]Aud/Ref : 49.915, Late Compensated = 18.907 ( -0.021 A/V buffers=02/21), Clk : 18.927958, State 2
09-01-2013 23:31:40.416 [1d74]Audio Continuity error... 8 ( prev 0 )
09-01-2013 23:31:40.416 [1d74]Video Continuity error... 0 ( prev a )
09-01-2013 23:31:40.417 [1d74]Audio Continuity error... 5 ( prev 9 )
09-01-2013 23:31:40.417 [1d74]Video Continuity error... 1 ( prev f )
09-01-2013 23:31:40.417 [1d74]Audio Continuity error... c ( prev 5 )
09-01-2013 23:31:40.417 [1d74]Video Continuity error... 1 ( prev 4 )
09-01-2013 23:31:40.418 [1d74]Audio Continuity error... 6 ( prev 2 )
09-01-2013 23:31:40.428 [1d74]Aud/Ref : 51.675, Late Compensated = 20.667 ( -0.063 A/V buffers=02/25), Clk : 20.730146, State 2
09-01-2013 23:31:42.426 [1d74]Video Continuity error... 2 ( prev d )
09-01-2013 23:31:42.426 [1d74]Audio Continuity error... 6 ( prev 4 )
09-01-2013 23:31:42.436 [1d74]Video Continuity error... b ( prev b )
09-01-2013 23:31:42.437 [1d74]Audio Continuity error... 4 ( prev 8 )
09-01-2013 23:31:42.437 [1d74]Video Continuity error... 1 ( prev 5 )
09-01-2013 23:31:42.437 [1d74]Audio Continuity error... 2 ( prev 5 )
09-01-2013 23:31:42.437 [1d74]Video Continuity error... 7 ( prev a )
09-01-2013 23:31:42.438 [1d74]Audio Continuity error... d ( prev 3 )
09-01-2013 23:31:42.443 [1d74]Aud/Ref : 53.755, Late Compensated = 22.747 ( -0.045 A/V buffers=01/18), Clk : 22.792084, State 2
09-01-2013 23:31:44.408 [1d74]Video Continuity error... d ( prev 5 )
09-01-2013 23:31:44.408 [1d74]Audio Continuity error... 0 ( prev b )
09-01-2013 23:31:44.409 [1d74]Video Continuity error... 4 ( prev 0 )
09-01-2013 23:31:44.409 [1d74]Audio Continuity error... b ( prev 0 )
09-01-2013 23:31:44.409 [1d74]Video Continuity error... 1 ( prev e )
09-01-2013 23:31:44.409 [1d74]Audio Continuity error... e ( prev b )
09-01-2013 23:31:44.410 [1d74]Video Continuity error... 3 ( prev 6 )
09-01-2013 23:31:44.410 [1d74]Audio Continuity error... f ( prev 1 )
09-01-2013 23:31:44.418 [1d74]Aud/Ref : 55.675, Late Compensated = 24.667 ( -0.169 A/V buffers=02/15), Clk : 24.836042, State 2
09-01-2013 23:31:46.376 [1d74]Audio Continuity error... d ( prev 3 )
09-01-2013 23:31:46.376 [1d74]Video Continuity error... 7 ( prev f )
09-01-2013 23:31:46.377 [1d74]Audio Continuity error... 3 ( prev e )
09-01-2013 23:31:46.384 [1d74]Aud/Ref : 57.755, Late Compensated = 26.747 ( -0.001 A/V buffers=01/25), Clk : 26.747980, State 2
09-01-2013 23:31:47.328 [288c]CTsReaderFilter::Pause() - IsTimeShifting = 0 - state = 2
09-01-2013 23:31:47.328 [288c] -- Pause() ->pause rtsp at position: 58.608000
09-01-2013 23:31:47.328 [288c]CRTSPClient::Pause()
09-01-2013 23:31:47.328 [288c]CRTSPClient::Pause() stopthread
09-01-2013 23:31:47.398 [2528]CRTSPClient:: thread stopped:9512
09-01-2013 23:31:47.399 [288c]CRTSPClient::Pause() thread stopped
09-01-2013 23:31:47.407 [288c]CRTSPClient::Pause() done
09-01-2013 23:31:47.407 [288c]CTsReaderFilter::Pause() - END - state = 1
09-01-2013 23:31:47.411 [288c]CTsReaderFilter::Stop()
09-01-2013 23:31:47.411 [283c]CTsReaderFilter::ThreadProc stopped()
09-01-2013 23:31:47.412 [288c]CTsReaderFilter::Stop() -stop source
09-01-2013 23:31:47.451 [288c]CTsReaderFilter::Stop() -stop source done
09-01-2013 23:31:47.452 [288c]CTsReaderFilter::Stop() -- stop rtsp
09-01-2013 23:31:47.452 [288c]memorybuffer: run:0 1
09-01-2013 23:31:47.452 [288c]memorybuffer: Clear() 903
09-01-2013 23:31:47.453 [288c]memorybuffer: Clear() done
09-01-2013 23:31:47.453 [288c]memorybuffer: running:0
09-01-2013 23:31:47.454 [288c]CRTSPClient:Stop
09-01-2013 23:31:47.454 [288c]CRTSPClient::shutdown()
09-01-2013 23:31:47.454 [288c]CRTSPClient::closeMediaSinks()
09-01-2013 23:31:47.454 [288c]CMemorySink::dtor
09-01-2013 23:31:47.454 [288c]CRTSPClient::tearDownStreams()
09-01-2013 23:31:47.455 [288c]CRTSPClient::clientTearDownSession()
09-01-2013 23:31:47.459 [288c]memorybuffer: Clear() 0
09-01-2013 23:31:47.459 [288c]memorybuffer: Clear() done
09-01-2013 23:31:47.459 [288c]CRTSPClient:Stop done
09-01-2013 23:31:47.459 [288c]demux:flushing
09-01-2013 23:31:47.460 [288c]demux:set hold audio:1
09-01-2013 23:31:47.460 [288c]demux:set hold video:1
09-01-2013 23:31:47.460 [288c]demux:set hold subtitle:1
09-01-2013 23:31:47.460 [288c]demux:flush audio
09-01-2013 23:31:47.460 [288c]demux:flush video
09-01-2013 23:31:47.461 [288c]demux:flush subtitle
09-01-2013 23:31:47.461 [288c]demux:set hold audio:0
09-01-2013 23:31:47.461 [288c]demux:set hold video:0
09-01-2013 23:31:47.462 [288c]demux:set hold subtitle:0
09-01-2013 23:31:47.462 [288c]CTsReaderFilter::Stop() done
09-01-2013 23:31:47.462 [288c]vid: UpdateFromSeek, m_rtStart 58.604000, m_dRateSeeking 1.000000
09-01-2013 23:31:47.564 [288c]CTsReaderFilter::dtor
09-01-2013 23:31:47.565 [288c]pin:dtor()
09-01-2013 23:31:47.565 [288c]sub pin:dtor()
09-01-2013 23:31:47.565 [288c]FileReader::CloseFile() no open file
09-01-2013 23:31:47.565 [288c]CMemoryBuffer::dtor
09-01-2013 23:31:47.565 [288c]memorybuffer: Clear() 0
09-01-2013 23:31:47.566 [288c]memorybuffer: Clear() done
09-01-2013 23:31:47.566 [288c]CRTSPClient::~CRTSPClient()
09-01-2013 23:31:47.566 [288c]demux:flushing
09-01-2013 23:31:47.566 [288c]demux:set hold audio:1
09-01-2013 23:31:47.567 [288c]demux:set hold video:1
09-01-2013 23:31:47.567 [288c]demux:set hold subtitle:1
09-01-2013 23:31:47.567 [288c]demux:flush audio
09-01-2013 23:31:47.567 [288c]demux:flush video
09-01-2013 23:31:47.567 [288c]demux:flush subtitle
09-01-2013 23:31:47.567 [288c]demux:set hold audio:0
09-01-2013 23:31:47.568 [288c]demux:set hold video:0
09-01-2013 23:31:47.568 [288c]demux:set hold subtitle:0If any other logs are required I can easily post them (the problem is fairly easy to reproduce, so logs from specific times shouldn't be difficult to get).
My setup is now somewhat different to that listed in my hardware page, as I upgraded it just before Christmas and haven't updated my page yet. I now have a multi-seat setup; the TV-server's specs are listed at the end of the post, while the primary client is as listed on my specs page, sans TV tuners. The second client isn't really used very much - it is a Dell M1530 laptop, with a 2.4GHz Core 2 Duo CPU, an nVidia GeForce 8600M GPU and 4 GB DDR2 RAM running Windows Vista Home Premium (32-bit).
Both the TV server and the primary client are connected via ethernet to a Netgear 100 Mbps ethernet switch, which is in turn connected to the router. (I have ordered a TP-link 1 Gbps switch to replace the Netgear, so if that is the cause somehow then it's not really a problem.) The laptop connects to the same network via 802.11n Wi-Fi.
TV-server specs:
- Mobo: MSI A75MA-G55
- APU (CPU+GPU): AMD A8 3870K @ 3 GHz
- RAM: 8GB DDR3 1600 MHz
- TV cards: TBS 6981 dual DVB-S2, Blackgold BGT3620 dual DVB-T2 and Hauppauge Nova-T-500 dual DVB-T
- Storage: several HDDs connected by SATA (2×3TB, 1×2TB and 1×1TB (system drive))
- OS: Windows 7 x64 Home Premium
Last edited:
