Mobile Sync Not Working

Oh man. I didn’t realize the dates.

“CRF:0”, using a value of 0 means to use the value in the next parameter. So the command would actually be along the lines of “crf:0 18”.

Have you updated to the latest version of PMS, 1.2.2? There was a bug where the parameter was being falsely called when a video or audio stream didn’t exist. That would fit the no video found error I saw before. Why it didn’t detect a video, I don’t know.

Please update then turn on “Enable Plex Media Server debug logging” in settings \ server \ general and then try syncing something.

Thanks

I am running 1.1.4 and the server configuration page is saying it is up to date. 1.1.4 is also what is available on the plex.tv download page.

You need to set Plex Web to check the Plex Pass channel. On our website there is a slider to switch to the PP downloads.

Updated to 1.2.2, and predictably, there is no difference in the behaviour, the same bugs remain:
Oct 22, 2016 20:58:42.472 [0xe9bff400] ERROR - [Transcoder] Unrecognized option ‘crf:0’.
Oct 22, 2016 20:58:42.474 [0xeca3b400] ? - [Transcoder] Error splitting the argument list: Option not found

Go to the prepay screen for a movie that won’t play and run “analyze” on it. Then try playing and see if that works. If not, I’ll need there full log again.

No difference, still the same error in the logs. New full log attached.
The relevant bit seems to be this, which is the same as before, if look at the post on the first page:

Oct 23, 2016 09:40:19.093 [0xdf9a3400] DEBUG - Job running: FFMPEG_EXTERNAL_LIBS=’/home/plex/Library/Application\ Support/Plex\ Media\ Server/Codecs/5a2d9a2-1127-linux-annapurna-arm7/’ XDG_CACHE_HOME=’/home/plex/Library/Application Support/Plex Media Server/Cache/
’ XDG_DATA_HOME=’/usr/lib/plexmediaserver/Resources/’ X_PLEX_TOKEN=‘xxxxxxxxxxxxxxxxxxxx’ ‘/usr/lib/plexmediaserver/Plex Transcoder’
‘-codec:#0x01’ ‘h264’ ‘-codec:#0x02’ ‘aac’ ‘-i’ ‘/zfs/media/Animated/Series/Bing/Season 01/Bing - s01e12 - Here I Go.mp4’ ‘-filter_complex’ ‘[0:#0x01]scale=w=min(720,iw):h=min(576,ih):force_original_aspect_ratio=decrease[0]’ ‘-map’ ‘[0]’ ‘-codec:0’ ‘libx264’ ‘-crf:0’ ‘16’ ‘-pix_fmt:0’ ‘yuv420p’ ‘-maxrate:0’ ‘2413k’ ‘-bufsize:0’ ‘4826k’ ‘-r:0’ ‘25’ ‘-preset:0’ ‘veryslow’ ‘-x264opts:0’ ‘subme
=2:me_range=4:rc_lookahead=10:me=dia:no_chroma_me:8x8dct=0:partitions=none’ ‘-map’ ‘0:#0x02’ ‘-metadata:s:1’ ‘language=eng’ ‘-codec:1’ ‘aac’ ‘-ar:1’ ‘48000’ ‘-channel_layout:1’ ‘stereo’ ‘-strict:1’ ‘experimental’ ‘-aac_coder:1’ ‘fast’ ‘-q:1’ ‘0’ ‘-f’ ‘mp4’ ‘-map_metadata’ ‘-1’ ‘-map_chapters’ ‘-1’ ‘-movflags’ ‘+faststart’ ‘/home/plex/Library/Application Support/Plex Media Server/Cache/Transcode/Sync+/11031375/88/7705.mp4.temp’ ‘-y’ ‘-nostats’ ‘-loglevel’ ‘quiet’ ‘-loglevel_plex’ ‘error’ ‘-progressurl’ ‘http://127.0.0.1:32400/video/:/transcode/session/9c161640-8af8-4342-8212-3a59f640fc17/progress
Oct 23, 2016 09:40:19.096 [0xdf9a3400] VERBOSE - Jobs: Starting child process with pid 6595
Oct 23, 2016 09:40:19.096 [0xdf9a3400] DEBUG - Using default transcode duration of 120 minutes
Oct 23, 2016 09:40:19.096 [0xdf9a3400] DEBUG - Started session successfully: 9c161640-8af8-4342-8212-3a59f640fc17
Oct 23, 2016 09:40:19.110 [0xe343b400] ERROR - [Transcoder] Unrecognized option ‘crf:0’.
Oct 23, 2016 09:40:19.112 [0xeca3b400] ? - [Transcoder] Error splitting the argument list: Option not found

