[Finished] Improvements to Live TV playback rate matching - for testing (4 Viewers)

[HTPCSourcer]

There are a lot of versions in this thread because I've been trying a whole range of changes (step by step) to find out what effect they have on the performance.

The thread has wandered off into experimental changes to TsWriter (used in TV Server) as well because we have been investigating the performance of Live TV timeshifting overall, and some things can only be changed at the server end of things.

And I would certainly be interested in taking a look at them. It's just that new versions are posted quite frequently and I am uncertain which one would be worthwile to try. "All" may not be a good choice, given the fact that there are so many different following up each other so closely..

 

[lodale]

Hi, seems I've started something here (didn't mean to)
I will try the TsReader version (v4.1.0.15) on my P2P (wireless 300 meters away of my home) MP ver. 1.12 PC. Give me some hours before feedback

 

[Owlsroost]

The best current combination of files is:

TsReader v4.1.0.15 for the client from here - https://forum.team-mediaportal.com/...ching-for-testing.130394/page-17#post-1150332 (note this is for MP1 1.11 or later only, and won't work on Win XP).

TsWriter v3.1.31.6 for TV Server from here - https://forum.team-mediaportal.com/...ching-for-testing.130394/page-15#post-1149817

Other combinations of TsReader and TsWriter will work together but might not give the best performance.

If you just want to do a small amount of testing, then go for the new TsReader on it's own (keep TV Server unchanged).

EDIT: TsReader link corrected...

 

[Owlsroost]

Hi, seems I've started something here (didn't mean to)
I will try the TsReader version (v4.1.0.15) on my P2P (wireless 300 meters away of my home) MP ver. 1.12 PC. Give me some hours before feedback

No problem - it was a perfectly good, sensible question

 

[lodale]

Hi, and sorry for late feedback. I have replaced original TsReader.ax with TsReader.ax (v4.1.0.15) on my remote WIFI TV client. It is working much better then the original file.
Before the client lost its connection to the TV server, but now it does not (at least till now ). The picture stutters in between, but it comes back to normal. I have tried with UNC paths with delay, but RTSP is by far the best solution for me.
Keep up the good work

 

[Palm_Maniac]

Hi,

I have the new TSReader now run for 2 days. Subjectively, the frequency of pixelation increased again with this version. It is to be crazy. As long as the TV signal in the server remains is all wonderful. Leaving it now the server to the client, you experience interference. All recordings are still wonderful, while simultaneously looking for a TV channel with sporadic pixelation.

The bad thing is that I now can not enjoy the series and films, because I'm waiting for the pixelation.

Enclosed the new logs of 2 days of testing. You start installing the new version TSReader.

On Sunday, I thought I had discovered a pattern, because the pixelation occurred almost in exact intervals. After 15min, 30min, 15min, 60min. Then we had switched to a different TV channel and it was over with the pattern. And on Monday evening there was this pattern is no longer even, instead increased the frequency.

Technically, I think I've gotten tested and configured everything what I got to tips and found on the internet. What can I do? I will of course continue to test as long as there are new versions, and report.

 

[Owlsroost]

There are definitely some networking issues in the logs:

TsReader.bak:

[2015-08-31 14:49:24,844] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/62, RTSP = -1, MaxReadLat: 10 ms, AveReadLat: 2.065 ms, A last: 6375.768, V Last: 6376.502, Comp: 0.474 s, AudMean: 1.078 s, AudDelta: 0.002 s, SPPM: 0
[2015-08-31 14:49:29,160] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/64, RTSP = -1, MaxReadLat: 21 ms, AveReadLat: 2.167 ms, A last: 6380.088, V Last: 6380.842, Comp: 0.474 s, AudMean: 1.080 s, AudDelta: 0.003 s, SPPM: 0
[2015-08-31 14:50:08,245] [27bbb0e8] [ ce8] - vidPin : Video to render late= -36.079
[2015-08-31 14:50:08,245] [27bbb0e8] [ ce8] - vidPin : Video to render very late, flushing
[2015-08-31 14:50:08,251] [27bbb0e8] [ 314] - Demux : Audio to render too late= -36.578 Sec, FileReadLatency: 5 ms, flushing
[2015-08-31 14:50:08,252] [27bbb0e8] [ 314] - CDeMultiplexer::ThreadProc - Flush

