PMS Linux/Docker - can't create library on fresh container

Server Version#: 1.18.5.2309-f5213a238
Player Version#: N/A (Web)

The Environment

This is an issue with Docker, so a few more relevant bits of info:

jochs@docker plex $ uname -a
Linux docker 4.9.0-11-amd64 #1 SMP Debian 4.9.189-3+deb9u2 (2019-11-11) x86_64 GNU/Linux
jochs@docker plex $ docker --version
Docker version 19.03.5, build 633a0ea838
jochs@docker plex $ id
uid=1000(jochs) gid=1000(jochs) groups=1000(jochs),24(cdrom),25(floppy),27(sudo),29(audio),30(dip),44(video),46(plugdev),999(docker)

In short, updated Debian 9 system, updated Docker, and my UID/GID is 1000:1000.

docker-compose.yml:

version: "3"
services:
  plex:
    image: plexinc/pms-docker:latest
    container_name: plex
    restart: unless-stopped
    stop_grace_period: 2m
    network_mode: host
    environment:
      PLEX_UID: 1000
      PLEX_GID: 1000
      TZ: 'America/Chicago'
    volumes:
      - ./config:/config
      - ./transcode:/transcode
      - ./local:/data:ro

Latest image, host networking, set UID/GID to match, use local directories for mounts. Like this:

jochs@docker plex $ \ls -lR .
.:
total 16
drwxr-xr-x 2 jochs jochs 4096 Jan 30 23:01 config
-rw-r--r-- 1 jochs jochs  415 Jan 30 22:43 docker-compose.yml
lrwxrwxrwx 1 root  root    53 Dec 22 15:18 Library -> config/Library/Application Support/Plex Media Server/
drwxr-xr-x 2 jochs jochs 4096 Jan 30 23:02 local
lrwxrwxrwx 1 root  root    10 Jan 27 13:52 media -> /mnt/video
drwxr-xr-x 2 jochs jochs 4096 Jan 30 22:43 transcode

./config:
total 0

./local:
total 40780
-rw-r--r-- 1 jochs jochs 41758062 Jan 30 12:45 Ash vs Evil Dead - Official Trailer.mp4

./transcode:
total 0

Bog standard. A couple symlinks there that would be in use under normal circumstances, but I’ve been avoiding while troubleshooting.

Simple, right? Let’s go.

Runtime

Fire up the container:

jochs@docker plex $ docker-compose up -d
Creating plex ... done
jochs@docker plex $ docker logs plex
[s6-init] making user provided files available at /var/run/s6/etc...exited 0.
[s6-init] ensuring user provided files have correct perms...exited 0.
[fix-attrs.d] applying ownership & permissions fixes...
[fix-attrs.d] done.
[cont-init.d] executing container initialization scripts...
[cont-init.d] 40-plex-first-run: executing... 
Creating pref shell
Plex Media Server first run setup complete
[cont-init.d] 40-plex-first-run: exited 0.
[cont-init.d] 45-plex-hw-transcode-and-connected-tuner: executing... 
[cont-init.d] 45-plex-hw-transcode-and-connected-tuner: exited 0.
[cont-init.d] 50-plex-update: executing... 
[cont-init.d] 50-plex-update: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
Starting Plex Media Server.

Port forward to the system to perform initial setup:

jochs@photon ~ % ssh docker.colo.joshuaochs.com -L 32400:localhost:32400   
jochs@docker ~ $ 

In the web UI, set up everything with defaults, adding a single “other videos” library with the single file in the above directory listing.


(Worth noting that the above image is a link to an album of screenshots, not just a single image.)

After this interesting result, shut it down:

jochs@docker plex $ docker stop plex
plex
jochs@docker plex $ 

At this point, I’m happy to grab whatever log files would be useful (figured I wouldn’t blindly post those in case there’s any account info or tokens in there). Of note, the Plex Scanner Log is zero bytes.

jochs@docker plex $ ls -lR Library/Logs/
Library/Logs/:
total 596
drwxr-xr-x 3 root  root    4096 Jan 30 23:23 ./
drwxr-xr-x 8 jochs jochs   4096 Jan 30 23:24 ../
-rw-r--r-- 1 root  root       0 Jan 30 23:23 Plex Media Scanner.log
-rw-r--r-- 1 root  root  592286 Jan 30 23:24 Plex Media Server.log
-rw-r--r-- 1 root  root    2893 Jan 30 23:24 Plex Tuner Service.log
drwxr-xr-x 2 root  root    4096 Jan 30 23:22 PMS Plugin Logs/

