k8s localRelayEnabled results in transcoder error (502 Bad Gateway)

[AngellusMortis]

Describe the bug

Using the default setting for the local relay in the Helm chart for k8s results in the transcoder failing. In the plex-worker logs, it looks like it is getting a 502 Bad Gateway when it tries to post the chunks back to the relay.

To Reproduce
Steps to reproduce the behavior:

1. Deploy Cluster Plex with Helm and Remote Only Workers
2. Try to transcode

Expected behavior

Transcoder should work as expected.

Screenshots

plex-worker log

[http @ 0x7f9b9426be40] HTTP error 502 Bad Gateway
[tcp @ 0x7f9b9e14ee80] Starting connection attempt to 10.101.77.235 port 32499
[tcp @ 0x7f9b9e14ee80] Successfully connected to 10.101.77.235 port 32499

nginx error log for relay

2024/08/17 00:29:43 [error] 867#867: *3332 upstream sent duplicate header line: "Content-Length: 83", previous value: "Content-Length: 83" while reading response header from upstream, client: 10.244.3.24, server: , request: "PUT /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=32324&vdec_packets=1318&vdec_hw_ok=1299&speed=0.4&vdec_hw_status=1 HTTP/1.1", upstream: "http://127.0.0.1:32400/video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=32324&vdec_packets=1318&vdec_hw_ok=1299&speed=0.4&vdec_hw_status=1", host: "plex-pms:32499"
2024/08/17 00:29:43 [error] 867#867: *3335 upstream sent duplicate header line: "Content-Length: 83", previous value: "Content-Length: 83" while reading response header from upstream, client: 10.244.3.24, server: , request: "PUT /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=32324&vdec_packets=1318&vdec_hw_ok=1299&speed=0.4&vdec_hw_status=1 HTTP/1.1", upstream: "http://127.0.0.1:32400/video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=32324&vdec_packets=1318&vdec_hw_ok=1299&speed=0.4&vdec_hw_status=1", host: "plex-pms:32499"
2024/08/17 00:29:44 [error] 867#867: *3337 upstream sent duplicate header line: "Content-Length: 83", previous value: "Content-Length: 83" while reading response header from upstream, client: 10.244.3.24, server: , request: "PUT /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=30546&vdec_packets=1323&vdec_hw_ok=1304&speed=0.4&vdec_hw_status=1 HTTP/1.1", upstream: "http://127.0.0.1:32400/video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=30546&vdec_packets=1323&vdec_hw_ok=1304&speed=0.4&vdec_hw_status=1", host: "plex-pms:32499"
2024/08/17 00:29:44 [error] 867#867: *3339 upstream sent duplicate header line: "Content-Length: 83", previous value: "Content-Length: 83" while reading response header from upstream, client: 10.244.3.24, server: , request: "PUT /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=34969&vdec_packets=1327&vdec_hw_ok=1308&speed=0.3&vdec_hw_status=1 HTTP/1.1", upstream: "http://127.0.0.1:32400/video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=34969&vdec_packets=1327&vdec_hw_ok=1308&speed=0.3&vdec_hw_status=1", host: "plex-pms:32499"
2024/08/17 00:29:45 [error] 867#867: *3341 upstream sent duplicate header line: "Content-Length: 83", previous value: "Content-Length: 83" while reading response header from upstream, client: 10.244.3.24, server: , request: "PUT /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=35121&vdec_packets=1332&vdec_hw_ok=1313&speed=0.4&vdec_hw_status=1 HTTP/1.1", upstream: "http://127.0.0.1:32400/video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=35121&vdec_packets=1332&vdec_hw_ok=1313&speed=0.4&vdec_hw_status=1", host: "plex-pms:32499"
2024/08/17 00:29:45 [error] 867#867: *3343 upstream sent duplicate header line: "Content-Length: 83", previous value: "Content-Length: 83" while reading response header from upstream, client: 10.244.3.24, server: , request: "PUT /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=31380&vdec_packets=1337&vdec_hw_ok=1318&speed=0.4&vdec_hw_status=1 HTTP/1.1", upstream: "http://127.0.0.1:32400/video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=31380&vdec_packets=1337&vdec_hw_ok=1318&speed=0.4&vdec_hw_status=1", host: "plex-pms:32499"
2024/08/17 00:29:45 [error] 867#867: *3356 upstream sent duplicate header line: "Content-Length: 83", previous value: "Content-Length: 83" while reading response header from upstream, client: 10.244.3.24, server: , request: "PUT /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=31380&vdec_packets=1337&vdec_hw_ok=1318&speed=0.4&vdec_hw_status=1 HTTP/1.1", upstream: "http://127.0.0.1:32400/video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=31380&vdec_packets=1337&vdec_hw_ok=1318&speed=0.4&vdec_hw_status=1", host: "plex-pms:32499"
2024/08/17 00:29:46 [error] 867#867: *3358 upstream sent duplicate header line: "Content-Length: 83", previous value: "Content-Length: 83" while reading response header from upstream, client: 10.244.3.24, server: , request: "PUT /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=31276&vdec_packets=1342&vdec_hw_ok=1323&speed=0.4&vdec_hw_status=1 HTTP/1.1", upstream: "http://127.0.0.1:32400/video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=31276&vdec_packets=1342&vdec_hw_ok=1323&speed=0.4&vdec_hw_status=1", host: "plex-pms:32499"
2024/08/17 00:29:46 [error] 867#867: *3361 upstream sent duplicate header line: "Content-Length: 83", previous value: "Content-Length: 83" while reading response header from upstream, client: 10.244.3.24, server: , request: "PUT /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=31276&vdec_packets=1342&vdec_hw_ok=1323&speed=0.4&vdec_hw_status=1 HTTP/1.1", upstream: "http://127.0.0.1:32400/video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress?progress=0.5&size=-22&remaining=31276&vdec_packets=1342&vdec_hw_ok=1323&speed=0.4&vdec_hw_status=1", host: "plex-pms:32499"

