Playback drops after ~8 mins

Server Version#: 1.18.4.2171
Player Version#: 3.104.2

So, I have this issue; after about 8 minutes of playback, the playback stops.
First, I get the buffering circle moving a bit and then I get dropped back into the ui.
This happens on both the clients I have tested; win10 and AppleTV4k.

I used to run a similar setup, without any issues but recently I replaced my server hardware with a bit of an upgrade. From i3 → i7 and a fresh install.
I’m running on ubuntu 18.04 with firewall disabled.

$ sudo ufw status
Status: inactive

I am pretty sure my config is almost identical to back when it worked. Just new (and better) hardware and ubuntu 18 instead of 16 (I think).

I haven’t really been able to find anything in the logs either, to help me with this.
The only thing I’ve found, if I set logging to verbose, is;

Jan 01, 2020 14:18:42.812 [0x7f8268896700] VERBOSE - We didn’t receive any data from 192.168.1.142:50765 in time, dropping connection.
Jan 01, 2020 14:18:42.817 [0x7f8263fff700] VERBOSE - We didn’t receive any data from 192.168.1.142:50761 in time, dropping connection.
Jan 01, 2020 14:18:42.828 [0x7f8268896700] VERBOSE - We didn’t receive any data from 192.168.1.142:50763 in time, dropping connection.
Jan 01, 2020 14:18:42.859 [0x7f8263fff700] VERBOSE - We didn’t receive any data from 192.168.1.142:50764 in time, dropping connection.
Jan 01, 2020 14:18:42.862 [0x7f8268896700] VERBOSE - We didn’t receive any data from 192.168.1.142:50766 in time, dropping connection.
Jan 01, 2020 14:18:42.868 [0x7f8263fff700] VERBOSE - We didn’t receive any data from 192.168.1.142:50762 in time, dropping connection.
Jan 01, 2020 14:18:43.037 [0x7f8268896700] VERBOSE - We didn’t receive any data from 127.0.0.1:51832 in time, dropping connection.

192.168.1.142 is my player, in this case. I am unsure if this actually means anything but it kind of sounds plausible. I just have no idea then, why it doesn’t recieve any data?

Any ideas what I can try? Any logs I can supply to help (the ones I checked shows nothing of errors of failed playbacks).

I read some other posts where it sounds like the “We didn’t recieve any data” message isn’t actually an error.
Does that mean it doesn’t kill the connection to my player, when this shows up?

Would it be possible to have the DEBUG (turn VERBOSE OFF please) logs where the playback was dropped?

PMS will see SSDP items on the LAN and “drop” them if inactive.
From the snippet above, it’s not possible to tell which is the case here.

Yep, I’ve attached them here.
Hope they are helpful, I haven’t been able to make any sense of them :frowning:

So, I put a Harry Potter movie on, and after 11 minutes and 1 second, it occured.
Loading circle appears and the playback stops. After a while, it runs again, for maybe 1 second, and then drop me into the Plex UI.

192.168.1.142 is the player, in this case.
Server is 192.168.1.104

Plex Crash Uploader.log (193 Bytes) Plex Media Server.log (279.5 KB) Plex Tuner Service.log (2.5 KB)

The player stopped. “reporting timeline state stopped

Jan 02, 2020 21:23:13.652 [0x7fa1657fa700] DEBUG - [Now] User is weirdo (ID: 1)
Jan 02, 2020 21:23:13.652 [0x7fa1657fa700] DEBUG - [Now] Device is Konvergo (DESKTOP-UBFRQSQ).
Jan 02, 2020 21:23:13.653 [0x7fa1657fa700] DEBUG - [Now] Profile is Konvergo
Jan 02, 2020 21:23:13.653 [0x7fa1657fa700] DEBUG - [Now] Updated play state for /library/metadata/1.
Jan 02, 2020 21:23:13.653 [0x7fa1657fa700] DEBUG - Statistics: (j5ph3eeworigh4egif8vvx6r) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 1
Jan 02, 2020 21:23:13.655 [0x7fa1c2880700] DEBUG - Completed: [192.168.1.142:65255] 200 GET /:/timeline?ratingKey=1&key=%2Flibrary%2Fmetadata%2F1&playbackTime=661757&playQueueItemID=7&state=playing&hasMDE=1&time=661000&duration=9425000 (4 live) TLS GZIP 5ms 495 bytes (pipelined: 94)
Jan 02, 2020 21:23:14.332 [0x7fa1c2880700] DEBUG - Auth: authenticated user 1 as weirdo
Jan 02, 2020 21:23:14.332 [0x7fa1657fa700] DEBUG - Request: [192.168.1.142:65255 (Subnet)] GET /:/timeline?ratingKey=1&key=%2Flibrary%2Fmetadata%2F1&playbackTime=661757&playQueueItemID=7&state=stopped&hasMDE=1&time=662000&duration=9425000 (3 live) TLS GZIP Signed-in Token (weirdo)
Jan 02, 2020 21:23:14.333 [0x7fa1657fa700] DEBUG - Client [1b979dlp7g6ehe3f8rjqugnw] reporting timeline state stopped, progress of 662000/9425000ms for guid=, ratingKey=1 url=, key=/library/metadata/1, containerKey=, metadataId=1, source=
Jan 02, 2020 21:23:14.334 [0x7fa1657fa700] DEBUG - Play progress on 1 'Harry Potter and the Goblet of Fire' - got played 662000 ms by account 1!
Jan 02, 2020 21:23:14.344 [0x7fa1657fa700] DEBUG - It took 10.000000 ms to retrieve 141 items.
Jan 02, 2020 21:23:14.346 [0x7fa1657fa700] DEBUG - [Now] User is weirdo (ID: 1)
Jan 02, 2020 21:23:14.346 [0x7fa1657fa700] DEBUG - [Now] Device is Konvergo (DESKTOP-UBFRQSQ).
Jan 02, 2020 21:23:14.346 [0x7fa1657fa700] DEBUG - [Now] Profile is Konvergo
Jan 02, 2020 21:23:14.346 [0x7fa1657fa700] DEBUG - [Now] Updated play state for /

Unfortunately, I can’t help with the player very much. If you collect its logs, there might be an obvious error being reported.

Is it only this (same) movie which stops?

It’s any movie and any player :frowning:
I’ll grab some debug logs from the player tomorrow, see if they say something.
Thanks for helping out, this is super frustrating for me. Getting a lot of pressure from the family :stuck_out_tongue:

Here’s the player log. I realize this is the server forum but this since this happens for any player I try with, I can only assume it’s the server that is actually causing it.

I’ve looked through it but I don’t really see anything that means something to me.
Suddenly, it just changes state to stopped :frowning:

Player.log (123.8 KB)

I’ve been doing some more testing.
It’s not exactly 11:01 in every movie. However, the harry potter movie, it is exactly 11:01 EVERY time.

Are there any other logs I can check?
It does look like plex server goes mental when it happens.

I have a couple of WD Red 5400 RPM disks in raid0, for the movie collection.
Is it possible that they are not fast enough, and that is what is causing it?

It does look like this only happens to 1080p and up.
I have some old DVD cartoons that I have put on there, and they actually play fine.
1080p and 4K though, does not.

So, when this happens, it also looks like it is trying to send A LOT of data through my ethernet interface (enp2s0).
It is only reading about 180M (per second) from the disc when this happens.
image

Ok, I suck. Sorry guys.

I don’t think my issue has anything to do with plex.
Instead, I think the movies has been copied to their final destination, before the file was completely done, resulting in a corrupted file.

This also explains why some work. I just need to figure out why that happens then, but that has nothing to do with plex.

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.