So I dare say the new log won’t add anything new on top of what I have repeated several times by now, in that at least on the QNAP ARM build:
1.1) transcoder parameter generation is broken
and/or
1.2) transcoder parameter parser is broken
and
2) target device capability analyzer is broken since it is pointlessly trying to invoke the the transcoder in the first place.

On the subject of erroneous decision to transcode, it seems to be doing it to upscale the video to 720p. Downscaling I could almost understand (although it is still wrong, the target device can handle downscaling on it’s own just fine) but upscaling for the target device is beyond ridiculous.

If DirectPlay is possible or forced in the app configuration, no attempt should be made to transcode for sync purposes.

Gordan,
Jumping back in here to see if I can help. What I see from the logs is your PMS Library directory is mounted on /home ? Most Linux systems have a noexec option in /etc/fstab to prevent certain types of code (the PMS libraries being one of those types) from being loaded into memory and executed.

If you manually moved Plex’s library to /home, go check /etc/fstab for the noexec option on the line that mounts /home. If present, remove it, save, and restart the box.

If you didn’t move Plex to /home, please let me know and I’ll dig deeper.

Since you asked, I verified that the privileges are in fact correct (trust me, I know what I’m doing, I have the thick end of two decades of Linux sysadmin experience). Secondly, /home/plex is the plex user’s home directory and that is where the data (metadata database, logs) is, that is NOT where the PMS binaries are, which is under /usr/lib/plexmediaserver.

