Transcoder issues on 1.8.0.4109 on FreeBSD

server-freebsd

#1

Having issues where any file that requires transcoding is failing to play. Getting the following:

Aug 05, 2017 19:40:28.974 [0x80d04cc00] ERROR - get - invalid frameRate value: 23.976
Aug 05, 2017 19:40:29.333 [0x80e02a400] ERROR - [Transcoder] [dash @ 0x80282d200] Cannot use rename on non file protocol, this may lead to races and temporary partial files
Aug 05, 2017 19:40:29.696 [0x80d04d400] ERROR - [Transcoder] [mp4 @ 0x80282de00] Application provided duration: -16 / timestamp: 494552 is out of range for mov/mp4 format
Aug 05, 2017 19:40:30.382 [0x80d04cc00] ERROR - [Transcoder] [mp4 @ 0x80282de00] Application provided duration: -16 / timestamp: 1491944 is out of range for mov/mp4 format
Aug 05, 2017 19:40:31.622 [0x80d04d400] ERROR - [Transcoder] [mp4 @ 0x80282de00] Application provided duration: -16 / timestamp: 3485672 is out of range for mov/mp4 format
Aug 05, 2017 19:40:31.920 [0x80d04d400] ERROR - [Transcoder] [mp4 @ 0x80282de00] Application provided duration: -16 / timestamp: 3984344 is out of range for mov/mp4 format
Aug 05, 2017 19:40:33.141 [0x80d04cc00] ERROR - [Transcoder] [mp4 @ 0x80282de00] Application provided duration: -16 / timestamp: 5978072 is out of range for mov/mp4 format

This was previously working on 1.7.X (cant remember the exact version I upgraded from) It looks to mainly be related when audio Transcoding.

System
Freenas: 9.10.2U6
Plex: 1.8.0.4109

Transcoder is sent to a directory called /mnt/Temp which is on a SSD. Attempted to remove this, still seeing the same failure.
Only other change made is Freenas was updated from U5 to U6.

Logs are attached

Need help understanding why these errors are now present.


#2

@eembling said:
Having issues where any file that requires transcoding is failing to play. Getting the following:

Aug 05, 2017 19:40:28.974 [0x80d04cc00] ERROR - get - invalid frameRate value: 23.976
Aug 05, 2017 19:40:29.333 [0x80e02a400] ERROR - [Transcoder] [dash @ 0x80282d200] Cannot use rename on non file protocol, this may lead to races and temporary partial files
Aug 05, 2017 19:40:29.696 [0x80d04d400] ERROR - [Transcoder] [mp4 @ 0x80282de00] Application provided duration: -16 / timestamp: 494552 is out of range for mov/mp4 format
Aug 05, 2017 19:40:30.382 [0x80d04cc00] ERROR - [Transcoder] [mp4 @ 0x80282de00] Application provided duration: -16 / timestamp: 1491944 is out of range for mov/mp4 format
Aug 05, 2017 19:40:31.622 [0x80d04d400] ERROR - [Transcoder] [mp4 @ 0x80282de00] Application provided duration: -16 / timestamp: 3485672 is out of range for mov/mp4 format
Aug 05, 2017 19:40:31.920 [0x80d04d400] ERROR - [Transcoder] [mp4 @ 0x80282de00] Application provided duration: -16 / timestamp: 3984344 is out of range for mov/mp4 format
Aug 05, 2017 19:40:33.141 [0x80d04cc00] ERROR - [Transcoder] [mp4 @ 0x80282de00] Application provided duration: -16 / timestamp: 5978072 is out of range for mov/mp4 format

This was previously working on 1.7.X (cant remember the exact version I upgraded from) It looks to mainly be related when audio Transcoding.

System
Freenas: 9.10.2U6
Plex: 1.8.0.4109

Transcoder is sent to a directory called /mnt/Temp which is on a SSD. Attempted to remove this, still seeing the same failure.
Only other change made is Freenas was updated from U5 to U6.

Logs are attached

Need help understanding why these errors are now present.

Debug Logging is off on the server

Please enable debug logging on the server and restart the server and then reproduce the problem and post new logs zip on next failure
See https://support.plex.tv/hc/en-us/articles/201643703-Reporting-issues-with-Plex-Media-Server

If you can get the failure on a small sample file and provide that, it would help with the investigation
See https://support.plex.tv/hc/en-us/articles/201035968-Generating-Sample-Files-from-Media


#3

Edit: Didnt Reboot, ignore


#4

Failure after debug logs enabled and reboot:

Timestamp:
Start: 12:29PM EDT
End: 12:32PM EDT

XML, Logs, and test file uploaded. (remove the .txt and extract for the sample file)


#5

@eembling said:
Failure after debug logs enabled and reboot:

Timestamp:
Start: 12:29PM EDT
End: 12:32PM EDT

XML, Logs, and test file uploaded. (remove the .txt and extract for the sample file)

I am starting to look at the logs.

Just need to tell you initial bit I found which is wrong - there is no loopback ip address configured
I cannot see a 127.0.0.1

Aug 06, 2017 12:10:45.233 [0x809c06400] DEBUG - Network interfaces:
Aug 06, 2017 12:10:45.233 [0x809c06400] DEBUG -  * 6 lagg0 (172.16.1.40) (loopback: 0)

This is common issue with FreeBSD and jail configurations

I will try and locate previous forum threads on the subject

Plex Media Server metadata handling and transcoding do not work without loopback ip


#6

@sa2000 said:

@eembling said:
Failure after debug logs enabled and reboot:

Timestamp:
Start: 12:29PM EDT
End: 12:32PM EDT

XML, Logs, and test file uploaded. (remove the .txt and extract for the sample file)

I am starting to look at the logs.

