Issue adding Music to library in Plex

Plex Media Server NAS & Devices
1

Server Version#: Version 1.16.3.1402
Player Version#: N/A

I have set up my music library and I have a bunch of music in the library folder that’s being managed with Lidarr. For some reason, in Plex, none of the music is showing up.

Is there anything I can check to see what is happening?

I’m trying to have my plex server scan the music folder on my file server to load the media in the interface as I do for my TV and Movies releases. For some reason, it’s not showing me any artists in the Music section on Plex and it completes the scan REALLY fast.
The logs are not telling me much either…

Any ideas what might be happening?
It looks like Lidarr has everything showing up like expected…
It’s just Plex is not showing me what I would expect.

What I get from the log when trying to scan my music folder…
image

2

Please drag the full log into here. I cannot read anything on this little thumbnail of yours and 8 lines are usually not very conclusive anyway.

3

Sure @OttoKerner. Sorry about that, I thought it would allow users to click on the image to make it bigger. Was not my intention to paste such a small image. Just wanted to show that nothing really happens and no errors pop up.

Below is the full log. I did notice that at some point it says something about On the Case With Paula Zahn which is a TV show I have on my server. That has nothing to do with my music but it seems to log that when I scan my Music section.

Full Log 
Aug 14, 2019 10:41:57.267 [8968] Debug — Push: Queueing up 1 sections to process for new content.
Aug 14, 2019 10:41:58.305 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.305 [7948] Debug — Request: [192.168.1.32:59760 (Subnet)] GET /library/sections/5/refresh (23 live) TLS GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.305 [7948] Debug — Library Updater: Requested that section 5 be updated, force=0, deep=0, subdir= iTunes=0
Aug 14, 2019 10:41:58.305 [7948] Debug — Library Updater: Queueing section 5
Aug 14, 2019 10:41:58.314 [8936] Info — Notification: Scanning the "Music" section - 
Aug 14, 2019 10:41:58.314 [8936] Debug — Scanning section 5
Aug 14, 2019 10:41:58.315 [8936] Debug — Job was already killed, not killing again.
Aug 14, 2019 10:41:58.315 [8936] Debug — Job running: EAE_ROOT='\\?\C:\Program Files (x86)\Plex\Plex Media Server\AppData\Plex Media Server\Cache\Transcode\Sessions\EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='C\:\\Program\ Files\ (x86)\\Plex\\Plex\ Media\ Server\\AppData\\Plex\ Media\ Server\\Codecs\\2144ff1-2376-windows-x86\\' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' C:\Program Files (x86)\Plex\Plex Media Server\Plex Media Scanner.exe --scan --refresh --section 5 
Aug 14, 2019 10:41:58.317 [7556] Debug — Completed: [192.168.1.32:59760] 200 GET /library/sections/5/refresh (23 live) TLS GZIP 8ms 274 bytes (pipelined: 2)
Aug 14, 2019 10:41:58.319 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.320 [7924] Debug — Request: [192.168.1.32:59760 (Subnet)] GET /library/sections (23 live) TLS GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.323 [7072] Debug — Completed: [192.168.1.32:59760] 200 GET /library/sections (23 live) TLS GZIP 3ms 1002 bytes (pipelined: 3)
Aug 14, 2019 10:41:58.330 [8936] Debug — Jobs: Starting child process with pid 1420
Aug 14, 2019 10:41:58.342 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.345 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.348 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.349 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.352 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.355 [5444] Debug — Request: [192.168.1.32:59757 (Subnet)] GET /hubs/home/recentlyAdded?type=1&includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.356 [7948] Debug — Request: [192.168.1.32:59760 (Subnet)] GET /hubs/home/continueWatching?includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.356 [7924] Debug — Request: [192.168.1.32:59762 (Subnet)] GET /hubs/home/recentlyAdded?type=2&includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.360 [7456] Debug — Request: [192.168.1.32:59761 (Subnet)] GET /hubs/home/recentlyAdded?type=1&personal=1&includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.363 [7456] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:58.364 [7556] Debug — Completed: [192.168.1.32:59761] 200 GET /hubs/home/recentlyAdded?type=1&personal=1&includeExternalMedia=1 (23 live) TLS GZIP Page 0-15 11ms 559 bytes (pipelined: 4)
Aug 14, 2019 10:41:58.367 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.368 [5444] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:58.379 [7924] Debug — It took 62.500000 ms to retrieve 200 items.
Aug 14, 2019 10:41:58.383 [3616] Debug — Request: [192.168.1.32:59761 (Subnet)] GET /hubs/home/recentlyAdded?type=13&includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.384 [3616] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:58.385 [7072] Debug — Completed: [192.168.1.32:59761] 200 GET /hubs/home/recentlyAdded?type=13&includeExternalMedia=1 (23 live) TLS GZIP Page 0-15 17ms 559 bytes (pipelined: 5)
Aug 14, 2019 10:41:58.388 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.389 [7456] Debug — Request: [192.168.1.32:59761 (Subnet)] GET /hubs/home/recentlyAdded?type=8&includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.391 [7948] Debug — It took 62.500000 ms to retrieve 0 items.
Aug 14, 2019 10:41:58.393 [5444] Debug — It took 93.750000 ms to retrieve 16 items.
Aug 14, 2019 10:41:58.395 [5444] Debug — Setting container serialization range to [0, 15] (total=837)
Aug 14, 2019 10:41:58.400 [7556] Debug — Completed: [192.168.1.32:59757] 200 GET /hubs/home/recentlyAdded?type=1&includeExternalMedia=1 (23 live) TLS GZIP Page 0-15 51ms 7566 bytes (pipelined: 7)
Aug 14, 2019 10:41:58.391 [7456] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:58.401 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.403 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.403 [3616] Debug — Request: [192.168.1.32:59764 (Subnet)] GET /media/providers (23 live) GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.404 [7456] Debug — Setting container serialization range to [0, 15] (total=0)
Aug 14, 2019 10:41:58.405 [5444] Debug — Request: [192.168.1.32:59757 (Subnet)] GET /library/sections/5/all?type=8&includeCollections=1&includeExternalMedia=1 (23 live) TLS Page 0--1 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.405 [4812] Debug — Request: [192.168.1.32:59759 (Subnet)] GET /hubs/home/onDeck?includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.406 [7556] Debug — Completed: [192.168.1.32:59761] 200 GET /hubs/home/recentlyAdded?type=8&includeExternalMedia=1 (23 live) TLS GZIP Page 0-15 17ms 559 bytes (pipelined: 6)
Aug 14, 2019 10:41:58.409 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.410 [5444] Debug — Setting container serialization range to [0, -1] (total=-1)
Aug 14, 2019 10:41:58.413 [7556] Debug — Completed: [192.168.1.32:59764] 200 GET /media/providers (23 live) GZIP 11ms 3403 bytes (pipelined: 2)
Aug 14, 2019 10:41:58.414 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.415 [7456] Debug — Request: [192.168.1.1:59765 (Subnet)] GET /media/providers (23 live) TLS GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.418 [7556] Debug — Completed: [192.168.1.1:59765] 200 GET /media/providers (23 live) TLS GZIP 3ms 3482 bytes (pipelined: 2)
Aug 14, 2019 10:41:58.433 [6724] Debug — Request: [192.168.1.32:59761 (Subnet)] GET /library/sections/5/firstCharacter?type=8&includeCollections=1 (23 live) TLS GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.439 [7072] Debug — Completed: [192.168.1.32:59761] 200 GET /library/sections/5/firstCharacter?type=8&includeCollections=1 (23 live) TLS GZIP 30ms 642 bytes (pipelined: 7)
Aug 14, 2019 10:41:58.443 [7924] Debug — It took 171.875000 ms to retrieve 50 items.
Aug 14, 2019 10:41:58.444 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.446 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.448 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.450 [6724] Debug — Request: [127.0.0.1:54558 (Loopback)] GET /hubs/home/onDeck?includeExternalMedia=1 (23 live) Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.450 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.450 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.449 [2648] Debug — Request: [127.0.0.1:54555 (Loopback)] GET /hubs/home/continueWatching?includeExternalMedia=1 (23 live) Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.453 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.454 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.455 [4396] Debug — Request: [127.0.0.1:54556 (Loopback)] GET /library/sections (23 live) GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.456 [3360] Debug — Request: [192.168.1.11:54552 (Subnet)] GET /media/providers (23 live) TLS GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.456 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.457 [3616] Debug — Request: [192.168.1.32:59761 (Subnet)] GET /media/providers (23 live) TLS GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.458 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.459 [5672] Debug — Request: [192.168.1.1:54553 (Subnet)] GET /media/providers (23 live) TLS GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.460 [6292] Debug — Request: [127.0.0.1:54554 (Loopback)] GET /hubs/home/recentlyAdded?type=2&includeExternalMedia=1 (23 live) Page 0-49 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.462 [1308] Debug — Request: [127.0.0.1:54551 (Loopback)] GET /media/providers (23 live) GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.465 [7556] Debug — Completed: [192.168.1.11:54552] 200 GET /media/providers (23 live) TLS GZIP 9ms 3482 bytes (pipelined: 2)
Aug 14, 2019 10:41:58.468 [7556] Debug — Completed: [127.0.0.1:54551] 200 GET /media/providers (23 live) GZIP 10ms 3482 bytes (pipelined: 2)
Aug 14, 2019 10:41:58.470 [7456] Debug — Request: [127.0.0.1:54557 (Loopback)] GET /hubs/home/recentlyAdded?type=1&includeExternalMedia=1 (23 live) Page 0-50 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.473 [7556] Debug — Completed: [127.0.0.1:54556] 200 GET /library/sections (23 live) GZIP 20ms 923 bytes (pipelined: 2)
Aug 14, 2019 10:41:58.476 [7556] Debug — Completed: [192.168.1.1:54553] 200 GET /media/providers (23 live) TLS GZIP 16ms 3482 bytes (pipelined: 2)
Aug 14, 2019 10:41:58.481 [7924] Debug — Setting container serialization range to [0, 15] (total=-1)
(content removed)
Aug 14, 2019 10:41:58.488 [7924] Debug — There were 1 top-level paths for Little People, Big World.
Aug 14, 2019 10:41:58.489 [7924] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.489 [7924] Debug — Selecting best audio stream for part ID 31658 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.489 [7924] Debug — Audio Stream: 63972, Subtitle Stream: -1
Aug 14, 2019 10:41:58.498 [7924] Debug — There were 1 top-level paths for On the Case With Paula Zahn.
Aug 14, 2019 10:41:58.500 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.508 [7924] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.508 [7924] Debug — Selecting best audio stream for part ID 31619 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.509 [7924] Debug — Audio Stream: 63854, Subtitle Stream: -1
Aug 14, 2019 10:41:58.509 [7556] Debug — Completed: [192.168.1.32:59761] 200 GET /media/providers (23 live) TLS GZIP 64ms 3482 bytes (pipelined: 8)
Aug 14, 2019 10:41:58.510 [7924] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.511 [7924] Debug — Selecting best audio stream for part ID 31610 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.511 [7924] Debug — Audio Stream: 63832, Subtitle Stream: -1
Aug 14, 2019 10:41:58.512 [7924] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.512 [7924] Debug — Selecting best audio stream for part ID 31590 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.512 [7924] Debug — Audio Stream: 63620, Subtitle Stream: -1
Aug 14, 2019 10:41:58.513 [7924] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.513 [7924] Debug — Selecting best audio stream for part ID 31582 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.513 [7924] Debug — Audio Stream: 63522, Subtitle Stream: -1
Aug 14, 2019 10:41:58.518 [7556] Debug — Completed: [192.168.1.32:59762] 200 GET /hubs/home/recentlyAdded?type=2&includeExternalMedia=1 (23 live) TLS GZIP Page 0-15 167ms 6156 bytes (pipelined: 2)
Aug 14, 2019 10:41:58.539 [2552] Debug — Request: [127.0.0.1:54556 (Loopback)] GET /hubs/home/recentlyAdded?type=1&personal=1&includeExternalMedia=1 (23 live) Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.542 [7456] Debug — It took 125.000000 ms to retrieve 51 items.
Aug 14, 2019 10:41:58.544 [7456] Debug — Setting container serialization range to [0, 50] (total=837)
Aug 14, 2019 10:41:58.551 [2552] Debug — It took 62.500000 ms to retrieve 3 items.
Aug 14, 2019 10:41:58.553 [6292] Debug — It took 296.875000 ms to retrieve 200 items.
Aug 14, 2019 10:41:58.558 [2552] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:58.566 [7072] Debug — Completed: [127.0.0.1:54556] 200 GET /hubs/home/recentlyAdded?type=1&personal=1&includeExternalMedia=1 (23 live) GZIP Page 0-15 65ms 480 bytes (pipelined: 3)
Aug 14, 2019 10:41:58.567 [7072] Debug — Completed: [127.0.0.1:54557] 200 GET /hubs/home/recentlyAdded?type=1&includeExternalMedia=1 (23 live) GZIP Page 0-50 115ms 20587 bytes (pipelined: 2)
Aug 14, 2019 10:41:58.582 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.584 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.585 [3616] Debug — Request: [127.0.0.1:54557 (Loopback)] GET /hubs/home/recentlyAdded?type=8&includeExternalMedia=1 (23 live) Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.588 [3616] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:58.590 [3616] Debug — Setting container serialization range to [0, 15] (total=0)
Aug 14, 2019 10:41:58.591 [7072] Debug — Completed: [127.0.0.1:54557] 200 GET /hubs/home/recentlyAdded?type=8&includeExternalMedia=1 (23 live) GZIP Page 0-15 6ms 480 bytes (pipelined: 3)
Aug 14, 2019 10:41:58.603 [3360] Debug — Request: [127.0.0.1:54556 (Loopback)] GET /hubs/home/recentlyAdded?type=13&includeExternalMedia=1 (23 live) Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.607 [6292] Warning — SLOW QUERY: It took 218.750000 ms to retrieve 50 items.
Aug 14, 2019 10:41:58.609 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:58.611 [4396] Debug — Request: [127.0.0.1:54557 (Loopback)] GET /media/providers (23 live) GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.620 [3360] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:58.621 [7556] Debug — Completed: [127.0.0.1:54556] 200 GET /hubs/home/recentlyAdded?type=13&includeExternalMedia=1 (23 live) GZIP Page 0-15 37ms 480 bytes (pipelined: 4)
Aug 14, 2019 10:41:58.622 [7556] Debug — Completed: [127.0.0.1:54557] 200 GET /media/providers (23 live) GZIP 12ms 3403 bytes (pipelined: 4)
Aug 14, 2019 10:41:58.638 [6292] Debug — Setting container serialization range to [0, 49] (total=-1)
Aug 14, 2019 10:41:58.641 [6292] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.641 [6292] Debug — Selecting best audio stream for part ID 31692 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.641 [6292] Debug — Audio Stream: 64066, Subtitle Stream: -1
Aug 14, 2019 10:41:58.642 [6292] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.642 [6292] Debug — Selecting best audio stream for part ID 31689 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.642 [6292] Debug — Audio Stream: 64060, Subtitle Stream: -1
Aug 14, 2019 10:41:58.643 [6292] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.643 [6292] Debug — Selecting best audio stream for part ID 31688 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.643 [6292] Debug — Audio Stream: 64058, Subtitle Stream: -1
Aug 14, 2019 10:41:58.644 [6292] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.644 [6292] Debug — Selecting best audio stream for part ID 31687 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.645 [6292] Debug — Audio Stream: 64055, Subtitle Stream: -1
Aug 14, 2019 10:41:58.645 [6292] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.645 [6292] Debug — Selecting best audio stream for part ID 31686 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.646 [6292] Debug — Audio Stream: 64053, Subtitle Stream: -1
Aug 14, 2019 10:41:58.648 [6292] Debug — There were 1 top-level paths for Little People, Big World.
Aug 14, 2019 10:41:58.649 [6292] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.649 [6292] Debug — Selecting best audio stream for part ID 31658 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.649 [6292] Debug — Audio Stream: 63972, Subtitle Stream: -1
Aug 14, 2019 10:41:58.652 [6292] Debug — There were 1 top-level paths for On the Case With Paula Zahn.
Aug 14, 2019 10:41:58.654 [6292] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.654 [6292] Debug — Selecting best audio stream for part ID 31619 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.654 [6292] Debug — Audio Stream: 63854, Subtitle Stream: -1
(content removed)
Aug 14, 2019 10:41:58.664 [6292] Debug — There were 1 top-level paths for Judge John Deed.
Aug 14, 2019 10:41:58.666 [6292] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.666 [6292] Debug — Selecting best audio stream for part ID 31096 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.666 [6292] Debug — Audio Stream: 62496, Subtitle Stream: -1
Aug 14, 2019 10:41:58.668 [6292] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.669 [6292] Debug — Selecting best audio stream for part ID 31618 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.669 [6292] Debug — Audio Stream: 63852, Subtitle Stream: -1
(content removed)
Aug 14, 2019 10:41:58.698 [6292] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:58.699 [6292] Debug — Selecting best audio stream for part ID 31195 (autoselect: 0 language: en)
Aug 14, 2019 10:41:58.699 [6292] Debug — Audio Stream: 62693, Subtitle Stream: -1
Aug 14, 2019 10:41:58.707 [7556] Debug — Completed: [127.0.0.1:54554] 200 GET /hubs/home/recentlyAdded?type=2&includeExternalMedia=1 (23 live) GZIP Page 0-49 252ms 15408 bytes (pipelined: 6)
Aug 14, 2019 10:41:58.932 [5672] Debug — Request: [127.0.0.1:54559 (Loopback)] GET /:/metadata/notify/cullTimeline?librarySectionID=5&sinceTime=1565792518 (24 live) GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:58.932 [5672] Debug — Asked to cull library timeline before time 1565792518, we're starting with 5 items.
Aug 14, 2019 10:41:58.933 [5672] Debug — Library timeline cull complete with 5 items left.
Aug 14, 2019 10:41:58.933 [7072] Debug — Completed: [127.0.0.1:54559] 200 GET /:/metadata/notify/cullTimeline?librarySectionID=5&sinceTime=1565792518 (24 live) GZIP 1ms 166 bytes
Aug 14, 2019 10:41:59.123 [5444] Debug — Setting container serialization range to [0, -1] (total=0)
Aug 14, 2019 10:41:59.124 [7072] Debug — Completed: [192.168.1.32:59757] 200 GET /library/sections/5/all?type=8&includeCollections=1&includeExternalMedia=1 (24 live) TLS GZIP Page 0--1 720ms 752 bytes (pipelined: 8)
Aug 14, 2019 10:41:59.287 [7948] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:59.289 [7072] Debug — Completed: [192.168.1.32:59760] 200 GET /hubs/home/continueWatching?includeExternalMedia=1 (24 live) TLS GZIP Page 0-15 946ms 559 bytes (pipelined: 4)
Aug 14, 2019 10:41:59.421 [6724] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:59.422 [7072] Debug — Completed: [127.0.0.1:54558] 200 GET /hubs/home/onDeck?includeExternalMedia=1 (24 live) GZIP Page 0-15 973ms 480 bytes (pipelined: 2)
Aug 14, 2019 10:41:59.431 [4812] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:59.433 [7072] Debug — Completed: [192.168.1.32:59759] 200 GET /hubs/home/onDeck?includeExternalMedia=1 (24 live) TLS GZIP Page 0-15 1086ms 559 bytes (pipelined: 2)
Aug 14, 2019 10:41:59.457 [2648] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:59.458 [7072] Debug — Completed: [127.0.0.1:54555] 200 GET /hubs/home/continueWatching?includeExternalMedia=1 (24 live) GZIP Page 0-15 1011ms 480 bytes (pipelined: 2)
Aug 14, 2019 10:41:59.465 [3040] Debug — Jobs: 'C:\Program Files (x86)\Plex\Plex Media Server\Plex Media Scanner.exe' exit code for process 1420 is 0 (success)
Aug 14, 2019 10:41:59.467 [8936] Debug — Activity: registered new activity 06bedb46-9d71-4606-8e2a-e1c71c3d25ee - Processing subscriptions
Aug 14, 2019 10:41:59.467 [8900] Debug — DVR:Grabber: Cleaning up orphaned grabs.
Aug 14, 2019 10:41:59.468 [8936] Info — Notification: Library scan complete - Extra information may still be downloading from the Internet
Aug 14, 2019 10:41:59.470 [8900] Debug — DVR:Grabber: Cleaned up 0 decrepit directories in 0.0 sec.
Aug 14, 2019 10:41:59.470 [8900] Debug — Activity: registered new activity e171761f-53ec-4b95-a895-7e54374210f1 - Processing subscriptions
Aug 14, 2019 10:41:59.471 [8900] Debug — DVR:Subscription: Scheduling subscriptions.
Aug 14, 2019 10:41:59.471 [8900] Debug — DVR:Subscription: Initialized 0 schedulers.
Aug 14, 2019 10:41:59.471 [8900] Debug — DVR:Subscription: Starting with 0 grabs, scheduled 0 active ones preemptively.
Aug 14, 2019 10:41:59.472 [8900] Debug — DVR:Subscription: Scheduled all subscriptions in 0 ms.
Aug 14, 2019 10:41:59.472 [8900] Debug — Activity: Ended activity e171761f-53ec-4b95-a895-7e54374210f1.
Aug 14, 2019 10:41:59.472 [8900] Debug — DVR:Subscription: There are 0 active grabs at the end.
Aug 14, 2019 10:41:59.472 [8900] Debug — Activity: Ended activity 06bedb46-9d71-4606-8e2a-e1c71c3d25ee.
Aug 14, 2019 10:41:59.473 [8900] Debug — DVR:Subscription: Refreshed all content in 5 ms.
Aug 14, 2019 10:41:59.523 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.524 [3360] Debug — Request: [127.0.0.1:54555 (Loopback)] GET /library/sections (23 live) GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.526 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.526 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.527 [5672] Debug — Request: [127.0.0.1:54558 (Loopback)] GET /hubs/home/continueWatching?includeExternalMedia=1 (23 live) Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.527 [7072] Debug — Completed: [127.0.0.1:54555] 200 GET /library/sections (23 live) GZIP 3ms 920 bytes (pipelined: 3)
Aug 14, 2019 10:41:59.527 [4396] Debug — Request: [192.168.1.32:59759 (Subnet)] GET /library/sections (23 live) TLS GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.529 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.530 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.531 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.532 [7948] Debug — Request: [127.0.0.1:54554 (Loopback)] GET /hubs/home/onDeck?includeExternalMedia=1 (23 live) Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.533 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.535 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.536 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.542 [6724] Debug — Request: [127.0.0.1:54555 (Loopback)] GET /hubs/home/recentlyAdded?type=1&includeExternalMedia=1 (23 live) Page 0-50 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.543 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.544 [6724] Debug — Setting container serialization range to [0, 50] (total=-1)
Aug 14, 2019 10:41:59.547 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.548 [7556] Debug — Completed: [192.168.1.32:59759] 200 GET /library/sections (23 live) TLS GZIP 21ms 999 bytes (pipelined: 3)
Aug 14, 2019 10:41:59.548 [5444] Debug — Request: [192.168.1.32:59760 (Subnet)] GET /hubs/home/continueWatching?includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.550 [7924] Debug — Request: [127.0.0.1:54556 (Loopback)] GET /hubs/home/recentlyAdded?type=1&personal=1&includeExternalMedia=1 (23 live) Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.551 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.551 [7924] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:59.552 [7072] Debug — Completed: [127.0.0.1:54556] 200 GET /hubs/home/recentlyAdded?type=1&personal=1&includeExternalMedia=1 (23 live) GZIP Page 0-15 4ms 480 bytes (pipelined: 5)
Aug 14, 2019 10:41:59.555 [3360] Debug — Request: [192.168.1.32:59759 (Subnet)] GET /hubs/home/recentlyAdded?type=1&personal=1&includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.557 [3360] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:59.558 [6292] Debug — Request: [192.168.1.32:59757 (Subnet)] GET /hubs/home/onDeck?includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.559 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.560 [7556] Debug — Completed: [192.168.1.32:59759] 200 GET /hubs/home/recentlyAdded?type=1&personal=1&includeExternalMedia=1 (23 live) TLS GZIP Page 0-15 7ms 559 bytes (pipelined: 4)
Aug 14, 2019 10:41:59.560 [7456] Debug — Request: [192.168.1.32:59762 (Subnet)] GET /hubs/home/recentlyAdded?type=1&includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.562 [3616] Debug — Request: [127.0.0.1:54557 (Loopback)] GET /hubs/home/recentlyAdded?type=2&includeExternalMedia=1 (23 live) Page 0-49 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.562 [4396] Debug — Request: [127.0.0.1:54556 (Loopback)] GET /hubs/home/recentlyAdded?type=13&includeExternalMedia=1 (23 live) Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.563 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.564 [4396] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:59.566 [7456] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:59.566 [7072] Debug — Completed: [127.0.0.1:54556] 200 GET /hubs/home/recentlyAdded?type=13&includeExternalMedia=1 (23 live) GZIP Page 0-15 6ms 480 bytes (pipelined: 6)
Aug 14, 2019 10:41:59.566 [7924] Debug — Request: [192.168.1.32:59759 (Subnet)] GET /hubs/home/recentlyAdded?type=13&includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.568 [2552] Debug — Request: [192.168.1.32:59761 (Subnet)] GET /hubs/home/recentlyAdded?type=2&includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.569 [7924] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:59.570 [7072] Debug — Completed: [192.168.1.32:59759] 200 GET /hubs/home/recentlyAdded?type=13&includeExternalMedia=1 (23 live) TLS GZIP Page 0-15 5ms 559 bytes (pipelined: 5)
Aug 14, 2019 10:41:59.573 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.574 [3360] Debug — Request: [192.168.1.32:59759 (Subnet)] GET /hubs/home/recentlyAdded?type=8&includeExternalMedia=1 (23 live) TLS Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.575 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.577 [4396] Debug — Request: [192.168.1.32:59764 (Subnet)] GET /media/providers (23 live) GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.578 [3360] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:59.582 [7072] Debug — Completed: [192.168.1.32:59764] 200 GET /media/providers (23 live) GZIP 5ms 3401 bytes (pipelined: 3)
Aug 14, 2019 10:41:59.583 [3360] Debug — Setting container serialization range to [0, 15] (total=0)
Aug 14, 2019 10:41:59.584 [7072] Debug — Completed: [192.168.1.32:59759] 200 GET /hubs/home/recentlyAdded?type=8&includeExternalMedia=1 (23 live) TLS GZIP Page 0-15 10ms 559 bytes (pipelined: 6)
Aug 14, 2019 10:41:59.586 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.587 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.589 [7924] Debug — Request: [192.168.1.1:59765 (Subnet)] GET /media/providers (23 live) TLS GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.590 [4396] Debug — Request: [192.168.1.32:59759 (Subnet)] GET /library/sections/5/all?type=8&includeCollections=1&includeExternalMedia=1 (23 live) TLS Page 0--1 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.592 [4396] Debug — Setting container serialization range to [0, -1] (total=-1)
Aug 14, 2019 10:41:59.596 [7072] Debug — Completed: [192.168.1.1:59765] 200 GET /media/providers (23 live) TLS GZIP 10ms 3480 bytes (pipelined: 3)
Aug 14, 2019 10:41:59.602 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.603 [3360] Debug — Request: [192.168.1.11:54552 (Subnet)] GET /media/providers (23 live) TLS GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.609 [7556] Debug — Completed: [192.168.1.11:54552] 200 GET /media/providers (23 live) TLS GZIP 6ms 3480 bytes (pipelined: 3)
Aug 14, 2019 10:41:59.610 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.615 [7924] Debug — Request: [127.0.0.1:54556 (Loopback)] GET /hubs/home/recentlyAdded?type=8&includeExternalMedia=1 (23 live) Page 0-15 GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.617 [7924] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:41:59.621 [7924] Debug — Setting container serialization range to [0, 15] (total=0)
Aug 14, 2019 10:41:59.624 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.625 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.625 [3360] Debug — Request: [192.168.1.1:54553 (Subnet)] GET /media/providers (23 live) TLS GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.627 [2648] Debug — Request: [127.0.0.1:54551 (Loopback)] GET /media/providers (23 live) GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.630 [7072] Debug — Completed: [192.168.1.1:54553] 200 GET /media/providers (23 live) TLS GZIP 5ms 3480 bytes (pipelined: 3)
Aug 14, 2019 10:41:59.632 [7072] Debug — Completed: [127.0.0.1:54551] 200 GET /media/providers (23 live) GZIP 5ms 3480 bytes (pipelined: 3)
Aug 14, 2019 10:41:59.638 [7072] Debug — Completed: [127.0.0.1:54556] 200 GET /hubs/home/recentlyAdded?type=8&includeExternalMedia=1 (23 live) GZIP Page 0-15 27ms 480 bytes (pipelined: 7)
Aug 14, 2019 10:41:59.651 [7456] Debug — Setting container serialization range to [0, 15] (total=837)
Aug 14, 2019 10:41:59.654 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.655 [4812] Debug — Request: [127.0.0.1:54556 (Loopback)] GET /media/providers (23 live) GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.658 [7072] Debug — Completed: [192.168.1.32:59762] 200 GET /hubs/home/recentlyAdded?type=1&includeExternalMedia=1 (23 live) TLS GZIP Page 0-15 123ms 7566 bytes (pipelined: 3)
Aug 14, 2019 10:41:59.660 [7072] Debug — Completed: [127.0.0.1:54556] 200 GET /media/providers (23 live) GZIP 4ms 3401 bytes (pipelined: 8)
Aug 14, 2019 10:41:59.661 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.662 [3360] Debug — Request: [192.168.1.32:59762 (Subnet)] GET /library/sections/5/firstCharacter?type=8&includeCollections=1 (23 live) TLS GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.664 [6724] Warning — SLOW QUERY: It took 250.000000 ms to retrieve 51 items.
Aug 14, 2019 10:41:59.665 [7556] Debug — Completed: [192.168.1.32:59762] 200 GET /library/sections/5/firstCharacter?type=8&includeCollections=1 (23 live) TLS GZIP 3ms 642 bytes (pipelined: 4)
Aug 14, 2019 10:41:59.666 [6724] Debug — Setting container serialization range to [0, 50] (total=837)
Aug 14, 2019 10:41:59.668 [7556] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:41:59.669 [7456] Debug — Request: [192.168.1.32:59762 (Subnet)] GET /media/providers (23 live) TLS GZIP Signed-in Token (Server)
Aug 14, 2019 10:41:59.672 [7072] Debug — Completed: [192.168.1.32:59762] 200 GET /media/providers (23 live) TLS GZIP 3ms 3480 bytes (pipelined: 5)
Aug 14, 2019 10:41:59.686 [7072] Debug — Completed: [127.0.0.1:54555] 200 GET /hubs/home/recentlyAdded?type=1&includeExternalMedia=1 (23 live) GZIP Page 0-50 148ms 20587 bytes (pipelined: 4)
Aug 14, 2019 10:41:59.733 [3616] Debug — It took 593.750000 ms to retrieve 200 items.
Aug 14, 2019 10:41:59.770 [2552] Debug — It took 812.500000 ms to retrieve 200 items.
Aug 14, 2019 10:41:59.780 [3616] Debug — It took 156.250000 ms to retrieve 50 items.
Aug 14, 2019 10:41:59.806 [3616] Debug — Setting container serialization range to [0, 49] (total=-1)
Aug 14, 2019 10:41:59.809 [3616] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:59.809 [3616] Debug — Selecting best audio stream for part ID 31692 (autoselect: 0 language: en)
Aug 14, 2019 10:41:59.809 [3616] Debug — Audio Stream: 64066, Subtitle Stream: -1
Aug 14, 2019 10:41:59.810 [3616] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:59.811 [3616] Debug — Selecting best audio stream for part ID 31689 (autoselect: 0 language: en)
Aug 14, 2019 10:41:59.811 [3616] Debug — Audio Stream: 64060, Subtitle Stream: -1
Aug 14, 2019 10:41:59.812 [3616] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:59.812 [3616] Debug — Selecting best audio stream for part ID 31688 (autoselect: 0 language: en)
Aug 14, 2019 10:41:59.812 [3616] Debug — Audio Stream: 64058, Subtitle Stream: -1
Aug 14, 2019 10:41:59.813 [3616] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:59.813 [3616] Debug — Selecting best audio stream for part ID 31687 (autoselect: 0 language: en)
Aug 14, 2019 10:41:59.813 [3616] Debug — Audio Stream: 64055, Subtitle Stream: -1
Aug 14, 2019 10:41:59.814 [3616] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:59.814 [3616] Debug — Selecting best audio stream for part ID 31686 (autoselect: 0 language: en)
Aug 14, 2019 10:41:59.814 [3616] Debug — Audio Stream: 64053, Subtitle Stream: -1
Aug 14, 2019 10:41:59.820 [3616] Debug — There were 1 top-level paths for Little People, Big World.
Aug 14, 2019 10:41:59.820 [2552] Warning — SLOW QUERY: It took 218.750000 ms to retrieve 50 items.
Aug 14, 2019 10:41:59.821 [3616] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:59.821 [3616] Debug — Selecting best audio stream for part ID 31658 (autoselect: 0 language: en)
Aug 14, 2019 10:41:59.821 [3616] Debug — Audio Stream: 63972, Subtitle Stream: -1
Aug 14, 2019 10:41:59.826 [3616] Debug — There were 1 top-level paths for On the Case With Paula Zahn.
(content removed)
Aug 14, 2019 10:41:59.831 [3616] Debug — We're going to try to auto-select an audio stream for account 1.
Aug 14, 2019 10:41:59.831 [3616] Debug — Selecting best audio stream for part ID 31576 (autoselect: 0 language: en)
Aug 14, 2019 10:41:59.832 [3616] Debug — Audio Stream: 63480, Subtitle Stream: -1
Aug 14, 2019 10:41:59.834 [3616] Debug — There were 1 top-level paths for Judge John Deed.
(content removed)
Aug 14, 2019 10:41:59.877 [7072] Debug — Completed: [127.0.0.1:54557] 200 GET /hubs/home/recentlyAdded?type=2&includeExternalMedia=1 (23 live) GZIP Page 0-49 333ms 15408 bytes (pipelined: 5)
Aug 14, 2019 10:41:59.879 [7072] Debug — Completed: [192.168.1.32:59761] 200 GET /hubs/home/recentlyAdded?type=2&includeExternalMedia=1 (23 live) TLS GZIP Page 0-15 342ms 6156 bytes (pipelined: 9)
Aug 14, 2019 10:42:00.150 [4396] Debug — Setting container serialization range to [0, -1] (total=0)
Aug 14, 2019 10:42:00.152 [7556] Debug — Completed: [192.168.1.32:59759] 200 GET /library/sections/5/all?type=8&includeCollections=1&includeExternalMedia=1 (23 live) TLS GZIP Page 0--1 563ms 752 bytes (pipelined: 7)
Aug 14, 2019 10:42:00.379 [7948] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:42:00.380 [7556] Debug — Completed: [127.0.0.1:54554] 200 GET /hubs/home/onDeck?includeExternalMedia=1 (23 live) GZIP Page 0-15 848ms 480 bytes (pipelined: 7)
Aug 14, 2019 10:42:00.416 [6292] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:42:00.416 [7556] Debug — Completed: [192.168.1.32:59757] 200 GET /hubs/home/onDeck?includeExternalMedia=1 (23 live) TLS GZIP Page 0-15 886ms 559 bytes (pipelined: 9)
Aug 14, 2019 10:42:00.426 [5672] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:42:00.427 [7556] Debug — Completed: [127.0.0.1:54558] 200 GET /hubs/home/continueWatching?includeExternalMedia=1 (23 live) GZIP Page 0-15 900ms 480 bytes (pipelined: 3)
Aug 14, 2019 10:42:00.442 [5444] Debug — Setting container serialization range to [0, 15] (total=-1)
Aug 14, 2019 10:42:00.443 [7556] Debug — Completed: [192.168.1.32:59760] 200 GET /hubs/home/continueWatching?includeExternalMedia=1 (23 live) TLS GZIP Page 0-15 914ms 559 bytes (pipelined: 5)
Aug 14, 2019 10:42:00.654 [7072] Debug — Completed: [192.168.1.32:58332] -2 GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (23 live) TLS GZIP 20003ms 5 bytes (pipelined: 467)
Aug 14, 2019 10:42:00.660 [7072] Debug — Auth: authenticated user 1 as Server
Aug 14, 2019 10:42:00.661 [7924] Debug — Request: [192.168.1.32:58332 (Subnet)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=3&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (23 live) TLS GZIP Signed-in Token (Server)

full_log_music_scan.txt (58.0 KB)

4

I need at least the scanner log(s) as well.

5

Which one(s)? I have Plex Media Scanner Analysis, Plex Media Scanner Chapter Thumbnails, Plex Media Scanner Deep Analysis and Plex Media Scanner logs.

6

Plex Media Scanner
zip them please

or simply use the zip you get from the plex app

7

Now we’re talking!! No need to zip them up and upload them because the log is VERY short…

Small scan log results

Aug 14, 2019 11:57:56.466 [7080] INFO - Plex Media Scanner v1.16.3.1402-22929c8a2 - Microsoft PC x64 - build: windows-x86 - GMT -04:00
Aug 14, 2019 11:57:56.467 [7080] INFO - Windows version: 6.2 (Build 9200), language en-US
Aug 14, 2019 11:57:56.467 [7080] INFO - 6 2394 MHz processor(s): Architecture=0, Level=6, Revision=11266 Processor Identifier=Intel64 Family 6 Model 44 Stepping 2, GenuineIntel
Aug 14, 2019 11:57:56.467 [7080] DEBUG - “C:\Program Files (x86)\Plex\Plex Media Server\Plex Media Scanner.exe” --scan --refresh --section 5
Aug 14, 2019 11:57:56.448 [5576] DEBUG - Opening 20 database sessions to library (com.plexapp.plugins.library), SQLite 3.26.0, threadsafe=1
Aug 14, 2019 11:57:56.719 [5576] DEBUG - Scanning Music using en(Plex Music Scanner) with 0 current media items and 1 section locations in the database…
Aug 14, 2019 11:57:56.720 [2792] DEBUG - HTTP requesting GET http://127.0.0.1:32400/:/metadata/notify/cullTimeline?librarySectionID=5&sinceTime=1565797076
Aug 14, 2019 11:57:56.723 [2792] DEBUG - HTTP 200 response from GET http://127.0.0.1:32400/:/metadata/notify/cullTimeline?librarySectionID=5&sinceTime=1565797076
Aug 14, 2019 11:57:56.953 [5576] DEBUG - Performing a scan with ‘Plex Music Scanner’ (language: en virtual: 0).
Aug 14, 2019 11:57:56.953 [5576] DEBUG - * Scanning \mediaserver\mp3s
Aug 14, 2019 11:57:56.967 [5576] DEBUG - * Scanning directory \mediaserver\mp3s (parent: no)
Aug 14, 2019 11:57:56.968 [5576] WARN - Filesystem error (boost::filesystem::last_write_time: Access is denied: “\mediaserver\mp3s”) during scanning: 5 in “\mediaserver\mp3s”
Aug 14, 2019 11:57:56.968 [5576] ERROR - We got an error scanning in \mediaserver\mp3s
Aug 14, 2019 11:57:56.970 [5576] WARN - Scanning the location \mediaserver\mp3s did not complete
Aug 14, 2019 11:57:56.970 [5576] DEBUG - Since it was an incomplete scan, we are not going to whack missing media.
Aug 14, 2019 11:57:56.971 [5576] DEBUG - Refreshing section 5 of type: 8
Aug 14, 2019 11:57:57.344 [4860] DEBUG - Refreshing 0 IDs.

Looks like I have an access error. I just didn’t know where to go looking for the error. The logs/events shown in the webgui did not give me the notion to go check out those files.

This should fix my issue, Thanks!!

8

OK so above is the issue obviously. The crazy thing is, I’m logged in as the same user that is running the PlexService service. With this account I can browse and play the mp3s all day in Windows. But for some reason the PlexService cannot access the files.

Is it using something else to run the scan other than the plex service like Plex Update Service? I just expected that service to handle Plex application upgrades.

9

When accessing SMB network shares with Windows, never rely on Windows to supply special access credentials when needed.

Do the following:

  • give the Windows user account, under which plex server is running, a password
  • choose a relatively simple username for this account (i.e. avoid spaces and special characters)
  • now create the same user name, and use the same password on your file server/NAS and grant it the necessary access permissions to your various media folders

It is a very bad idea to run Plex under the Windows SYSTEM user. Not only from a security standpoint. But also because you cannot give it a password. Which then makes accessing network resources with authentication erroneous.

10

Done. The password is simple. Let’s just say it’s “plex”.

Done. The username is simple as well. It IS “plex”.

That is also done. The user “plex” has read access to that share.

But… maybe I’m not understanding you. Because it should be obvious all this is already done per my previous posts. I explained that I use the plex account to log into my PLEX server (which can see everything in the music folder). Then I use that SAME EXACT account (plex) to run the service. For some reason the service can’t see the files but the windows login can?

Does it need more than read access for some reason?

11

Normally not. But maybe your NAS is doing something weird when it comes to reading extended attributes of the root folder of a share.

I see in the log that you are pointing your Plex library directly to a network share name. \\mediaserver\mp3s (mediaserver is the host name, mp3s is the share name)
Don’t do that. Point it to a folder located inside a network share.

Try this:
Make the network share not identical with the root folder of your music collection.

e.g. Let’s says the NAS hast the host name NAS
and this NAS is offering a network share named Media
in this share there is a folder named Music which contains then the various artist folders.
so the address would be \\NAS\Media\Music
Make sure that the user Plex still has read permissions to both the parent folder where the Music folder is located in, as well as the network share named Music.
Yes, these can be differing.

Instead, make the share the parent folder of your music folder.

12

Wait a sec… I might have found the issue. It seems that the plex user is not a member of the group it should be… I think the permissions for the account are not propagating like they should for the login. I’m going to try to restart the service to see if it takes effect.

13

Thanks for all the help @OttoKerner! Pointing out those logs really helped me. It’s working now, I just needed to stop the PlexService, log off the server with the plex account I have (this way there was no plex user account currently being used), then log back on with the plex account and start the PlexService service.

It’s working perfectly now!

1 Like
14

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