....note the 38 second gap in the log lines, due to the duration update thread being stalled because it can't read the timeshift files.

At the same time in MediaPortal.log:

[2015-08-31 14:49:49,336] [Log    ] [20       ] [DEBUG] - fileSystemWatcher_Error path \\server\film-hd 1\filme exception=System.ComponentModel.Win32Exception (0x80004005): Der angegebene Netzwerkname ist nicht mehr verfügbar
[2015-08-31 14:49:49,339] [Log    ] [20       ] [DEBUG] - RemoveWatcher \\server\film-hd 1\filme
[2015-08-31 14:49:59,905] [Log    ] [26       ] [DEBUG] - fileSystemWatcher_Error path \\server\htpc-mp\thumbs exception=System.ComponentModel.Win32Exception (0x80004005): Der angegebene Netzwerkname ist nicht mehr verfügbar
[2015-08-31 14:49:59,905] [Log    ] [26       ] [DEBUG] - RemoveWatcher \\server\htpc-mp\thumbs
[2015-08-31 14:50:08,271] [Log    ] [20       ] [DEBUG] - RemoveWatcher removing folders from cache=\\server\film-hd 1\filme
[2015-08-31 14:50:08,274] [Log    ] [26       ] [DEBUG] - RemoveWatcher removing folders from cache=\\server\htpc-mp\thumbs

Note the '"The specified network name is no longer available" error messages at 14:49:49.
So it looks like the client lost it's connection to the Server for more than 30 seconds.

 

[Owlsroost]

You are also getting huge variations in read access times for the timeshift files in TsReader.bak:

