Got it, that explains the gap at the end when I thought it should show some activity.
And, the local record function is still active. It recorded Blacklist at 5/7 10pm local time.
Enable the server debug logs.
look at the clock
play the test video for ~1 minute.
fetch the server logs
inspect the Plex Media Server.log
scroll down to about the time stamp of the start of playback
look out for lines which contain MDE: at the beginning. These and the surrounding lines will have an explanation in them why the playback mode was chosen.
OK. While I’m doing that, can you tell me if Plex Server Installation is non-destructive? i.e. if I download and install the package from Plex, will it see the existing server and maintain its settings (libraries and locations, mainly)?
It will retain all your data, if you take heed of the following:
- do not use registry optimizers/cleaner of any kind
- do not use 3rd-party “uninstaller” apps
- do not change the Windows user account, as the Plex settings are stored in the User part of the registry and the User data folder
If there’s an official test video you wanted me to play, I couldn’t identify it with a quick search.
I turned on debug and ran some recently recorded TV that I have in my library, from 11:45 to 11:47.
Your link to server logs uses app.plex.tv which cannot connect to my server, so those instructions don’t work. At this point, last time, I went down the “manual” route, which you told me returned the microserver logs instead of the actual server logs. Do you have any alternate instructions to get to the actual local server logs?
I meant simply the video (or one of the videos) which exhibited the issue on your setup.
You should be able to access the Troubleshooting menu just fine on the local web app as well.
I was able to download the logs that way. There are no MDE: entries in the entire file. Here’s a sample of the section where the video was playing:
May 08, 2023 11:45:53.165 [12284] DEBUG - [Req#1311] Augment: Completed episode augmentation in 0.4 sec.
May 08, 2023 11:45:53.166 [8140] DEBUG - [Req#1311] Activity: Ended activity 68a352a9-acf1-4190-bc81-c86cef7a16c6.
May 08, 2023 11:45:53.181 [7932] DEBUG - [Req#130c] Created thumbnail of size 1920x1080, has pixels: 1
May 08, 2023 11:45:53.276 [5512] DEBUG - Request: [127.0.0.1:52511 (Loopback)] GET /library/parts/57325/1680323400/file.ts?Accept-Language=en (12 live) #132b Signed-in Token (true911) (HTPC-7010) (range: bytes=1437495416-)
May 08, 2023 11:45:53.316 [5512] DEBUG - Content-Length of F:\Recorded TV\Washington Week (2012)\Season 55\Washington Week (2012) - S55E40 - Washington Week.ts is 250000 (of total: 1437745416).
May 08, 2023 11:45:53.316 [1168] DEBUG - Failed to stream media, client probably disconnected after 13107200 bytes: 10054 - An existing connection was forcibly closed by the remote host
May 08, 2023 11:45:53.316 [1168] DEBUG - Completed after connection close: [127.0.0.1:52510] 206 GET /library/parts/57325/1680323400/file.ts?Accept-Language=en (12 live) #1327 165ms 13107200 bytes (range: bytes=0-)
May 08, 2023 11:45:53.332 [1136] DEBUG - Completed: [127.0.0.1:52511] 206 GET /library/parts/57325/1680323400/file.ts?Accept-Language=en (11 live) #132b 56ms 250000 bytes (range: bytes=1437495416-)
May 08, 2023 11:45:53.333 [5512] DEBUG - Request: [127.0.0.1:52512 (Loopback)] GET /library/parts/57325/1680323400/file.ts?Accept-Language=en (11 live) #1330 Signed-in Token (true911) (HTPC-7010) (range: bytes=0-)
May 08, 2023 11:45:53.334 [5512] DEBUG - Content-Length of F:\Recorded TV\Washington Week (2012)\Season 55\Washington Week (2012) - S55E40 - Washington Week.ts is 1437745416 (of total: 1437745416).
May 08, 2023 11:45:53.378 [7932] DEBUG - [Req#130c] Converted 32-bit thumbnail of type 1 to 24-bit with pixels
May 08, 2023 11:45:53.474 [1136] DEBUG - Completed: [127.0.0.1:52463] 200 GET /photo/:/transcode?width=1920&height=1013&opacity=10&background=343a3f&minSize=1&url=%2Flibrary%2Fmetadata%2F24457%2Fart%2F1653105601%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (11 live) #130c GZIP 689ms 28994 bytes (pipelined: 8)
May 08, 2023 11:46:03.222 [7932] DEBUG - Request: [127.0.0.1:52482 (Loopback)] GET /:/timeline?ratingKey=32167&key=%2Flibrary%2Fmetadata%2F32167&playbackTime=9083&playQueueItemID=7205&state=playing&hasMDE=1&time=10000&duration=1797000 (8 live) #132a GZIP Signed-in Token (true911) (HTPC-7010)
May 08, 2023 11:46:03.223 [7932] DEBUG - [Req#132a] Client [8k8r928ey80q6jo18cqflayv] reporting timeline state playing, progress of 10000/1797000ms for guid=, playbackTime=9083ms ratingKey=32167 url=, key=/library/metadata/32167, containerKey=, metadataId=32167, source=
May 08, 2023 11:46:03.224 [7932] DEBUG - [Req#132a] [Now] User is true911 (ID: 1)
May 08, 2023 11:46:03.224 [7932] DEBUG - [Req#132a] [Now] Device is Konvergo (HTPC-7010).
May 08, 2023 11:46:03.226 [7932] DEBUG - [Req#132a] [Now] Profile is Konvergo
May 08, 2023 11:46:03.226 [7932] DEBUG - [Req#132a] [Now] Updated play state for /library/metadata/32167.
May 08, 2023 11:46:03.226 [7932] DEBUG - [Req#132a] Statistics: (a16jnp6rzi0vpl1xyenmkuik) Reporting active playback in state 0 of type 4 (scrobble: 0) for account 1
May 08, 2023 11:46:03.230 [1136] DEBUG - Completed: [127.0.0.1:52482] 200 GET /:/timeline?ratingKey=32167&key=%2Flibrary%2Fmetadata%2F32167&playbackTime=9083&playQueueItemID=7205&state=playing&hasMDE=1&time=10000&duration=1797000 (8 live) #132a GZIP 16ms 490 bytes (pipelined: 9)
May 08, 2023 11:46:13.194 [7932] DEBUG - Request: [127.0.0.1:52482 (Loopback)] GET /:/timeline?ratingKey=32167&key=%2Flibrary%2Fmetadata%2F32167&playbackTime=19229&playQueueItemID=7205&state=playing&hasMDE=1&time=20000&duration=1797000 (7 live) #133c GZIP Signed-in Token (true911) (HTPC-7010)
May 08, 2023 11:46:13.195 [7932] DEBUG - [Req#133c] Client [8k8r928ey80q6jo18cqflayv] reporting timeline state playing, progress of 20000/1797000ms for guid=, playbackTime=19229ms ratingKey=32167 url=, key=/library/metadata/32167, containerKey=, metadataId=32167, source=
May 08, 2023 11:46:13.196 [7932] DEBUG - [Req#133c] [Now] User is true911 (ID: 1)
May 08, 2023 11:46:13.196 [7932] DEBUG - [Req#133c] [Now] Device is Konvergo (HTPC-7010).
May 08, 2023 11:46:13.197 [7932] DEBUG - [Req#133c] [Now] Profile is Konvergo
May 08, 2023 11:46:13.197 [7932] DEBUG - [Req#133c] [Now] Updated play state for /library/metadata/32167.
May 08, 2023 11:46:13.197 [7932] DEBUG - [Req#133c] Statistics: (a16jnp6rzi0vpl1xyenmkuik) Reporting active playback in state 0 of type 4 (scrobble: 0) for account 1
May 08, 2023 11:46:13.199 [1136] DEBUG - Completed: [127.0.0.1:52482] 200 GET /:/timeline?ratingKey=32167&key=%2Flibrary%2Fmetadata%2F32167&playbackTime=19229&playQueueItemID=7205&state=playing&hasMDE=1&time=20000&duration=1797000 (7 live) #133c GZIP 4ms 490 bytes (pipelined: 10)
May 08, 2023 11:46:23.180 [7932] DEBUG - Request: [127.0.0.1:52482 (Loopback)] GET /:/timeline?ratingKey=32167&key=%2Flibrary%2Fmetadata%2F32167&playbackTime=29306&playQueueItemID=7205&state=playing&hasMDE=1&time=30000&duration=1797000 (7 live) #1342 GZIP Signed-in Token (true911) (HTPC-7010)
May 08, 2023 11:46:23.181 [7932] DEBUG - [Req#1342] Client [8k8r928ey80q6jo18cqflayv] reporting timeline state playing, progress of 30000/1797000ms for guid=, playbackTime=29306ms ratingKey=32167 url=, key=/library/metadata/32167, containerKey=, metadataId=32167, source=
May 08, 2023 11:46:23.182 [7932] DEBUG - [Req#1342] [Now] User is true911 (ID: 1)
May 08, 2023 11:46:23.182 [7932] DEBUG - [Req#1342] [Now] Device is Konvergo (HTPC-7010).
May 08, 2023 11:46:23.215 [7932] DEBUG - [Req#1342] [Now] Profile is Konvergo
May 08, 2023 11:46:23.215 [7932] DEBUG - [Req#1342] [Now] Updated play state for /library/metadata/32167.
And here’s the entire download.
I’m prepared at this point to reinstall over the existing install, to hopefully get all the pointers and services back in their proper places. I have a full backup from 5/1 to revert to that will at least get me back up and running. Let me know if you have any other steps you’d like me to try before I go that route, thanks.
The log excerpt appears to be from a different log. Not from the zip archive you have posted below it.
The zip archive shows only logs without debug logging enabled – i.e. not usable.
Did you enable debug logging in the player, but not in the server?
The settings are in different places. Please re-read the instructions.
Don’t do anything like this, yet. It is too early for that.
Here is the setting I selected in the SERVER screen, is it the right one?
And these are the server logs downloaded from the server interface screen (I used the local PLAYER app the last time to do the download).
I went to Settings > (server) > Manage / Troubleshooting in the server app and selected Download Logs.
And this is the file that I downloaded
Plex Media Server Logs_2023-05-08_12-48-45.zip (2.2 MB)
No MDEs. Is debug still turned off here? Where else should I be turning it on?
Correct.
Did you stop and restart the server after doing this?
Not sure how/where to do that since it isn’t running in task manager or services. I will restart the machine and see if there’s any difference.
Have you ever seen the Plex task tray icon? Do a right-click on it.
After PC restart, Plex Media Server now shows as a running process (not a service) and the plex task bar has the Start Plex Media at Login prompt checked. (I don’t recall seeing this icon earlier when the server wasn’t running).
The remote client still cannot connect to it, however.
I found the main block, it is Vipre running on the server computer. I don’t know why transcoded videos were let through, or why this connectivity stopped while troubleshooting. However, with Vipre disabled, I can load a movie from a remote client and it runs as Original.
I’ll try allowing the plex executables directory through Vipre, and if that doesn’t work I’ll move to the Vipre forums to see if anything is there.
Thanks for both of your assistance to this point.
In most cases, using 3rd-party anti virus software is simply no longer justified. The included Windows Defender is good enough.
I have 40 years experience in IT and I can’t disagree more with your assessment.
