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.