[2015-08-31 13:56:53,292] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/50, RTSP = -1, MaxReadLat: 10 ms, AveReadLat: 2.045 ms, A last: 3224.248, V Last: 3225.002, Comp: 0.458 s, AudMean: 0.912 s, AudDelta: 0.002 s, SPPM: 0
[2015-08-31 13:56:57,607] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/48, RTSP = -1, MaxReadLat: 304 ms, AveReadLat: 3.584 ms, A last: 3228.568, V Last: 3229.262, Comp: 0.457 s, AudMean: 0.864 s, AudDelta: -0.046 s, SPPM: 797
[2015-08-31 13:57:01,923] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/47, RTSP = -1, MaxReadLat: 9 ms, AveReadLat: 2.042 ms, A last: 3232.888, V Last: 3233.622, Comp: 0.456 s, AudMean: 0.916 s, AudDelta: 0.006 s, SPPM: 0
[2015-08-31 13:57:06,243] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/52, RTSP = -1, MaxReadLat: 8 ms, AveReadLat: 1.923 ms, A last: 3237.208, V Last: 3237.982, Comp: 0.456 s, AudMean: 0.914 s, AudDelta: 0.005 s, SPPM: 0
[2015-08-31 13:57:10,515] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/48, RTSP = -1, MaxReadLat: 304 ms, AveReadLat: 5.273 ms, A last: 3241.528, V Last: 3242.162, Comp: 0.454 s, AudMean: 0.873 s, AudDelta: -0.037 s, SPPM: 645
[2015-08-31 13:57:12,293] [27bbb0e8] [ 314] - MultiFileReader m_filesAdded : 24, m_filesRemoved : 16, file->startPosition : 5865000000, currentPosition = 39008, LatestFileID = 24
[2015-08-31 13:57:13,751] [27bbb0e8] [ 2fc] - MultiFileReader m_filesAdded : 24, m_filesRemoved : 16, file->startPosition : 5865000000, currentPosition = 2884576, LatestFileID = 24
[2015-08-31 13:57:14,741] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/48, RTSP = -1, MaxReadLat: 304 ms, AveReadLat: 3.721 ms, A last: 3245.688, V Last: 3246.422, Comp: 0.452 s, AudMean: 0.875 s, AudDelta: -0.035 s, SPPM: 611
[2015-08-31 13:57:19,053] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/45, RTSP = -1, MaxReadLat: 11 ms, AveReadLat: 2.115 ms, A last: 3250.008, V Last: 3250.642, Comp: 0.451 s, AudMean: 0.909 s, AudDelta: -0.001 s, SPPM: 0
[2015-08-31 13:57:23,281] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/43, RTSP = -1, MaxReadLat: 14 ms, AveReadLat: 2.078 ms, A last: 3254.168, V Last: 3254.842, Comp: 0.451 s, AudMean: 0.912 s, AudDelta: 0.002 s, SPPM: 0
[2015-08-31 13:57:27,504] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/46, RTSP = -1, MaxReadLat: 302 ms, AveReadLat: 3.397 ms, A last: 3258.488, V Last: 3259.182, Comp: 0.451 s, AudMean: 0.890 s, AudDelta: -0.020 s, SPPM: 0
[2015-08-31 13:57:31,820] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/50, RTSP = -1, MaxReadLat: 7 ms, AveReadLat: 1.793 ms, A last: 3262.808, V Last: 3263.502, Comp: 0.451 s, AudMean: 0.911 s, AudDelta: 0.001 s, SPPM: 0
[2015-08-31 13:57:35,364] [27bbb0e8] [ 314] - Demux : Video to render 0.596 Sec
[2015-08-31 13:57:35,371] [27bbb0e8] [ 314] - Demux : Audio to render too late= 0.016 Sec, FileReadLatency: 4 ms
[2015-08-31 13:57:35,826] [27bbb0e8] [ 314] - Demux : Video to render 1.485 Sec
[2015-08-31 13:57:35,915] [27bbb0e8] [ 314] - Demux : Audio to render 0.942 Sec
[2015-08-31 13:57:36,140] [27bbb0e8] [ 2fc] - CTsReaderFilter:: DurationThread : Audio to render late= -0.191
[2015-08-31 13:57:36,879] [27bbb0e8] [ 314] - Demux : Video to render 0.593 Sec
[2015-08-31 13:57:36,879] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/39, RTSP = -1, MaxReadLat: 906 ms, AveReadLat: 11.665 ms, A last: 3266.968, V Last: 3267.562, Comp: 0.450 s, AudMean: 0.718 s, AudDelta: -0.191 s, SPPM: 3349
[2015-08-31 13:57:36,949] [27bbb0e8] [ 314] - Demux : Audio to render too late= 0.069 Sec, FileReadLatency: 3 ms
[2015-08-31 13:57:37,307] [27bbb0e8] [ 314] - Demux : Video to render 1.584 Sec
[2015-08-31 13:57:37,627] [27bbb0e8] [ 314] - Demux : Audio to render 0.672 Sec
[2015-08-31 13:57:38,153] [27bbb0e8] [ 314] - Demux : Video to render 1.278 Sec
[2015-08-31 13:57:38,874] [27bbb0e8] [ 314] - Demux : Video to render 1.217 Sec
[2015-08-31 13:57:40,389] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/48, RTSP = -1, MaxReadLat: 309 ms, AveReadLat: 11.745 ms, A last: 3271.288, V Last: 3272.002, Comp: 0.450 s, AudMean: 0.810 s, AudDelta: 0.000 s, SPPM: 0
[2015-08-31 13:57:44,710] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/53, RTSP = -1, MaxReadLat: 22 ms, AveReadLat: 1.976 ms, A last: 3275.608, V Last: 3276.422, Comp: 0.450 s, AudMean: 0.935 s, AudDelta: 0.000 s, SPPM: 0
[2015-08-31 13:57:49,167] [27bbb0e8] [ 314] - Demux : Audio to render 0.651 Sec
[2015-08-31 13:57:49,167] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/45, RTSP = -1, MaxReadLat: 304 ms, AveReadLat: 2.986 ms, A last: 3279.768, V Last: 3280.562, Comp: 0.450 s, AudMean: 0.942 s, AudDelta: 0.000 s, SPPM: 0
[2015-08-31 13:57:53,212] [27bbb0e8] [ 2fc] - Buffers : A/V = 1/52, RTSP = -1, MaxReadLat: 56 ms, AveReadLat: 2.180 ms, A last: 3284.248, V Last: 3284.902, Comp: 0.450 s, AudMean: 0.940 s, AudDelta: 0.000 s, SPPM: 0
[2015-08-31 13:57:54,620] [27bbb0e8] [ 314] - Demux : Audio to render 0.638 Sec
[2015-08-31 13:57:57,527] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/51, RTSP = -1, MaxReadLat: 302 ms, AveReadLat: 3.514 ms, A last: 3288.568, V Last: 3289.202, Comp: 0.450 s, AudMean: 0.908 s, AudDelta: 0.000 s, SPPM: 0
[2015-08-31 13:58:01,839] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/51, RTSP = -1, MaxReadLat: 29 ms, AveReadLat: 2.257 ms, A last: 3292.728, V Last: 3293.562, Comp: 0.450 s, AudMean: 0.939 s, AudDelta: 0.000 s, SPPM: 0
[2015-08-31 13:58:06,165] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/48, RTSP = -1, MaxReadLat: 303 ms, AveReadLat: 4.744 ms, A last: 3297.048, V Last: 3297.842, Comp: 0.450 s, AudMean: 0.894 s, AudDelta: 0.000 s, SPPM: 0
[2015-08-31 13:58:10,422] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/58, RTSP = -1, MaxReadLat: 13 ms, AveReadLat: 1.961 ms, A last: 3301.368, V Last: 3302.262, Comp: 0.450 s, AudMean: 0.941 s, AudDelta: 0.047 s, SPPM: -818
[2015-08-31 13:58:14,735] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/54, RTSP = -1, MaxReadLat: 303 ms, AveReadLat: 3.320 ms, A last: 3305.688, V Last: 3306.462, Comp: 0.454 s, AudMean: 0.913 s, AudDelta: 0.019 s, SPPM: 0
[2015-08-31 13:58:18,996] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/56, RTSP = -1, MaxReadLat: 312 ms, AveReadLat: 3.526 ms, A last: 3310.008, V Last: 3310.822, Comp: 0.454 s, AudMean: 0.919 s, AudDelta: 0.025 s, SPPM: -437
[2015-08-31 13:58:23,318] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/51, RTSP = -1, MaxReadLat: 20 ms, AveReadLat: 1.945 ms, A last: 3314.328, V Last: 3314.982, Comp: 0.456 s, AudMean: 0.934 s, AudDelta: 0.040 s, SPPM: -692
[2015-08-31 13:58:27,633] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/57, RTSP = -1, MaxReadLat: 13 ms, AveReadLat: 2.096 ms, A last: 3318.648, V Last: 3319.422, Comp: 0.459 s, AudMean: 0.932 s, AudDelta: 0.038 s, SPPM: -656
[2015-08-31 13:58:31,953] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/52, RTSP = -1, MaxReadLat: 6 ms, AveReadLat: 1.887 ms, A last: 3322.968, V Last: 3323.682, Comp: 0.462 s, AudMean: 0.935 s, AudDelta: 0.041 s, SPPM: -712
[2015-08-31 13:58:36,213] [27bbb0e8] [ 2fc] - Buffers : A/V = 1/50, RTSP = -1, MaxReadLat: 9 ms, AveReadLat: 1.890 ms, A last: 3327.288, V Last: 3327.902, Comp: 0.464 s, AudMean: 0.931 s, AudDelta: 0.037 s, SPPM: -648
[2015-08-31 13:58:40,518] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/52, RTSP = -1, MaxReadLat: 7 ms, AveReadLat: 1.753 ms, A last: 3331.448, V Last: 3332.242, Comp: 0.467 s, AudMean: 0.926 s, AudDelta: 0.032 s, SPPM: -560
[2015-08-31 13:58:44,834] [27bbb0e8] [ 2fc] - Buffers : A/V = 0/49, RTSP = -1, MaxReadLat: 7 ms, AveReadLat: 2.027 ms, A last: 3335.768, V Last: 3336.542, Comp: 0.469 s, AudMean: 0.923 s, AudDelta: 0.029 s, SPPM: -511