Library/Logs/PMS Plugin Logs:
total 536
drwxr-xr-x 2 root root   4096 Jan 30 23:22 ./
drwxr-xr-x 3 root root   4096 Jan 30 23:23 ../
-rw-r--r-- 1 root root  12753 Jan 30 23:18 com.plexapp.agents.fanarttv.log
-rw-r--r-- 1 root root   7661 Jan 30 23:18 com.plexapp.agents.htbackdrops.log
-rw-r--r-- 1 root root   8564 Jan 30 23:19 com.plexapp.agents.imdb.log
-rw-r--r-- 1 root root   5640 Jan 30 23:18 com.plexapp.agents.imdb.log.1
-rw-r--r-- 1 root root   7993 Jan 30 23:18 com.plexapp.agents.lastfm.log
-rw-r--r-- 1 root root  18440 Jan 30 23:18 com.plexapp.agents.localmedia.log
-rw-r--r-- 1 root root   5440 Jan 30 23:18 com.plexapp.agents.lyricfind.log
-rw-r--r-- 1 root root   5174 Jan 30 23:18 com.plexapp.agents.movieposterdb.log
-rw-r--r-- 1 root root  15380 Jan 30 23:18 com.plexapp.agents.none.log
-rw-r--r-- 1 root root   7237 Jan 30 23:18 com.plexapp.agents.opensubtitles.log
-rw-r--r-- 1 root root   7198 Jan 30 23:19 com.plexapp.agents.plexthememusic.log
-rw-r--r-- 1 root root  10274 Jan 30 23:19 com.plexapp.agents.themoviedb.log
-rw-r--r-- 1 root root   7150 Jan 30 23:19 com.plexapp.agents.thetvdb.log
-rw-r--r-- 1 root root  26590 Jan 30 23:24 com.plexapp.system.log
-rw-r--r-- 1 root root 341954 Jan 30 23:22 com.plexapp.system.log.1
-rw-r--r-- 1 root root   9385 Jan 30 23:19 org.musicbrainz.agents.music.log
-rw-r--r-- 1 root root   9563 Jan 30 23:19 tv.plex.agents.music.log

Most things in the Server log look standard to my eyes, such as the lines referencing the new library:

Jan 30, 2020 23:22:59.803 [0x7f0421ffb700] DEBUG - Request: [[::1]:39532 (Loopback)] POST /library/sections?name=Other%20Videos&type=movie&agent=com.plexapp.agents.none&scanner=Plex%20Video%20Files%20Scanner&language=xn&importFromiTunes=&enableAutoPhotoTags=&location=%2Fdata (7 live) GZIP Signed-in Token (diamondsw)
Jan 30, 2020 23:22:59.821 [0x7f04d159d700] DEBUG - Completed: [[::1]:39532] 201 POST /library/sections?name=Other%20Videos&type=movie&agent=com.plexapp.agents.none&scanner=Plex%20Video%20Files%20Scanner&language=xn&importFromiTunes=&enableAutoPhotoTags=&location=%2Fdata (7 live) GZIP 18ms 770 bytes (pipelined: 12)
Jan 30, 2020 23:22:59.822 [0x7f04a1ffb700] DEBUG - Activity: updated activity 4e2872c7-d859-420a-b2cb-1e54729b0c4f - completed 0.0% - Scanning Other Videos

But this certainly does not:

Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: Entity: line 82183:
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: parser
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: error :
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: AttValue: ' expected
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: container="mp4" has64bitOffsets="0" optimizedForStreaming="1" videoProfile="high
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML:                                                                                ^
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: Entity: line 82183:
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: parser
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: error :
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: attributes construct error
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: container="mp4" has64bitOffsets="0" optimizedForStreaming="1" videoProfile="high
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML:                                                                                ^
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: Entity: line 82183:
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: parser
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: error :
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: Couldn't find end of Start Tag Part line 82183
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: container="mp4" has64bitOffsets="0" optimizedForStreaming="1" videoProfile="high
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML:                                                                                ^
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: Entity: line 82183:
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: parser
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: error :
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: Premature end of data in tag Media line 82182
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: container="mp4" has64bitOffsets="0" optimizedForStreaming="1" videoProfile="high
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML:                                                                                ^
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: Entity: line 82183:
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: parser
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: error :
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: Premature end of data in tag Video line 82181
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: container="mp4" has64bitOffsets="0" optimizedForStreaming="1" videoProfile="high
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML:                                                                                ^
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: Entity: line 82183:
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: parser
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: error :
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: Premature end of data in tag MediaContainer line 2
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML: container="mp4" has64bitOffsets="0" optimizedForStreaming="1" videoProfile="high
Jan 30, 2020 23:23:39.546 [0x7f043b7fe700] ERROR - XML:                                                                                ^
Jan 30, 2020 23:23:39.661 [0x7f043b7fe700] ERROR - Error parsing content.

I’m far from a noob at this; this is a rebuild of a previously-running docker PMS, and is also the third (and thankfully least-important) PMS I have running. The other two (hosted on a different server) are running just fine - but this has me rattled.

How about adding the DEBUG log files so we can figure out where the NOOB oversight is? :rofl:

(you probably are staring right at it, like we all do countless times)

Well, now I recall why I don’t come to the forums anymore.

I’m happy to grab whatever log files would be useful (figured I wouldn’t blindly post those in case there’s any account info or tokens in there).

Which there are, such as friends servers, my e-mail address, etc. FWIW, the bundle is posted in the #ninja channel. [EDIT: cleansed somewhat and attaching here]

Logs.zip (112.4 KB)

Setting that aside, all of the detail regarding setting up the container was to emphasize that it’s as bog-standard as it can get. Do you see anything amiss?

As discussed, you have the logs, there’s nothing remotely related to IPv6 going on, and PMS is aware of its IPv4 address as seen in Remote Access.

This still appears to be a Plex issue.

For completeness, I built a completely fresh Debian 10.2 VM, installed docker-compose, and put the compose file and a single video file in place. Agains, as simple as I could get. Failure. Something is very wrong with the Plex container.

(Also gotta love those phantom old Docker servers showing up on the sidebar, even though I’ve removed them from the Authorized Devices and deleted the servers themselves.)

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