PMS Ubuntu 14.04 LTS Suddenly loses connection but regains it back after a while / Or not.

server-linux

#1

Dear All,
I hope you are doing great.

As the title says, PMS is running 14.04 ubuntu, and sometimes the server stops responding.
The logs shows this error:
ERROR - NAT: PMP::getPublicIP, couldn't initialize: -3:Unable to get Gateway

I haven't found an answer on previous post in this forum.

Best regards


#2

"Unable to get gateway" is PMS telling you it can't get it's public (WAN) ethernet address. This is a direct indication of a networking failure between PMS and the gateway (modem / router).

Do you have the actual log files ( Settings - Server - Help - Download Logs) which show this? The logs will provide the additional information I need to help you diagnose exactly what's happening.


#3

Dear @ChuckPA ,

Thanks for investigating :)

here is the log. It is a VPS.

Best regards.


#4

Thanks for the logs.

What you're seeing is PMS reporting it's unable to initiate UPnP / NAT-PMP port mapping. This error shows only that automatic port mapping isn't available because their equipment doesn't permit it.

Sep 02, 2017 09:45:34.005 [0x648a1cd69700] DEBUG - HTTP 200 response from POST http://127.0.0.1:32600/devices/discover
Sep 02, 2017 09:45:36.747 [0x648a3db2e700] DEBUG - NAT: UPnP, getPublicIP didn't find usable IGD.
Sep 02, 2017 09:45:36.747 [0x648a3db2e700] ERROR - NAT: PMP::getPublicIP, couldn't initialize: -3:Unable to get Gateway
Sep 02, 2017 09:45:36.747 [0x648a31e93700] DEBUG - PublicAddressManager: Obtaining public address and mapping port.
Sep 02, 2017 09:45:36.747 [0x648a3f304700] DEBUG - PublicAddressManager: Obtaining public address and mapping port.
Sep 02, 2017 09:45:36.747 [0x648a30365700] DEBUG - PublicAddressManager: Obtaining public IP.
Sep 02, 2017 09:45:36.747 [0x648a30365700] DEBUG - HTTP requesting GET http://plex.tv/pms/:/ip

If you scroll down further, you'll see where PMS does get its public IP address successfully.

The ZIP file is missing Plex Media Server.1.log . I cannot find any loss of connectivity in the other log files. I do see the server streaming consistently throughout.

The next time PMS does disconnect, would you please try to capture another set of log files as quickly as possible? If there was a hard disconnect, it might have scrolled off or is in that missing log file.


#5

Dear @ChuckPA
Thanks for responding.

Remote access is forwarded MANUALLY through port 32400, I have even dropped iptables for a week now to make sure it is not interfering. Should I try to manually re-forward it to another port?

Best regards.


#6

I would try it. Sometimes VPS providers are sensitive but most aren't.

Also, a restart of the whole VPS (Reboot) wouldn't hurt (if you can do that)


#7

Do you really think rebooting the whole thing would help? Ubuntu 14.04 LTS has been as stable as a ROCK for all my other app without rebooting :)

Thank you for responding fast.


#8

Check your netstat and lsof output. If nothing is open after you shut down PMS, then NO, it's not. That said, I've seen stranger things with Linux and 14.04 is a little long in the tooth as far as distros go given how fast they roll them now.


#9

Dear @ChuckPA ,
How are you,

I ran into that EXACT same issue.

Here is the log.

Best regards.


#10

@ChuckPA ,

As soon as I "kill -9 PMSPID", everything went back to normale. This is very weird.

Best regards.


#11

@cineboxit

I ask you turn off Verbose logging until such time we need it. I got through the logs you provided but would have benefited more from having more data to look at (which Verbose limits due to log file max size).

I am seeing the transcoder consistently timing out trying to read a particular block of data.