nginx access log for relay

10.244.3.24 - - [17/Aug/2024:00:29:48 -0400] "POST /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress/log?level=3&message=%5Bdash%20%40%200x7f9bc9c35040%5D%20Representation%201%20media%20segment%2055%20written%20to%3A%20chunk-stream1-00054.m4s HTTP/1.1" 200 0 "-" "Lavf/LIBAVFORMAT_VERSION"
10.244.3.24 - - [17/Aug/2024:00:29:48 -0400] "POST /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress/log?level=2&message=%5Bdash%20%40%200x7f9bc9c35040%5D%20Opening%20%27http%3A%2F%2Fplex-pms%3A32499%2Fvideo%2F%3A%2Ftranscode%2Fsession%2Frwcyq466ntin5daii1hxd2kh%2F9007548b-bb8b-45e4-ae4f-72f857e89460%2Fmanifest%3FX-Plex-Http-Pipeline%3Dinfinite%27%20for%20writing HTTP/1.1" 200 0 "-" "Lavf/LIBAVFORMAT_VERSION"
10.244.3.24 - - [17/Aug/2024:00:29:48 -0400] "POST /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress/log?level=3&message=%5Btcp%20%40%200x7f9bcb0cd580%5D%20Starting%20connection%20attempt%20to%2010.101.77.235%20port%2032499 HTTP/1.1" 200 0 "-" "Lavf/LIBAVFORMAT_VERSION"
10.244.3.24 - - [17/Aug/2024:00:29:48 -0400] "POST /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress/log?level=3&message=%5Btcp%20%40%200x7f9bcb0cd580%5D%20Successfully%20connected%20to%2010.101.77.235%20port%2032499 HTTP/1.1" 200 0 "-" "Lavf/LIBAVFORMAT_VERSION"
10.244.3.24 - - [17/Aug/2024:00:29:48 -0400] "POST /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress/log?level=3&message=%5BAVIOContext%20%40%200x7f9b9426b040%5D%20Statistics%3A%202111%20bytes%20written%2C%200%20seeks%2C%201%20writeouts HTTP/1.1" 200 0 "-" "Lavf/LIBAVFORMAT_VERSION"
10.244.3.24 - - [17/Aug/2024:00:29:48 -0400] "POST /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/manifest?X-Plex-Http-Pipeline=infinite HTTP/1.1" 499 0 "-" "Lavf/LIBAVFORMAT_VERSION"
10.244.3.24 - - [17/Aug/2024:00:29:48 -0400] "POST /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress/log?level=2&message=%5Bdash%20%40%200x7f9bc9c35040%5D%20Opening%20%27chunk-stream0-00055.m4s.tmp%27%20for%20writing HTTP/1.1" 200 0 "-" "Lavf/LIBAVFORMAT_VERSION"
10.244.3.24 - - [17/Aug/2024:00:29:48 -0400] "POST /video/:/transcode/session/rwcyq466ntin5daii1hxd2kh/9007548b-bb8b-45e4-ae4f-72f857e89460/progress/log?level=2&message=%5Bdash%20%40%200x7f9bc9c35040%5D%20Opening%20%27chunk-stream1-00055.m4s.tmp%27%20for%20writing HTTP/1.1" 200 0 "-" "Lavf/LIBAVFORMAT_VERSION"