...the average read latency (AveReadLat) is very low - about 2-3 ms, probably what I'd expect on a Gigabit connection. But the typical peak latency (MaxReadLat) is over 300 ms and occasionally over 900 ms (very high). I can't see anything in the other logs related to when these high peaks happen, so it's hard to see anything in MP that might be causing this (but I guess it's still possible).

 

[davidf]

At this point I would agree with @Owlsroost and look closely at the network. This may cause trouble in itself as it's intrusive, but worth doing anyway...

First start a command prompt (run cmd.exe) and enter: ping -t server >pingres.txt

After you've had a problem press CTRL-C, You would have a file which looks like:

Reply from 192.168.254.140: bytes=32 time=6ms TTL=64
Reply from 192.168.254.140: bytes=32 time=2ms TTL=64
Reply from 192.168.254.140: bytes=32 time=6ms TTL=64
Reply from 192.168.254.140: bytes=32 time=3ms TTL=64
Reply from 192.168.254.140: bytes=32 time=5ms TTL=64

Ping statistics for 192.168.254.140:
  Packets: Sent = 8, Received = 8, Lost = 0 (0% loss),
Approximate round trip times in milli-seconds:
  Minimum = 2ms, Maximum = 6ms, Average = 3ms
Control-C

You'll either have a much bigger times than a few Ms or host unreachable. Try it both with MP running and without, to see if MP is the cause of the problem (hint: after you have the file import it into excel so you can sort on the times). Now the hard bit, if you have entries which are unreachable or very high, then something has gone very wrong. I suspect from what owlsroost is picking up that you're either having autodetect problems, as I said earlier, or the network is full for short periods (and occasional long ones). You'll need to get a tool like wireshark and find out what's going on - Google is your friend as I couldn't write all the things you'll need to check for. I see you've centralised just about every MP database to your server and turned on the file existence cache (it looks like that from the logs but I could be wrong), this alone will be generating quite a lot of unnecessary traffic. Turn file existence cache off in GUI configuration - it won't help for you (and it will cause extra problems if the network isn't working well). Wireshark will show you this traffic, and where it's coming from. If it's your client, then the windows performance monitor will help pinpoint the application. I'm hoping we have a network guru who can help now or when you get some more information - because I'm no guru .

This is a bit more enterprise class but here's a nice article :

http://www.techrepublic.com/article/common-causes-of-network-slowdowns/

David

 

[Palm_Maniac]

Hi Owlsroost,

I forgot to write. The items you mentioned you can safely ignore. At this time, I had copied a large file from the server to my PC. Of course, the live TV stream has been severely disrupted. This process thus took about 5-6 minutes. Look times as from 19 clock and later on, because then you dive most pixelation that I get so with. Just back last night it was very common. As I have written seems to be the current version TSReader me worse to run than the previous version.

Thanks for the link davidf, but all that has already been checked and made. The term of the pings to the server are on average 0.6ms without outliers upwards. But one thing I had enabled both clients who "File Existence cache" function. I have now turned off times on both clients. In addition, I also had the network all other connections on the switch already separated because of possible disturbers and left only the two clients and the server off. I have everything through already. But you are right, I have centralized databases of MP on the server, so that both can access the same data over and I have to maintain only one database. Also I will order tests change in the next few days and see if and how it affects.

But as it is written, the mistakes that have been recorded from 13:50, I was with my data transfer from the server to my PC and not MP alone.