Anyway, privileges clearly aren’t the problem here because if that were the case the executable wouldn’t have gotten as far as parsing the arguments to complain about an invalid one (that and the fact that none of Plex would be working at all as the service wouldn’t even start.

I am quite certain that the problem is caused by exactly the set of bugs I described above, and as I have been describing for the past 2.5 months. At this rate if the bug isn’t at least acknowledged with an expected fix ETA, I’m going to be contacting Paypal for a refund on my lifetime Plex Pass membership since it seems to be unfit for purpose. Let’s face it, Mobile Sync is key feature that makes the PP subscription worthwhile.

If it was open source and reasonably well documented I’d have fixed it myself and posted the patch months ago.

Trust me, I’ve been at this 35+ years now and when Unix/Linux says “permission denied” or “operation not permitted”, it means it.

Yes, I know where the PMS main binaries and libraries are but the codecs are stored under /home/plex/Library/Application Support/Plex Media Server/Codecs

Oct 23, 2016 09:37:07.098 [0xeff7e400] ERROR - [Transcoder] Error loading external lib: /home/plex/Library/Application Support/Plex Media Server/Codecs/5a2d9a2-1127-linux-annapurna-arm7/libh264_decoder.so: failed to map segment from shared object: Operation not permitted
Oct 23, 2016 09:37:07.105 [0xe5eb3400] ? - [Transcoder] Unknown decoder 'h264'
Oct 23, 2016 09:37:07.106 [0xef3ff400] ERROR - JobManager: child process returned: 1 (Operation not permitted)

It can’t load the h264 codec. The secondary error is ‘Unknown decoder’

What does you /etc/fstab have? Does it have noexec as one of the options when mounting /home ?

So if we’re done posturing, let’s figure out why Linux can’t load the shared library??

@gordan79 - Exactly what model of QNAP are you using?

What is the exact model QNAP you are using? I see which version of PMS you have loaded but which model? The difference between the two models, x31 and x31PLUS is essential

Build version:
According to the download page only X31+ build is available for download (that is what I am using), so I wouldn’t expect the X31 binaries to be dynamically downloadable. I am not running it on a QNAP machine, I am running it on an aarch64 (X-Gene1) inside a docker container.

Permissions:
As mentioned, running in a docker container.

ls -laZ

drwxr-xr-x. plex plex system_u:object_r:svirt_sandbox_file_t:s0 .
drwxr-xr-x. plex plex system_u:object_r:svirt_sandbox_file_t:s0 …
-rw-r–r--. plex plex system_u:object_r:svirt_sandbox_file_t:s0 libaac_decoder.so
-rw-r–r--. plex plex system_u:object_r:svirt_sandbox_file_t:s0 libaac_encoder.so
-rw-r–r--. plex plex system_u:object_r:svirt_sandbox_file_t:s0 libh264_decoder.so
-rw-r–r--. plex plex system_u:object_r:svirt_sandbox_file_t:s0 libhevc_decoder.so
-rw-r–r--. plex plex system_u:object_r:svirt_sandbox_file_t:s0 liblibx264_encoder.so
-rw-r–r--. plex plex system_u:object_r:svirt_sandbox_file_t:s0 libmpeg4_decoder.so

The plex user can read these files, and as you can see, the SELinux context is in fact set correctly for a docker container.
The permission seems to have been set to 644 by PMS when it downloaded the files. Not sure if that is correct or whether that should be 755, but it doesn’t seem to make a difference to the “Operation not permitted” part here:

Oct 24, 2016 21:25:19.708 [0xf05dd400] ERROR - [Transcoder] Unrecognized option ‘crf:0’.
Oct 24, 2016 21:25:19.711 [0xec53b400] ? - [Transcoder] Error splitting the argument list: Option not found
Oct 24, 2016 21:25:19.712 [0xeeeff400] ERROR - JobManager: child process returned: 1 (Operation not permitted)

I just cleared the logs and restarted the PMS service and re-did everything. The Android app also updated a few hours ago. In the fresh log (attached) there is no longer any reference to “Unknown decoder h264”, but the crf option remains unparseable.

I also ran Plex Transcoder manually with the logged options (removed the quiet logging options off the end), as the plex user inside the container, and that doesn’t seem to mention anything about permissions but does error out with “Unrecognized option crf:0”.

And then there’s the fact that it’s transcoding 576p h264/aac/mp4 into a higher res (seemingly 720p and thus probably higher bit rate AND lower quality due to the additional lossy compression pass) h264/aac/mp4 in the first place, but I guess that’s a little less interesting.

May I have the log file which covers that time-stamp period please? The one you provided covers from 21:01 - 21:06

@gordan79 said:
Build version:
According to the download page only X31+ build is available for download (that is what I am using), so I wouldn’t expect the X31 binaries to be dynamically downloadable. I am not running it on a QNAP machine, I am running it on an aarch64 (X-Gene1) inside a docker container.
This information would have been useful in the beginning. A quick search indicates that the X-Gene uses an ArmV8 processor. Plex does not currently have a version that supports using an ArmV8 chip. The PMS you are using is specifically meant for the ArmV7X31+ chip so this (transcoding) is not going to work.

@MovieFan.Plex Nice try, but X-Gene is in fact backward compatible with ARMv7, as evidenced by all other binaries working just fine. Additionally, if there was an instruction set compatibility the error emitted would be “invalid instruction”, and there is no evidence of that or any other tell-tale signs of binary incompatibility. I have a pretty good idea what such incompatibility looks like because:

  1. I originally tried using now deprecated QNAP x21 soft float packages which included proprietary extensions on Marvell Kirkwood with RedSleeve 6 user space, which I used for years previously on a QNAP TS-421 (running RedSleeve). This didn’t work on the X-Gene due to those proprietary extensions that those soft-float PMS binaries were built with. X31+ binaries with CentOS armv7hl do work just fine on the X-Gene.

  2. I am one of the maintainers of RedSleeve Linux (EL6 and EL7 port for ARM, 5 years before CentOS had an ARM port).

Now, granted, this gives you a seemingly gold plated pretext to wash your hands of the issue (you haven’t mentioned you tried and failed to reproduce it on an actual QNAP x31+, though, and I may or may not have one handy to do so).

But the fact that PMS is erroneously deciding to transcode to a lower quality and higher bit rate when there is no plausible justification for it doing so is still very much on the table and entirely unaddressed.

@ChuckPa I’ll retrieve the more recent log tomorrow when I am in front of full size keyboard.

I’m not a dev so I don’t know the specifics, but the error shown in your log is basically saying that the decoders can’t be used. These were built based on them being used for a specific device and they just are not loading in your environment.

For the decision to transcode, you are trying to playback 6 channel audio. Your device is reporting it only supports 2 channels, which means the audio has to be transcoded. The transcoder is not trying to upscale your video. If you have a similar video with only 2 channel aac, you should be able to direct play that file, but the 6 channel aac is not going to work.

  1. It is trying to transcode the video, otherwise it wouldn’t be needing the H264 codec. If it was transcoding only the audio it would be using ‘-codec copy’ for the video. (You are right that it isn’t actually upscaling, but it is rescaling to the same resolution, look at the -filter_complex option).

  2. The media DirectPlays just fine on the device, and DP is set to forced. Ergo it shouldn’t be trying to transcode anything at all.

  3. It is setting the codec twice, once to h264, once to libx264, which doesn’t seem right.

I’ll try some more manual invocations shortly to try to pin down exactly what is going wrong with the transcoder.

1 - Sorry. Reading too fast. You are correct, it is trying to transcode the video, not just a remux. I’m not positive, but it looks like the transcoding might be trigerred by the anamorphic flag in the file. Even though the flag is enabled, the resolution is already at the appropriate ratio so it doesn’t need to do anything. I need to check if PMS should ignore this setting if the resolution is already correct.

Oct 24, 2016 21:03:34.551 [0xe6d77400] DEBUG - Here I Go - video.anamorphic limitation applies: 1 == 1

2 - When syncing, the DP/DS options are not used, so you cannot force it to sync as-is.

3 - The first -h264 mention is for the decoder. libxh264 is the encoder.

Another thing I see in your XML file, although it doesn’t appear to be involved in this case, is that the profile level for your file is listed as “level=12”, which would be 1.2. You cannot have a 720x576 video at profile level 1.2, that is out of spec.

@MovieFan.Plex said:
1 - Sorry. Reading too fast. You are correct, it is trying to transcode the video, not just a remux. I’m not positive, but it looks like the transcoding might be trigerred by the anamorphic flag in the file. Even though the flag is enabled, the resolution is already at the appropriate ratio so it doesn’t need to do anything. I need to check if PMS should ignore this setting if the resolution is already correct.

Oct 24, 2016 21:03:34.551 [0xe6d77400] DEBUG - Here I Go - video.anamorphic limitation applies: 1 == 1

2 - When syncing, the DP/DS options are not used, so you cannot force it to sync as-is.

In that case I would suggest that DP/DS options most definitely should be considered when sync-ing.

3 - The first -h264 mention is for the decoder. libxh264 is the encoder.

I cannot say I have ever seen ffmpeg not auto-detect the file contents correctly, so unless there is an example of a massively popular application producing consistently broken files, specifying the input codecs should probably be omitted entirely.

Another thing I see in your XML file, although it doesn’t appear to be involved in this case, is that the profile level for your file is listed as “level=12”, which would be 1.2. You cannot have a 720x576 video at profile level 1.2, that is out of spec.

What profile is this referring to? All of my media is encoded to h.264 Level 4 high.
Mediainfo reports the following on the file:
General
Complete name : Bing - s01e12 - Here I Go.mp4
Format : MPEG-4
Format profile : Base Media
Codec ID : isom (isom/iso2/avc1/mp41)
File size : 108 MiB
Duration : 7mn 20s
Overall bit rate : 2 063 Kbps
Encoded date : UTC 1904-01-01 00:00:00
Tagged date : UTC 1904-01-01 00:00:00
Writing application : Lavf56.25.101

Video
ID : 1
Format : AVC
Format/Info : Advanced Video Codec
Format profile : High@L4
Format settings, CABAC : Yes
Format settings, ReFrames : 16 frames
Codec ID : avc1
Codec ID/Info : Advanced Video Coding
Duration : 7mn 20s
Bit rate : 1 609 Kbps
Width : 720 pixels
Height : 576 pixels
Display aspect ratio : 16:9
Frame rate mode : Constant
Frame rate : 25.000 fps
Standard : PAL
Color space : YUV
Chroma subsampling : 4:2:0
Bit depth : 8 bits
Scan type : Progressive
Bits/(Pixel*Frame) : 0.155
Stream size : 84.5 MiB (78%)
Writing library : x264 core 142 r2495 6a301b6
Encoding settings : cabac=1 / ref=16 / deblock=1:0:0 / analyse=0x3:0x133 / me=umh / subme=10 / psy=1 / psy_rd=1.00:0.00 / mixed_ref=1 / me_range=24 / chroma_me=1 / trellis=2 / 8x8dct=1 / cqm=0 / deadzone=21,11 / fast_pskip=1 / chroma_qp_offset=-2 / threads=36 / lookahead_threads=4 / sliced_threads=0 / nr=0 / decimate=1 / interlaced=0 / bluray_compat=0 / constrained_intra=0 / bframes=8 / b_pyramid=2 / b_adapt=2 / b_bias=0 / direct=3 / weightb=1 / open_gop=0 / weightp=2 / keyint=250 / keyint_min=25 / scenecut=40 / intra_refresh=0 / rc_lookahead=60 / rc=crf / mbtree=1 / crf=16.0 / qcomp=0.60 / qpmin=0 / qpmax=69 / qpstep=4 / vbv_maxrate=10000 / vbv_bufsize=10000 / crf_max=0.0 / nal_hrd=none / filler=0 / ip_ratio=1.40 / aq=1:1.00
Encoded date : UTC 1904-01-01 00:00:00
Tagged date : UTC 1904-01-01 00:00:00

Audio
ID : 2
Format : AAC
Format/Info : Advanced Audio Codec
Format profile : LC
Codec ID : 40
Duration : 7mn 20s
Bit rate mode : Constant
Bit rate : 448 Kbps
Channel(s) : 2 channels
Channel(s)_Original : 6 channels
Channel positions : Front: L C R, Side: L R, LFE
Sampling rate : 48.0 KHz
Frame rate : 46.875 fps (1024 spf)
Compression mode : Lossy
Stream size : 23.5 MiB (22%)
Language : English
Default : Yes
Alternate group : 1
Encoded date : UTC 1904-01-01 00:00:00
Tagged date : UTC 1904-01-01 00:00:00

And ffmpeg reports this:

Input #0, mov,mp4,m4a,3gp,3g2,mj2, from ‘Bing - s01e12 - Here I Go.mp4’:
Metadata:
major_brand : isom
minor_version : 512
compatible_brands: isomiso2avc1mp41
encoder : Lavf56.25.101
Duration: 00:07:20.49, start: 0.042667, bitrate: 2062 kb/s
Stream #0:0(und): Video: h264 (High) (avc1 / 0x31637661), yuv420p, 720x576 [SAR 64:45 DAR 16:9], 1608 kb/s, 25 fps, 25 tbr, 12800 tbn, 50 tbc (default)
Metadata:
handler_name : VideoHandler
Stream #0:1(eng): Audio: aac (LC) (mp4a / 0x6134706D), 48000 Hz, 5.1, fltp, 447 kb/s (default)
Metadata:
handler_name : SoundHandler

Plex Transcoder reports:
Guessed Channel Layout for Input Stream #0.1 : 5.1
Input #0, mov,mp4,m4a,3gp,3g2,mj2, from ‘/zfs/media/Animated/Series/Bing/Season 01/Bing - s01e12 - Here I Go.mp4’:
Metadata:
major_brand : isom
minor_version : 512
compatible_brands: isomiso2avc1mp41
encoder : Lavf56.25.101
Duration: 00:07:20.49, start: 0.000000, bitrate: 2062 kb/s
Stream #0:0(und): Video: h264 (avc1 / 0x31637661), none, 720x576, 1608 kb/s, SAR 64:45 DAR 16:9, 25 fps, 25 tbr, 12800 tbn (default)
Metadata:
handler_name : VideoHandler
Stream #0:1(eng): Audio: aac (LC) (mp4a / 0x6134706D), 48000 Hz, 6 channels (default)
Metadata:
handler_name : SoundHandler

I still cannot see anything about a profile version 12 or 1.2 anywhere.

@ChuckPa You were right about perms! It was mmap()-ing the codec .so that was failing, not reading them. The permissions are correct, as are the SELinux contexts, but for some reason it looks like when the container was originally created, docker set the noexec permission on the additional mounted (non-root) file systems, so it wouldn’t have mattered if it was in /var/lib/rather than /home. Turns out there are a number of similar looking mmap() failing bug reports on docker’s github. I tore the container down and re-created it, re-attached the file systems (the docker packages were updated several times since I originally built the container), and lo and behold, it can now mmap() the codec .so files, despite the contents or permissions on the underlying /home/plex not having changed at all.

My bad - you were right. Kudos for spotting it and apologies.

Summary:

  1. Binaries weren’t the problem, QNAP x31+ binaries work just fine on X-Gene with CentOS 7 armv7hl userspace.
  2. Problem seems to have been a since-fixed docker bug that caused non-root paths to be mounted noexec (no, the noexec wasn’t showing up in mount output on the host)
  3. Transcoding direct-playable content still isn’t sensible, or even workable in some use cases (for example, to quickly hoard 200GB of a small child’s cartoon collection for consumption on a long flight that is departing in less time than it would take to transcode the entirety of the content on an ARM server).

Thanks for your help guys. Who’d have thought that it is possible to repeat the same process and end up with a different result.

I’ll mark this thread as answered and open a new one about the feature to skip transcoding of DP content based on the DP force flag in the app configuration.