Desktop (please complete the following information):

• OS: Windows
• Version: 11

(not a client issue)

Additional context

Cluster is on bare metal running Talos OS 1.7.6 and k8s 1.30.3. PMS is 1.40.5. Cluster Plex is 1.4.13 (latest everything, just installed today).

Disabling the relay, whitelisting all IPs and adding the plex-pms service IP to the pmsIP in the Helm chart fixes everything.

[pabloromeo]

Let me try to reproduce it

[llajas]

I'm seeing this as well. Transcoding appears to work, but quite a number of 502 errors much like shown in the initial comment. Direct plays are working without issue, fortunately but I've gotten reports of some instances where things just spin at playback attempts.

@AngellusMortis Are you able to elaborate on what you did to get things working? When you say disable the relay, I assume you mean in both the chart as well as the Plex settings. I tried this as well as adding the SVC IP for PMS as described ( I actually added all private CIDRs and the specific IP to the 'List of IP addresses and networks that are allowed without auth' section ) and I was not able to get things working. Perhaps I'm missing something but wanted to confirm. Thanks for your time.

[AngellusMortis]

The relay in Plex settings has nothing to do with this relay. The Plex settings relay is to relay via Plex's servers if it cannot direct connect.

The relay in the chart is a nginx reverse proxy to let the other worker pods access Plex without authentication. You can whitelist all the IPs of worker pods and then set the pmsIP in the chart to the PMS service IP address.

[llajas]

Thank you for the clarity. Unfortunately even when I disable the relay in the chart, whitelist all private range CIDR’s in Plex setting and set the value of pmsIP to that of my pms service, things actually don’t run at all, whereas before it would post the job to the orchestrator and then the worker which would give consistent 502’s, nothing ever gets seen by the orchestrator and playback fails immediately. I tried with service IP as well as loadbalancer IP and all I get is the below on each playback attempt:

Calling external transcoder: /app/transcoder.js
Starting sentinel monitoring pid 956 and child pid 957
PMS_SERVICE is only allowed in conjunction with LOCAL_RELAY_ENABLED='1'. This is due to a high chance of Plex rejecting the traffic coming from the Worker.
Main process is no longer running

I’m running k3s v1.28.3+k3s2 on top of FedoraOS. I’ll continue testing and report back if I discover anything. Thanks, all.

[github-actions]

This issue is stale because it has been open for 30 days with no activity.

[github-actions]

This issue was closed because it has been inactive for 14 days since being marked as stale.

[pabloromeo]

From looking at those nginx logs it would appear that the plex transcoder is sending duplicate header lines for Content-Length.
Gotta do a bit of research to see what is causing it and if there's a way for nginx to filter those duplicates.

[github-actions]

This issue is stale because it has been open for 30 days with no activity.

[github-actions]

This issue was closed because it has been inactive for 14 days since being marked as stale.

[github-actions]

This issue is stale because it has been open for 30 days with no activity.

[github-actions]

This issue was closed because it has been inactive for 14 days since being marked as stale.