Just need to tell you initial bit I found which is wrong - there is no loopback ip address configured
I cannot see a 127.0.0.1

Aug 06, 2017 12:10:45.233 [0x809c06400] DEBUG - Network interfaces:
Aug 06, 2017 12:10:45.233 [0x809c06400] DEBUG -  * 6 lagg0 (172.16.1.40) (loopback: 0)

This is common issue with FreeBSD and jail configurations

I will try and locate previous forum threads on the subject

Plex Media Server metadata handling and transcoding do not work without loopback ip

A couple of forum threads here that may help you ensure there is a loopback 127.0.0.1 available for Plex Media Server

https://forums.plex.tv/discussion/comment/1036178/#Comment_1036178

http://forums.plex.tv/discussion/189879/non-vimage-jail-photo-transcode-requires-127-0-0-1-address-specifically

Do let me know if it makes a difference

I have stopped looking into the diagnostics as without a loopback IP address the environment is wrong and outcomes are indeterminate.

So we need to repeat this test and get new diagnostics (if it still fails) once you have a loopback IP address of 127.0.0.1 configured


#7

I added the address under the alias and got an IP for the loopback

lo0: flags=8049 metric 0 mtu 16384

options=600003

inet 127.0.0.1 netmask 0xff000000

Still seeing the same issue.

Timestamp:
Start: 19:22PM EDT
Stop: 19:24PM EDT

Aug 06, 2017 19:22:12.270 [0x80b479c00] DEBUG - NetworkInterface: Watching for changes on the interfaces.
Aug 06, 2017 19:22:12.270 [0x809c06400] DEBUG - Network interfaces:
Aug 06, 2017 19:22:12.270 [0x809c06400] DEBUG - * 5 lo0 (127.0.0.1) (loopback: 1)
Aug 06, 2017 19:22:12.270 [0x809c15000] DEBUG - HTTP requesting GET http://plex.tv/pms/:/ip
Aug 06, 2017 19:22:12.270 [0x809c06400] DEBUG - * 6 lagg0 (172.16.1.40) (loopback: 0)
Aug 06, 2017 19:22:12.270 [0x809c06400] DEBUG - * 6 lagg0 (127.0.0.1) (loopback: 0)

Aug 06, 2017 19:22:12.281 [0x80b47a000] WARN - NetworkServiceBrowser: Error sending out discover packet from 172.16.1.40 to 127.255.255.255: Can't assign requested address
Aug 06, 2017 19:22:12.281 [0x809c14800] DEBUG - EPG[onconnect]: Starting.
Aug 06, 2017 19:22:12.281 [0x80b47a000] WARN - NetworkServiceBrowser: Error sending out discover packet from 172.16.1.40 to 127.255.255.255: Can't assign requested address

Aug 06, 2017 19:22:23.347 [0x80d829400] DEBUG - Streaming Resource: Reached Decision id=243410 codes=(General=1001,Direct play not available; Conversion OK. Direct Play=3000,App cannot direct play this item. Direct play is disabled. Transcode=1001,Direct play not available; Conversion OK.) media=(id=881575 part=(id=884270 decision=transcode container=mp4 protocol=dash streams=(Video=(id=1793291 decision=copy width=1920 height=1036) Audio=(id=1793292 decision=transcode bitrate=256 encoder=aac channels=2 rate=48000))))

Aug 06, 2017 19:22:27.282 [0x80b47a000] WARN - NetworkServiceBrowser: Error sending out discover packet from 172.16.1.40 to 127.255.255.255: Can't assign requested address
Aug 06, 2017 19:22:27.283 [0x80b47a000] WARN - NetworkServiceBrowser: Error sending out discover packet from 172.16.1.40 to 127.255.255.255: Can't assign requested address

I also attempted to use VIMAGE but that causes other issues with the plugins in FreeNAS not loading to restart the plugin itself.


#8

This is beyond my knowledge - my knowledge is generic Plex Media Server and I don't know anything about Freenas jail and VIMAGE - except what sort of issues users had in the past

I cannot really continue when there is a configuration with two 127.0.0.1 interfaces, as you can see below for * 5 and *6 - one identified as loopback and one is not

Aug 06, 2017 19:22:12.270 [0x809c06400] DEBUG - Network interfaces:
Aug 06, 2017 19:22:12.270 [0x809c06400] DEBUG - * 5 lo0 (127.0.0.1) (loopback: 1)
Aug 06, 2017 19:22:12.270 [0x809c06400] DEBUG - * 6 lagg0 (172.16.1.40) (loopback: 0)
Aug 06, 2017 19:22:12.270 [0x809c06400] DEBUG - * 6 lagg0 (127.0.0.1) (loopback: 0)

Will see if someone else can step in. I need to see a normal configuration before I start to look into the issue of transcoding


#9

I have consulted our development team and I am afraid we cannot help with your configuration

The only one we know of for your environment that gets a localhost IP address correctly is VIMAGE and the recommendation is to use VIMAGE


#10

Fair enough, gonna rebuild the plug-in.

Looks like it might be an issue with FreeNAS when upgrading.


#11

I'm also having this issue on ubuntu 16.04 with mkv files. @sa2000


#12

@Nott240 said:
I'm also having this issue on ubuntu 16.04 with mkv files. @sa2000

you would not have the missing localhost interface issue on ubuntu - so no, you are not having this issue

Lots of different underlying issues could give the same symptom - they are not the same problem

Please raise your issue on the linux forum with server logs and outline of the problem and when
See
https://support.plex.tv/hc/en-us/articles/201643703-Reporting-issues-with-Plex-Media-Server
https://support.plex.tv/hc/en-us/articles/200250417-Plex-Media-Server-Log-Files