Transcoding Troubleshooting (speed =>)

Plex Media Server
1

Server Version#: 1.19.5.3112
Player Version#: Multiple

I am trying to troubleshoot a playback issue for one of my users. Looking back at previous posts, if PMS is transcoding a stream, I should see transcode speed entries in the Plex Media Server logs with Verbose/Debug logging enabled. However, I am not seeing them.

Here is a snippit from the logs. Confirmed (via Tautulli) the stream is being transcoded.

image

Aug 26, 2020 11:43:09.868 [10736] DEBUG - Request: [127.0.0.1:55052 (Loopback)] PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress?status=startup (25 live) Signed-in Token (xxxxxx) (range: bytes=0-)
Aug 26, 2020 11:43:09.868 [3432] DEBUG - Completed: [127.0.0.1:55052] 204 PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress?status=startup (25 live) 0ms 203 bytes (pipelined: 1) (range: bytes=0-)
Aug 26, 2020 11:43:09.889 [10736] DEBUG - Request: [127.0.0.1:55052 (Loopback)] PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress?status=startup (25 live) Signed-in Token (xxxxxx) (range: bytes=0-)
Aug 26, 2020 11:43:09.889 [3432] DEBUG - Completed: [127.0.0.1:55052] 204 PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress?status=startup (25 live) 0ms 203 bytes (pipelined: 2) (range: bytes=0-)
Aug 26, 2020 11:43:09.889 [10736] DEBUG - Request: [127.0.0.1:55052 (Loopback)] PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress?status=opening (25 live) Signed-in Token (xxxxxx) (range: bytes=0-)
Aug 26, 2020 11:43:09.889 [3432] DEBUG - Completed: [127.0.0.1:55052] 204 PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress?status=opening (25 live) 0ms 203 bytes (pipelined: 3) (range: bytes=0-)
Aug 26, 2020 11:43:09.891 [10736] DEBUG - Request: [127.0.0.1:55052 (Loopback)] PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress?status=opened (25 live) Signed-in Token (xxxxxx) (range: bytes=0-)
Aug 26, 2020 11:43:09.891 [3432] DEBUG - Completed: [127.0.0.1:55052] 204 PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress?status=opened (25 live) 0ms 203 bytes (pipelined: 4) (range: bytes=0-)
Aug 26, 2020 11:43:09.891 [10736] DEBUG - Request: [127.0.0.1:55052 (Loopback)] PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress/stream?index=0&id=0&codec=ac3&type=audio (25 live) Signed-in Token (xxxxxx) (range: bytes=0-)
Aug 26, 2020 11:43:09.891 [3432] DEBUG - Completed: [127.0.0.1:55052] 200 PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress/stream?index=0&id=0&codec=ac3&type=audio (25 live) 0ms 195 bytes (pipelined: 5) (range: bytes=0-)
Aug 26, 2020 11:43:09.891 [10736] DEBUG - Request: [127.0.0.1:55052 (Loopback)] PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress/stream?index=1&id=0&codec=h264&type=video (25 live) Signed-in Token (xxxxxx) (range: bytes=0-)
Aug 26, 2020 11:43:09.891 [9172] DEBUG - Completed: [127.0.0.1:55052] 200 PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress/stream?index=1&id=0&codec=h264&type=video (25 live) 0ms 195 bytes (pipelined: 6) (range: bytes=0-)
Aug 26, 2020 11:43:09.958 [10736] DEBUG - Request: [127.0.0.1:55052 (Loopback)] PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress/streamDetail?index=0&id=0&codec=ac3&type=audio&bitrate=384000&language=eng&channels=2&layout=stereo&sampleRate=48000&disp_default=1 (25 live) Signed-in Token (xxxxxx) (range: bytes=0-)
Aug 26, 2020 11:43:09.958 [9172] DEBUG - Completed: [127.0.0.1:55052] 200 PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress/streamDetail?index=0&id=0&codec=ac3&type=audio&bitrate=384000&language=eng&channels=2&layout=stereo&sampleRate=48000&disp_default=1 (25 live) 0ms 195 bytes (pipelined: 7) (range: bytes=0-)
Aug 26, 2020 11:43:09.958 [10736] DEBUG - Request: [127.0.0.1:55052 (Loopback)] PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress/streamDetail?index=1&id=0&codec=h264&type=video&profile=High&width=1920&height=1040&interlaced=0&level=41&frameRate=59.940&disp_default=1 (25 live) Signed-in Token (xxxxxx) (range: bytes=0-)
Aug 26, 2020 11:43:09.958 [3432] DEBUG - Completed: [127.0.0.1:55052] 200 PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress/streamDetail?index=1&id=0&codec=h264&type=video&profile=High&width=1920&height=1040&interlaced=0&level=41&frameRate=59.940&disp_default=1 (25 live) 0ms 195 bytes (pipelined: 8) (range: bytes=0-)
Aug 26, 2020 11:43:09.961 [10736] DEBUG - Request: [127.0.0.1:55052 (Loopback)] PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress?duration=5387.692000 (25 live) Signed-in Token (xxxxxx) (range: bytes=0-)
Aug 26, 2020 11:43:09.961 [12032] DEBUG - Started session successfully: 160r29o4js67pclcs60n6o1o
Aug 26, 2020 11:43:09.961 [3432] DEBUG - Completed: [127.0.0.1:55052] 204 PUT /video/:/transcode/session/160r29o4js67pclcs60n6o1o/bf884400-a72f-40dc-8074-a2798d66072c/progress?duration=5387.692000 (25 live) 0ms 203 bytes (pipelined: 9) (range: bytes=0-)
Aug 26, 2020 11:43:09.962 [9172] DEBUG - Completed: [67.133.62.200:33108] 200 GET /video/:/transcode/universal/start.mpd?hasMDE=1&path=%2Flibrary%2Fmetadata%2F121&mediaIndex=0&partIndex=0&protocol=dash&fastSeek=1&directPlay=0&directStream=1&subtitleSize=100&audioBoost=100&location=wan&maxVideoBitrate=2000&addDebugOverlay=0&autoAdjustQuality=0&directStreamAudio=1&mediaBufferSize=102400&session=160r29o4js67pclcs60n6o1o&subtitles=burn&Accept-Language=en (25 live) TLS GZIP 173ms 1028 bytes (pipelined: 7)

Have the speed entries been moved or am I missing something here?

2

In Plex Media Server.log:

Aug 26, 2020 15:42:08.003 [0x7f2b1ffff700] DEBUG - Request: [127.0.0.1:57608 (Loopback)] PUT /video/:/transcode/session/9eo27wxot04zuuxt7az1nbom/54cc3354-08cb-4f86-92cd-2af43acf59c4/progress?progress=0.6&size=-22&remaining=4404&vdec_packets=997&vdec_hw_ok=992&speed=1.6&vdec_hw_status=1 (13 live) Signed-in Token (FordGuy61) (range: bytes=0-) 

Aug 26, 2020 15:42:08.511 [0x7f2b99616700] VERBOSE -  * speed => 1.6

Aug 26, 2020 15:42:08.512 [0x7f2b9a4bc700] DEBUG - Completed: [127.0.0.1:57608] 206 PUT /video/:/transcode/session/9eo27wxot04zuuxt7az1nbom/54cc3354-08cb-4f86-92cd-2af43acf59c4/progress?progress=0.6&size=-22&remaining=4391&vdec_packets=1016&vdec_hw_ok=1011&speed=1.6&vdec_hw_status=1 (13 live) 0ms 355 bytes (pipelined: 61) (range: bytes=0-)
3

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