Sep 05, 2017 23:38:19.147 [0x760ff9ba7700] DEBUG - Removed transcode output stream 0x760fea243000, active count 59 => 58
Sep 05, 2017 23:38:19.696 [0x760fb2607700] ERROR - Throttle: timed out trying to read chunk 49
Sep 05, 2017 23:38:19.878 [0x760fb50e5700] DEBUG - [TranscodeOutputStream] Input processing thread exited after writing 5032 bytes, m_closed=1, m_endOfFileReached=0, session->isStopped()=0
`

My first thought is, if the media is on a single local hard disk, you're about to have a drive failure. Normal desktop drives will sit and retry to read the data causing PMS to generate a timeout rather than a hard error (which is what a NAS rated drive does)

It is possible that when you terminated processing, everything could come back to life because the I/O processing in the kernel could return to normal.

Does this match your local configuration / observations in any way?


#12

@ChuckPA ,

Media is on Local and NFS shares.

Best Regards


#13

This time PMS didnt get back by itself, I have to kill PID.

Best regards.


#14

Please explain to me. Is this the same problem as the VPS problem?

It looks like you're running a RasPlex box.

If it is Rasplex (meaning a Pi), it's having a heck of a time trying to transcode something. Presumably just the audio transcoding?

If this is local, either a) insufficient CPU or b) as I suggested above with the I/O waiting and inability to read something.

Sep 05, 2017 23:38:57.899 [0x760ff9ba7700] DEBUG - Completed: [94.23.10.146:53052] 200 GET /status/sessions (109 live) 4ms 41307 bytes (pipelined: 1)
Sep 05, 2017 23:38:57.903 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.905 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.908 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.909 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.913 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.915 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.915 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.916 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.916 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.916 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.918 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.918 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.918 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.921 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.922 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.922 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.922 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.922 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.925 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.925 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.926 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.926 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.926 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.929 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.929 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.935 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.938 [0x760ff9ba7700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.944 [0x760ff9375700] VERBOSE - [TranscodeOutputStream] Waiting 100ms for more data...
Sep 05, 2017 23:38:57.944 [0x760ff9ba7700] DEBUG - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.


#15

Dear @ChuckPA
Thank you for your response.

Yes it is the same as the VPS problem. I also use a raspberry pi running rasplex but I haven't used it in a while thus I don't think it is the problem.

For the info, CPU is "Intel(R) Xeon(R) CPU E3-1245 v5 @ 3.50GHz". and I never had to transcode more than 4 streams at the same (plus they are low bitrate, 1500-2500)

Could it be that one of my NFS shares lost connectivity?

I was running PMS 1.5.5, and i upgraded today to 1.8.1, could it be that I was witnessing a transcoder crash/deadlock related to a previous problem?

Best regards.


#16

Dear @ChuckPA
I hope you are doing great :smile:

I had the same problems happening again where PMS loses connectivity. I have attached 2 separate logs.

Best regards.


#17

According to your logs, yes you are losing connectivity and it does look like the transcoder can't read.

Sep 13, 2017 15:49:53.474 [0x711e0bf28700] DEBUG - handleStreamWrite code 32: Broken pipe
Sep 13, 2017 15:49:53.474 [0x711e0bf28700] DEBUG - Removed transcode output stream 0x711dcefb5000, active count 55 => 54
Sep 13, 2017 15:49:53.612 [0x711db0b67700] ERROR - Throttle: timed out trying to read chunk 189
Sep 13, 2017 15:49:53.813 [0x711dc0c3c700] ERROR - Throttle: timed out trying to read chunk 189
Sep 13, 2017 15:49:54.234 [0x711db0b67700] DEBUG - [TranscodeOutputStream] Input processing thread exited after writing 17736 bytes, m_closed=1, m_endOfFileReached=0, session->isStopped()=0

Is your transcode temp on a NFS share? If so, there is an extra step you must perform in the mounts. local_lock=posix.


#18

Hello @ChuckPA
Thank you very much for helping.

PMS is on dedi and transcode temp is NOT in NFS. However I have other NFS mounts.

Best regards.


#19

Here is how I do it. Yes, this is overkill but it gets the job done quite nicely.

# movies
vienna:/movies    /vie/movies     nfs sec=sys,rsize=131072,wsize=131072,intr,rw,vers=4,timeo=15,auto,async,nofail,bg 0 0
#

#20

@ChuckPA
Should i do this for all my NFS Libs? :smiley:

Best regards.