Oct 27, 2018 11:53:11.424 [9700] INFO - Plex Media Server v1.13.8.5395-10d48da0d - Microsoft PC x64 - build: windows-i386 english - GMT 01:00
Oct 27, 2018 11:53:11.595 [9700] INFO - Windows version: 10.0 (Build 17134), language en-US
Oct 27, 2018 11:53:11.611 [9700] INFO - 4 1896 MHz processor(s): Architecture=0, Level=6, Revision=17665 Processor Identifier=Intel64 Family 6 Model 69 Stepping 1, GenuineIntel
Oct 27, 2018 11:53:11.611 [9700] DEBUG - "C:\Program Files (x86)\Plex\Plex Media Server\Plex Media Server.exe" 
Oct 27, 2018 11:53:11.611 [9476] DEBUG - Granting application loopback exemption: "C:\WINDOWS\system32\CheckNetIsolation.exe" LoopbackExempt -a "-n=caf9e577.plex_aam28m9va5cke"
Oct 27, 2018 11:53:13.362 [3388] DEBUG - Job running: C:\Program Files (x86)\Plex\Plex Media Server\CrashUploader.exe "--directory=C:\Users\craig\AppData\Local\Plex Media Server\Crash Reports\1.13.8.5395-10d48da0d" --version=1.13.8.5395-10d48da0d "--platform=windows-i386 (10.0 (Build 17134))" --serverUuid=7e0d395b9e4a10d7fb39e3151eecdf3274164576 --userId=email@craigtubby.co.uk --url=https://crashreport.plexapp.com 
Oct 27, 2018 11:53:13.362 [9476] ERROR - CheckNetIsolation.exe exited with code 0x5
Oct 27, 2018 11:53:13.362 [9476] ERROR - Failed to grant application loopback exemption
Oct 27, 2018 11:53:13.424 [3388] DEBUG - Jobs: Starting child process with pid 9756
Oct 27, 2018 11:53:13.987 [9476] DEBUG - BPQ: [Idle] -> [Starting]
Oct 27, 2018 11:53:14.018 [9824] DEBUG - Jobs: 'C:\Program Files (x86)\Plex\Plex Media Server\CrashUploader.exe' exit code for process 9756 is 0 (success)
Oct 27, 2018 11:53:14.205 [9476] DEBUG - FeatureManager: Using cached data for features list
Oct 27, 2018 11:53:14.425 [9476] DEBUG - Opening 20 database sessions to library (com.plexapp.plugins.library), SQLite 3.13.0, threadsafe=1
Oct 27, 2018 11:53:15.487 [9476] INFO - SQLITE3:0x155ae247, 283, recovered 317 frames from WAL file C:\Users\craig\AppData\Local\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Oct 27, 2018 11:53:15.706 [9476] DEBUG - Running migrations. (EPG 0)
Oct 27, 2018 11:53:16.348 [9476] DEBUG - ChangestampAllocator: initialized to 1639391
Oct 27, 2018 11:53:16.379 [9476] DEBUG - Opening 2 database sessions to library (com.plexapp.plugins.library.blobs), SQLite 3.13.0, threadsafe=1
Oct 27, 2018 11:53:16.457 [9476] INFO - SQLITE3:0x155ae247, 283, recovered 125 frames from WAL file C:\Users\craig\AppData\Local\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.blobs.db-wal
Oct 27, 2018 11:53:16.504 [9476] DEBUG - Running migrations. (EPG 0)
Oct 27, 2018 11:53:18.113 [9476] DEBUG - CERT: Installed certificate with fingerprint 9f:25:a9:2b:e8:5d:f7:86:73:cc:8f:d6:7a:ff:15:16:e8:e3:1b:c8.
Oct 27, 2018 11:53:18.113 [9476] DEBUG - CERT: Installed new private key.
Oct 27, 2018 11:53:18.113 [9476] DEBUG - CERT: Subject name is /C=US/ST=California/L=Los Gatos/O=Plex, Inc./CN=*.ad427cb724c341cca480923eb5887d20.plex.direct
Oct 27, 2018 11:53:18.144 [9476] DEBUG - CERT: OCSP requests for stapling will be made to 'http://ocspx.digicert.com/'.
Oct 27, 2018 11:53:18.160 [9476] INFO - OCSP: Successfully retrieved response from cache.
Oct 27, 2018 11:53:18.160 [9476] DEBUG - CERT: Installed intermediate certificate.
Oct 27, 2018 11:53:18.301 [9476] DEBUG - NetworkInterface: ignoring adapter 'Bluetooth Network Connection 2' (fe80::4926:b0f8:818e:dd3d%12,169.254.221.61) because it has no gateway
Oct 27, 2018 11:53:18.301 [9476] DEBUG - NetworkInterface: ignoring adapter 'Loopback Pseudo-Interface 1' (::1,127.0.0.1) because it has no gateway
Oct 27, 2018 11:53:18.301 [9476] DEBUG - NetworkInterface: ignoring adapter 'vEthernet (Default Switch)' (fe80::48e4:3f73:1a7b:fe4c%9,172.26.5.81) because it has no gateway
Oct 27, 2018 11:53:18.301 [9476] DEBUG - HttpServer: Listening on port 32400 with queue of 2147483647 connections.
Oct 27, 2018 11:53:18.317 [9476] DEBUG - HttpServer: Listening on port 32401 with queue of 2147483647 connections.
Oct 27, 2018 11:53:18.676 [3388] DEBUG - DVR:Grabber: Cleaning up orphaned grabs.
Oct 27, 2018 11:53:18.754 [9476] DEBUG - Media Provider: Registering provider com.plexapp.plugins.library
Oct 27, 2018 11:53:18.770 [9476] DEBUG - Auth: Refreshing tokens inside the token-based authentication filter.
Oct 27, 2018 11:53:18.801 [3844] DEBUG - Relay: read 14 cached entries from hosts file
Oct 27, 2018 11:53:18.848 [3844] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:18.879 [9476] DEBUG - MyPlex: using cached data for request for https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Oct 27, 2018 11:53:18.957 [9476] DEBUG - MyPlex: updating with 55 access tokens
Oct 27, 2018 11:53:19.176 [3920] DEBUG - Auth: Refreshing tokens inside the token-based authentication filter.
Oct 27, 2018 11:53:19.176 [3920] DEBUG - HTTP requesting GET https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Oct 27, 2018 11:53:19.489 [4000] DEBUG - File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d" changed: -1 => 2018-10-13 19:06:55 (1539454015).
Oct 27, 2018 11:53:19.520 [4000] DEBUG - File "C:\Users\craig\AppData\Local\Plex Media Server\Plug-ins" changed: -1 => 2018-10-10 17:52:12 (1539190332).
Oct 27, 2018 11:53:19.520 [4000] DEBUG - Scanning for plug-ins in "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d"
Oct 27, 2018 11:53:19.582 [3844] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:19.676 [3920] DEBUG - HTTP 200 response from GET https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Oct 27, 2018 11:53:19.692 [3920] DEBUG - MyPlex: updating with 55 access tokens
Oct 27, 2018 11:53:19.692 [3948] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:19.848 [3948] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:19.848 [3948] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:20.020 [3948] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:20.332 [4000] DEBUG - Scanning for plug-ins in "C:\Users\craig\AppData\Local\Plex Media Server\Plug-ins"
Oct 27, 2018 11:53:20.614 [3388] DEBUG - DVR:Grabber: Cleaned up 0 decrepit directories in 0.7 sec.
Oct 27, 2018 11:53:20.661 [4000] DEBUG - PluginRepository::setStartState: 1, startingSystem
Oct 27, 2018 11:53:20.661 [4000] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\System.bundle.
Oct 27, 2018 11:53:20.661 [4000] DEBUG - [com.plexapp.system] Setting plug-in to always running (daemon mode).
Oct 27, 2018 11:53:20.895 [4000] DEBUG - Starting file watcher for com.plexapp.system
Oct 27, 2018 11:53:20.911 [4000] DEBUG - Plugin::createProcess: Creating plugin process: "C:\Program Files (x86)\Plex\Plex Media Server\PlexScriptHost.exe" "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\Framework.bundle\Contents\Resources\Versions\2\Python\bootstrap.py" "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\System.bundle"
Oct 27, 2018 11:53:21.004 [4000] DEBUG - Spawned plug-in com.plexapp.system with PID 4324
Oct 27, 2018 11:53:21.004 [4000] DEBUG - [com.plexapp.system] Sending command: GET /:/prefixes

Oct 27, 2018 11:53:27.335 [4000] DEBUG - Reading 486 bytes in the body, code is 200
Oct 27, 2018 11:53:27.335 [4000] DEBUG - [com.plexapp.system] Plug-in running on port 49877.
Oct 27, 2018 11:53:27.335 [4000] DEBUG -  * Plug-in handles prefix: /system
Oct 27, 2018 11:53:27.335 [4000] DEBUG -  * Plug-in handles prefix: /player
Oct 27, 2018 11:53:27.335 [4000] DEBUG - Read configuration for [com.plexapp.system], had 2 prefixes
Oct 27, 2018 11:53:27.475 [4000] DEBUG - Done with 1 synchronous plug-in starts, starting the rest in parallel.
Oct 27, 2018 11:53:27.475 [4000] DEBUG - PluginRepository::setStartState: 2, startingPlugins
Oct 27, 2018 11:53:27.475 [4000] DEBUG - Updating the list of agents known by the system.
Oct 27, 2018 11:53:27.475 [4000] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/agents
Oct 27, 2018 11:53:27.475 [4000] DEBUG - HTTP requesting GET http://127.0.0.1:49877/system/agents
Oct 27, 2018 11:53:27.553 [9476] DEBUG - Image transcode cache directory: "C:\Users\craig\AppData\Local\Plex Media Server\Cache\PhotoTranscoder"
Oct 27, 2018 11:53:27.553 [9476] DEBUG - Transcoder: Cleaning old transcode directories.
Oct 27, 2018 11:53:27.585 [9476] DEBUG - MyPlex: using cached data for request for https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Oct 27, 2018 11:53:27.585 [9476] DEBUG - MyPlex: updating with 55 access tokens
Oct 27, 2018 11:53:27.585 [4044] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:27.632 [9476] DEBUG - MyPlex: using cached data for request for https://plex.tv/users/account.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeGeolocation=1
Oct 27, 2018 11:53:27.710 [9476] DEBUG - MyPlex: username is tubs74, login is email@craigtubby.co.uk, home is 1, has pin
Oct 27, 2018 11:53:27.710 [9476] DEBUG - PublicAddressManager: Starting.
Oct 27, 2018 11:53:27.710 [5744] DEBUG - HTTP requesting GET https://plex.tv/users/account.xml?auth_token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:27.757 [9476] DEBUG - PublicAddressManager: Obtaining public address and mapping port.
Oct 27, 2018 11:53:27.757 [9476] DEBUG - NetworkInterface: Notified of network changed (force=0)
Oct 27, 2018 11:53:27.757 [3844] DEBUG - PublicAddressManager: Obtaining public IP.
Oct 27, 2018 11:53:27.757 [3844] DEBUG - HTTP requesting GET http://plex.tv/pms/:/ip
Oct 27, 2018 11:53:27.772 [9476] DEBUG - Network interfaces:
Oct 27, 2018 11:53:27.772 [9476] DEBUG -  * 6 vEthernet (New Virtual Switch) {3183A285-F0A2-4D7A-90E0-FE389F2042E6} (192.168.1.146) (loopback: 0)
Oct 27, 2018 11:53:27.772 [9476] DEBUG - Creating NetworkServices singleton.
Oct 27, 2018 11:53:27.772 [9476] DEBUG - NetworkServices: Initializing...
Oct 27, 2018 11:53:27.772 [9476] DEBUG - NetworkService: Creating new service.
Oct 27, 2018 11:53:27.772 [4044] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Got notification of changed network (first change: 1)
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Quick dispatch of network change.
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Creating new service.
Oct 27, 2018 11:53:27.788 [7524] DEBUG - Network change for advertiser.
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Got notification of changed network (first change: 1)
Oct 27, 2018 11:53:27.788 [7524] DEBUG - NetworkService: Setting up multicast listener on 0.0.0.0:32414 (outbound: 0)
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Quick dispatch of network change.
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Creating new service.
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Got notification of changed network (first change: 1)
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Quick dispatch of network change.
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Creating new service.
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Got notification of changed network (first change: 1)
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Quick dispatch of network change.
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Creating new service.
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Got notification of changed network (first change: 1)
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Quick dispatch of network change.
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Creating new service.
Oct 27, 2018 11:53:27.772 [4044] DEBUG - NAT: UPnP, attempting port mapping.
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Got notification of changed network (first change: 1)
Oct 27, 2018 11:53:27.788 [9476] DEBUG - NetworkService: Quick dispatch of network change.
Oct 27, 2018 11:53:27.803 [3844] DEBUG - HTTP 200 response from GET http://plex.tv/pms/:/ip
Oct 27, 2018 11:53:27.819 [3844] DEBUG - PublicAddressManager: Got public IP from http://plex.tv: 86.139.150.227
Oct 27, 2018 11:53:27.882 [7524] DEBUG - Network change for advertiser.
Oct 27, 2018 11:53:27.882 [7524] DEBUG - NetworkService: Setting up multicast listener on 0.0.0.0:32410 (outbound: 0)
Oct 27, 2018 11:53:27.882 [7524] DEBUG - Network change for advertiser.
Oct 27, 2018 11:53:27.897 [7524] DEBUG - NetworkService: Setting up multicast listener on 0.0.0.0:32412 (outbound: 0)
Oct 27, 2018 11:53:27.944 [7524] DEBUG - NetworkService: Network change for browser (polled=0), closing 0 browse sockets.
Oct 27, 2018 11:53:27.944 [7524] DEBUG - NetworkService: Setting up multicast listener on 0.0.0.0:32413 (outbound: 0)
Oct 27, 2018 11:53:27.944 [7524] DEBUG - NetworkService: Browsing on interface 192.168.1.146 on broadcast address 192.168.1.255 (index: 0)
Oct 27, 2018 11:53:27.944 [7524] DEBUG - NetworkService: Network change for browser (polled=1), closing 0 browse sockets.
Oct 27, 2018 11:53:27.944 [7524] DEBUG - NetworkService: Browsing on interface 192.168.1.146 on broadcast address 192.168.1.255 (index: 0)
Oct 27, 2018 11:53:27.944 [7524] DEBUG - NetworkService: Network change for browser (polled=0), closing 0 browse sockets.
Oct 27, 2018 11:53:27.944 [7524] DEBUG - NetworkService: Setting up multicast listener on 0.0.0.0:1901 (outbound: 0)
Oct 27, 2018 11:53:27.944 [7524] DEBUG - NetworkService: Browsing on interface 192.168.1.146 on broadcast address 239.255.255.250 (index: 0)
Oct 27, 2018 11:53:27.960 [5744] DEBUG - HTTP 200 response from GET https://plex.tv/users/account.xml?auth_token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:28.038 [5744] DEBUG - MyPlex: username is tubs74, login is email@craigtubby.co.uk, home is 1, has pin
Oct 27, 2018 11:53:28.069 [5744] DEBUG - HTTP requesting GET https://plex.tv/api/v2/features?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:28.225 [5744] DEBUG - HTTP 200 response from GET https://plex.tv/api/v2/features?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:28.272 [5744] DEBUG - HTTP requesting GET https://plex.tv/api/v2/user/privacy?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:28.444 [5744] DEBUG - HTTP 200 response from GET https://plex.tv/api/v2/user/privacy?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:28.491 [5744] DEBUG - Sync: onMyPlexSignIn
Oct 27, 2018 11:53:28.491 [5744] DEBUG - HTTP requesting GET https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/sync_lists?auth_token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:28.678 [3920] DEBUG - DVR:Device: Discovering and refreshing all devices.
Oct 27, 2018 11:53:28.757 [3920] DEBUG - DVR:Grabber: HDHomerun discovered 0 compatible devices.
Oct 27, 2018 11:53:28.772 [5744] DEBUG - HTTP 200 response from GET https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/sync_lists?auth_token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:28.788 [3920] DEBUG - HTTP requesting POST http://127.0.0.1:32600/devices/discover
Oct 27, 2018 11:53:28.819 [4000] DEBUG - HTTP 200 response from GET http://127.0.0.1:49877/system/agents
Oct 27, 2018 11:53:28.819 [4000] DEBUG - [com.plexapp.system] HTTP reply status 200, with 9036 bytes of content.
Oct 27, 2018 11:53:28.819 [4000] DEBUG - The system knows about 13 agents.
Oct 27, 2018 11:53:28.819 [5900] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\Fanart-TV.bundle.
Oct 27, 2018 11:53:28.819 [7048] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\Framework.bundle.
Oct 27, 2018 11:53:28.835 [4000] DEBUG - Waiting for 24 plug-ins to finish starting.
Oct 27, 2018 11:53:28.835 [8364] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\HTbackdrops.bundle.
Oct 27, 2018 11:53:28.835 [7048] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\LastFM.bundle.
Oct 27, 2018 11:53:28.835 [7048] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.lastfm] yet.
Oct 27, 2018 11:53:28.835 [8364] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.htbackdrops] yet.
Oct 27, 2018 11:53:28.835 [7048] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\LocalMedia.bundle.
Oct 27, 2018 11:53:28.835 [8364] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\LyricFind.bundle.
Oct 27, 2018 11:53:28.850 [5900] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.fanarttv] yet.
Oct 27, 2018 11:53:28.850 [5900] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\Media-Flags.bundle.
Oct 27, 2018 11:53:28.850 [5900] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\MoviePosterDB.bundle.
Oct 27, 2018 11:53:28.882 [8364] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.lyricfind] yet.
Oct 27, 2018 11:53:28.882 [8364] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\OpenSubtitles.bundle.
Oct 27, 2018 11:53:28.882 [5900] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.movieposterdb] yet.
Oct 27, 2018 11:53:28.882 [5900] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\PersonalMedia.bundle.
Oct 27, 2018 11:53:28.913 [5900] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.none] yet.
Oct 27, 2018 11:53:28.913 [5900] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\PlexMovie.bundle.
Oct 27, 2018 11:53:28.913 [8364] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.opensubtitles] yet.
Oct 27, 2018 11:53:28.913 [8364] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\PlexMusic.bundle.
Oct 27, 2018 11:53:28.944 [9476] DEBUG - Gracenote Version 3.07.7.3686 (build: 2015-07-05 11:53-0700)
Oct 27, 2018 11:53:28.960 [8364] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.plexmusic] yet.
Oct 27, 2018 11:53:28.960 [8364] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\PlexThemeMusic.bundle.
Oct 27, 2018 11:53:28.960 [5900] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.imdb] yet.
Oct 27, 2018 11:53:28.960 [5900] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\Scanners.bundle.
Oct 27, 2018 11:53:28.960 [5900] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\TheMovieDB.bundle.
Oct 27, 2018 11:53:28.975 [8364] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.plexthememusic] yet.
Oct 27, 2018 11:53:28.975 [8364] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\TheTVDB.bundle.
Oct 27, 2018 11:53:29.022 [5900] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.themoviedb] yet.
Oct 27, 2018 11:53:29.022 [5900] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle.
Oct 27, 2018 11:53:29.022 [5900] DEBUG - Starting plug-in C:\Users\craig\AppData\Local\Plex Media Server\Plug-ins\BBC iPlayer.bundle.
Oct 27, 2018 11:53:29.038 [8364] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.thetvdb] yet.
Oct 27, 2018 11:53:29.038 [8364] DEBUG - Starting plug-in C:\Users\craig\AppData\Local\Plex Media Server\Plug-ins\CcloudTv.bundle.
Oct 27, 2018 11:53:29.054 [5744] DEBUG - Sync: downloaded 3 sync lists, analyzing now...
Oct 27, 2018 11:53:29.100 [5900] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.plugins.iplayer] yet.
Oct 27, 2018 11:53:29.100 [5900] DEBUG -  * Added BBC iPlayer at /video/iplayer
Oct 27, 2018 11:53:29.100 [5900] DEBUG - Starting plug-in C:\Users\craig\AppData\Local\Plex Media Server\Plug-ins\Crunchyroll.bundle.
Oct 27, 2018 11:53:29.132 [5744] DEBUG - Sync: sync list 26054734: user 1 (tubs74), device Emma’s iPhone, profile iOS, id C3E425F6-5BBD-48D9-808F-6D0ECA92A45C, sync item(s): 28989790,28989793,28989804,28989810
Oct 27, 2018 11:53:29.132 [5744] DEBUG - Sync: sync list 24750675: user 1 (tubs74), device iPhone, profile iOS, id CA59F2C9-6404-464D-9F3A-CD769CA78600, sync item(s): 29255612,29433922,29433930,29433931,29433934
Oct 27, 2018 11:53:29.132 [5744] DEBUG - Sync: sync list 25669848: user 18823418 (Seb), device Seb?s iPhone, profile iOS, id 035146E6-B486-4FE3-AB8B-B6B9D5FAAF75, sync item(s): 30074073,30074170,30074197,30074212,30074237,30115400,30116959,30116965,30168043
Oct 27, 2018 11:53:29.132 [5744] DEBUG - Sync: synchronizing 3 sync lists to generators
Oct 27, 2018 11:53:29.147 [9476] DEBUG - Gracenote: Using SQLite 3.13.0
Oct 27, 2018 11:53:29.194 [5900] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.plugins.crunchyroll] yet.
Oct 27, 2018 11:53:29.194 [5900] DEBUG -  * Added Crunchyroll at /video/crunchyroll
Oct 27, 2018 11:53:29.194 [5900] DEBUG - Starting plug-in C:\Users\craig\AppData\Local\Plex Media Server\Plug-ins\ITV-Player.bundle.
Oct 27, 2018 11:53:29.194 [7048] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.localmedia] yet.
Oct 27, 2018 11:53:29.194 [7048] DEBUG - Starting plug-in C:\Users\craig\AppData\Local\Plex Media Server\Plug-ins\Services.bundle.
Oct 27, 2018 11:53:29.194 [7048] DEBUG - Starting plug-in C:\Users\craig\AppData\Local\Plex Media Server\Plug-ins\TWiT.TV.bundle.
Oct 27, 2018 11:53:29.225 [8364] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.plugins.ccloudtv] yet.
Oct 27, 2018 11:53:29.225 [8364] DEBUG -  * Added cCloud TV | A Community based Social IPTV Service for Live TV, Movies, TV Shows & Radio at /video/ccloudtv
Oct 27, 2018 11:53:29.225 [8364] DEBUG - Starting plug-in C:\Users\craig\AppData\Local\Plex Media Server\Plug-ins\WebTools.bundle.
Oct 27, 2018 11:53:29.225 [8364] DEBUG - [com.plexapp.plugins.WebTools] Setting plug-in to always running (daemon mode).
Oct 27, 2018 11:53:29.257 [7048] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.plugins.twitlive] yet.
Oct 27, 2018 11:53:29.257 [7048] DEBUG -  * Added TWiT.TV at /video/twittv
Oct 27, 2018 11:53:29.273 [8412] DEBUG - Plex Dlna Server.exe starting.
Oct 27, 2018 11:53:29.288 [8412] DEBUG - Job running: C:\Program Files (x86)\Plex\Plex Media Server\Plex Dlna Server.exe 
Oct 27, 2018 11:53:29.413 [5900] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.plugins.itvplayer] yet.
Oct 27, 2018 11:53:29.413 [5900] DEBUG -  * Added ITV Player at /video/itv
Oct 27, 2018 11:53:29.491 [8412] DEBUG - Jobs: Starting child process with pid 7496
Oct 27, 2018 11:53:29.507 [9476] DEBUG - Starting HTTP server.
Oct 27, 2018 11:53:29.507 [7752] DEBUG - Plex Tuner Service.exe starting.
Oct 27, 2018 11:53:29.507 [9476] DEBUG - Running server...
Oct 27, 2018 11:53:29.523 [9476] DEBUG - Waiting for server condition to be signaled.
Oct 27, 2018 11:53:29.523 [7752] DEBUG - Job running: C:\Program Files (x86)\Plex\Plex Media Server\Plex Tuner Service.exe "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Tuner\Private" "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Tuner\Shared" 1.13.8.5395-10d48da0d 32600 /waitmutex 
Oct 27, 2018 11:53:29.523 [8504] DEBUG - HttpServer: Set up a thread pool with 2 threads.
Oct 27, 2018 11:53:29.523 [8504] DEBUG - HTTP requesting GET https://plex.tv/api/v2/features?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:29.616 [6092] DEBUG - Request: [127.0.0.1:49873 (Loopback)] GET / (8 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:29.616 [8600] DEBUG - Request: [127.0.0.1:49874 (Loopback)] GET /:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_ (8 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:29.616 [6876] DEBUG - Request: [127.0.0.1:49875 (Loopback)] GET / (8 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:29.616 [7844] DEBUG - Request: [127.0.0.1:49876 (Loopback)] GET /servers (8 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:29.695 [8504] DEBUG - HTTP 200 response from GET https://plex.tv/api/v2/features?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:29.695 [7752] DEBUG - Jobs: Starting child process with pid 5720
Oct 27, 2018 11:53:29.710 [5744] DEBUG - Sync: synchronized 3 sync list(s) to 18 generators
Oct 27, 2018 11:53:29.710 [5744] INFO - Sync: downloaded 3 sync list(s) with 18 sync items(s): 0 new, 0 updated, 0 deleted
Oct 27, 2018 11:53:29.710 [0296] DEBUG - BPQ: garbageCollect - sync - forced - 8
Oct 27, 2018 11:53:29.710 [0296] DEBUG - Sync: starting Sync garbage collection: 8, forced
Oct 27, 2018 11:53:29.710 [5744] DEBUG - HTTP requesting GET https://plex.tv/api/v2/release_channels?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:29.726 [8504] DEBUG - HTTP requesting GET https://plex.tv/api/v2/user/privacy?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale ar
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale cs_CZ
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale da
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale de
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale en
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale es
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale et_EE
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale fr
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale he
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale hr_HR
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale hu_HU
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale it
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale ja_JP
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale ko
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale lt
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale nl
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale nl_BE
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale no
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale pt_BR
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale ro
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale ru
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale sr
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale sv
Oct 27, 2018 11:53:29.773 [6092] DEBUG - Translator: Found locale zh_CN
Oct 27, 2018 11:53:29.804 [0296] DEBUG - Sync: scanning for items to reprocess in sync list 26054734
Oct 27, 2018 11:53:29.835 [5744] DEBUG - HTTP 200 response from GET https://plex.tv/api/v2/release_channels?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:29.866 [0296] DEBUG - Sync: scanned for items to reprocess in sync list 26054734
Oct 27, 2018 11:53:29.866 [0296] DEBUG - Sync: scanning for items to reprocess in sync list 24750675
Oct 27, 2018 11:53:29.866 [0296] DEBUG - Sync: scanned for items to reprocess in sync list 24750675
Oct 27, 2018 11:53:29.866 [0296] DEBUG - Sync: scanning for items to reprocess in sync list 25669848
Oct 27, 2018 11:53:29.866 [8504] DEBUG - HTTP 200 response from GET https://plex.tv/api/v2/user/privacy?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:29.882 [8504] DEBUG - Running database fix-ups.
Oct 27, 2018 11:53:29.882 [4444] DEBUG - HTTP requesting GET https://plex.tv/api/v2/server/webhooks?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:29.898 [9824] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:29.898 [5744] DEBUG - EventSource: Resolving 139.162.227.137 port 443s
Oct 27, 2018 11:53:29.945 [3788] DEBUG - EventSource: Resolved 139.162.227.137 to 139.162.227.137
Oct 27, 2018 11:53:29.991 [0296] DEBUG - Sync: scanned for items to reprocess in sync list 25669848
Oct 27, 2018 11:53:29.991 [0296] DEBUG - Sync: finished Sync garbage collection: 8
Oct 27, 2018 11:53:29.991 [0296] DEBUG - Sync: updating status for sync list 26054734, sync item 28989790, generator 2216
Oct 27, 2018 11:53:29.991 [3788] DEBUG - EventSource: Connected in 34 ms.
Oct 27, 2018 11:53:29.991 [3776] DEBUG - EventSource: Wrote data, reading reply.
Oct 27, 2018 11:53:30.070 [9824] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:30.085 [3776] DEBUG - EventSource: Read HTTP reply header.
Oct 27, 2018 11:53:30.085 [3776] DEBUG - MyPlex: We appear to have regained Internet connectivity.
Oct 27, 2018 11:53:30.101 [8504] DEBUG - Database Fixups: Destroyed 0 transient items.
Oct 27, 2018 11:53:30.148 [4444] DEBUG - HTTP 200 response from GET https://plex.tv/api/v2/server/webhooks?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:30.195 [8364] DEBUG - Starting file watcher for com.plexapp.plugins.WebTools
Oct 27, 2018 11:53:30.195 [8364] DEBUG - Plugin::createProcess: Creating plugin process: "C:\Program Files (x86)\Plex\Plex Media Server\PlexScriptHost.exe" "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\Framework.bundle\Contents\Resources\Versions\2\Python\bootstrap.py" "C:\Users\craig\AppData\Local\Plex Media Server\Plug-ins\WebTools.bundle"
Oct 27, 2018 11:53:30.320 [8364] DEBUG - Spawned plug-in com.plexapp.plugins.WebTools with PID 8932
Oct 27, 2018 11:53:30.320 [8364] DEBUG - [com.plexapp.plugins.WebTools] Sending command: GET /:/prefixes

Oct 27, 2018 11:53:30.820 [3844] DEBUG - NAT: UPnP, found device <http://192.168.1.254:49153/4451712f/gatedesc0b.xml> with private address <192.168.1.146>
Oct 27, 2018 11:53:30.820 [3844] DEBUG - NAT: UPnP, usable device <http://192.168.1.254:49153/4451712f/gatedesc0b.xml> with private address <192.168.1.146>.
Oct 27, 2018 11:53:30.820 [3844] DEBUG - NAT: UPnP, public address is 86.139.150.227
Oct 27, 2018 11:53:30.835 [3920] ERROR - Error issuing curl_easy_perform(handle): 7
Oct 27, 2018 11:53:30.835 [3920] WARN - HTTP error requesting POST http://127.0.0.1:32600/devices/discover (0, No error) (Failed connect to 127.0.0.1:32600; No error)
Oct 27, 2018 11:53:30.835 [3920] DEBUG - DVR:Grabber: Failed to retrieve device data
Oct 27, 2018 11:53:30.851 [3776] DEBUG - PublicAddressManager: Obtaining public address and mapping port.
Oct 27, 2018 11:53:30.851 [3776] DEBUG - EventSource: Successfully connected to 139.162.227.137.
Oct 27, 2018 11:53:30.851 [3948] DEBUG - PublicAddressManager: Obtaining public IP.
Oct 27, 2018 11:53:30.851 [3948] DEBUG - HTTP requesting GET http://plex.tv/pms/:/ip
Oct 27, 2018 11:53:30.851 [0296] DEBUG - BPQ: generator 2216 is in complete state
Oct 27, 2018 11:53:30.851 [0296] DEBUG - Sync: sync list 26054734, sync item 28989790 is in complete state
Oct 27, 2018 11:53:30.851 [0296] DEBUG - Sync: updating status for sync list 26054734, sync item 28989793, generator 2217
Oct 27, 2018 11:53:30.867 [8936] DEBUG - MyPlex: Sending Server Info to myPlex (user=email@craigtubby.co.uk, ip=, port=0)
Oct 27, 2018 11:53:30.867 [8936] DEBUG - HTTP requesting POST https://plex.tv/servers.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&async=1&asyncIdentifier=d78af6b0-3169-483d-b6f7-50e96b0ef8c0
Oct 27, 2018 11:53:30.882 [5744] DEBUG - MyPlex: Updating device connections (from timer: 0)
Oct 27, 2018 11:53:30.882 [5744] DEBUG - HTTP requesting PUT https://plex.tv/devices/7e0d395b9e4a10d7fb39e3151eecdf3274164576?Connection[][uri]=http://192.168.1.146:32400&httpsEnabled=1&httpsRequired=0&X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:30.898 [4044] DEBUG - NAT: UPnP, found device <http://192.168.1.254:49153/4451712f/gatedesc0b.xml> with private address <192.168.1.146>
Oct 27, 2018 11:53:30.898 [4044] DEBUG - NAT: UPnP, usable device <http://192.168.1.254:49153/4451712f/gatedesc0b.xml> with private address <192.168.1.146>.
Oct 27, 2018 11:53:30.898 [3948] DEBUG - HTTP 200 response from GET http://plex.tv/pms/:/ip
Oct 27, 2018 11:53:30.898 [3948] DEBUG - PublicAddressManager: Got public IP from http://plex.tv: 86.139.150.227
Oct 27, 2018 11:53:31.023 [4044] DEBUG - NAT: UPnP, mapped port 13407 to 192.168.1.146:32400.
Oct 27, 2018 11:53:31.054 [5744] DEBUG - HTTP 200 response from PUT https://plex.tv/devices/7e0d395b9e4a10d7fb39e3151eecdf3274164576?Connection[][uri]=http://192.168.1.146:32400&httpsEnabled=1&httpsRequired=0&X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:31.054 [5744] DEBUG - CERT: Certificate will not expire soon.
Oct 27, 2018 11:53:31.117 [8936] DEBUG - HTTP 201 response from POST https://plex.tv/servers.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&async=1&asyncIdentifier=d78af6b0-3169-483d-b6f7-50e96b0ef8c0
Oct 27, 2018 11:53:31.117 [8936] DEBUG - MyPlex: Published Mapping State response was 201
Oct 27, 2018 11:53:31.117 [8936] DEBUG - MyPlex: Got response for 7e0d395b9e4a10d7fb39e3151eecdf3274164576 ~ registered :0
Oct 27, 2018 11:53:31.148 [8600] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_
Oct 27, 2018 11:53:31.148 [8600] DEBUG - HTTP requesting GET http://127.0.0.1:49877/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_
Oct 27, 2018 11:53:31.148 [3776] DEBUG - Completed: [127.0.0.1:49876] 200 GET /servers (8 live) GZIP 1527ms 489 bytes
Oct 27, 2018 11:53:31.257 [10176] DEBUG - Request: [127.0.0.1:49906 (Loopback)] GET / (9 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:31.320 [8600] DEBUG - HTTP 200 response from GET http://127.0.0.1:49877/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_
Oct 27, 2018 11:53:31.320 [3776] DEBUG - EventSource: Got event [data] '<Message address="" port="0" asyncIdentifier="d78af6b0-3169-483d-b6f7-50e96b0ef8c0" connectivity="0" command="notifyConnectivity"/>'
Oct 27, 2018 11:53:31.320 [8600] DEBUG - [com.plexapp.system] HTTP reply status 200, with 62566 bytes of content.
Oct 27, 2018 11:53:31.320 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:31.320 [3788] DEBUG - Completed: [127.0.0.1:49874] 200 GET /:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_ (9 live) GZIP 1710ms 20198 bytes
Oct 27, 2018 11:53:31.320 [7844] DEBUG - Request: [192.168.1.199:57226 (Allowed Network)] GET / (9 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:31.632 [3388] DEBUG - Gracenote: Loading 29 locales in 2.5 seconds.
Oct 27, 2018 11:53:31.695 [0296] DEBUG - BPQ: generator 2217 is in complete state
Oct 27, 2018 11:53:31.695 [0296] DEBUG - Sync: sync list 26054734, sync item 28989793 is in complete state
Oct 27, 2018 11:53:31.711 [0296] DEBUG - Sync: updating status for sync list 26054734, sync item 28989804, generator 2218
Oct 27, 2018 11:53:32.351 [0296] DEBUG - BPQ: generator 2218 is in complete state
Oct 27, 2018 11:53:32.351 [0296] DEBUG - Sync: sync list 26054734, sync item 28989804 is in complete state
Oct 27, 2018 11:53:32.367 [0296] DEBUG - Sync: updating status for sync list 26054734, sync item 28989810, generator 2219
Oct 27, 2018 11:53:32.617 [0296] DEBUG - BPQ: generator 2219 is in complete state
Oct 27, 2018 11:53:32.617 [0296] DEBUG - Sync: sync list 26054734, sync item 28989810 is in complete state
Oct 27, 2018 11:53:32.632 [0296] DEBUG - Sync: updating status for sync list 24750675, sync item 29255612, generator 2240
Oct 27, 2018 11:53:32.664 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:32.664 [6348] DEBUG - Request: [192.168.1.199:57211 (Allowed Network)] GET / (10 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:32.664 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:32.664 [6344] DEBUG - Request: [192.168.1.199:57212 (Allowed Network)] GET / (10 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:32.726 [0296] DEBUG - BPQ: generator 2240 is in complete state
Oct 27, 2018 11:53:32.726 [0296] DEBUG - Sync: sync list 24750675, sync item 29255612 is in complete state
Oct 27, 2018 11:53:32.742 [0296] DEBUG - Sync: updating status for sync list 24750675, sync item 29433922, generator 2257
Oct 27, 2018 11:53:32.742 [0296] DEBUG - BPQ: generator 2257 is in complete state
Oct 27, 2018 11:53:32.742 [0296] DEBUG - Sync: sync list 24750675, sync item 29433922 is in complete state
Oct 27, 2018 11:53:32.742 [0296] DEBUG - Sync: updating status for sync list 24750675, sync item 29433930, generator 2258
Oct 27, 2018 11:53:32.758 [0296] DEBUG - BPQ: generator 2258 is in complete state
Oct 27, 2018 11:53:32.758 [0296] DEBUG - Sync: sync list 24750675, sync item 29433930 is in complete state
Oct 27, 2018 11:53:32.758 [0296] DEBUG - Sync: updating status for sync list 24750675, sync item 29433931, generator 2259
Oct 27, 2018 11:53:32.773 [0296] DEBUG - BPQ: generator 2259 is in complete state
Oct 27, 2018 11:53:32.773 [0296] DEBUG - Sync: sync list 24750675, sync item 29433931 is in complete state
Oct 27, 2018 11:53:32.773 [0296] DEBUG - Sync: updating status for sync list 24750675, sync item 29433934, generator 2260
Oct 27, 2018 11:53:32.789 [7524] DEBUG - NetworkServiceBrowser: SERVER arrived: 192.168.1.146 (Juno)
Oct 27, 2018 11:53:32.789 [7524] DEBUG - Notifying the system bundle an update to server /system/notify/serverUpdated?host=192.168.1.146
Oct 27, 2018 11:53:32.789 [7524] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/notify/serverUpdated?host=192.168.1.146
Oct 27, 2018 11:53:32.789 [7524] DEBUG - HTTP requesting GET http://127.0.0.1:49877/system/notify/serverUpdated?host=192.168.1.146
Oct 27, 2018 11:53:32.789 [0296] DEBUG - BPQ: generator 2260 is in complete state
Oct 27, 2018 11:53:32.789 [0296] DEBUG - Sync: sync list 24750675, sync item 29433934 is in complete state
Oct 27, 2018 11:53:32.789 [0296] DEBUG - Sync: updating status for sync list 25669848, sync item 30074073, generator 2296
Oct 27, 2018 11:53:32.804 [0296] DEBUG - BPQ: generator 2296 is in complete state
Oct 27, 2018 11:53:32.804 [0296] DEBUG - Sync: sync list 25669848, sync item 30074073 is in complete state
Oct 27, 2018 11:53:32.804 [0296] DEBUG - Sync: updating status for sync list 25669848, sync item 30074170, generator 2297
Oct 27, 2018 11:53:32.804 [0296] DEBUG - BPQ: generator 2297 is in complete state
Oct 27, 2018 11:53:32.804 [0296] DEBUG - Sync: sync list 25669848, sync item 30074170 is in complete state
Oct 27, 2018 11:53:32.804 [0296] DEBUG - Sync: updating status for sync list 25669848, sync item 30074197, generator 2298
Oct 27, 2018 11:53:32.820 [0296] DEBUG - BPQ: generator 2298 is in complete state
Oct 27, 2018 11:53:32.820 [0296] DEBUG - Sync: sync list 25669848, sync item 30074197 is in complete state
Oct 27, 2018 11:53:32.820 [0296] DEBUG - Sync: updating status for sync list 25669848, sync item 30074212, generator 2299
Oct 27, 2018 11:53:32.820 [0296] DEBUG - BPQ: generator 2299 is in complete state
Oct 27, 2018 11:53:32.820 [0296] DEBUG - Sync: sync list 25669848, sync item 30074212 is in complete state
Oct 27, 2018 11:53:32.820 [0296] DEBUG - Sync: updating status for sync list 25669848, sync item 30074237, generator 2300
Oct 27, 2018 11:53:32.836 [0296] DEBUG - BPQ: generator 2300 is in complete state
Oct 27, 2018 11:53:32.836 [0296] DEBUG - Sync: sync list 25669848, sync item 30074237 is in complete state
Oct 27, 2018 11:53:32.836 [0296] DEBUG - Sync: updating status for sync list 25669848, sync item 30115400, generator 2307
Oct 27, 2018 11:53:32.836 [0296] DEBUG - BPQ: generator 2307 is in complete state
Oct 27, 2018 11:53:32.836 [0296] DEBUG - Sync: sync list 25669848, sync item 30115400 is in complete state
Oct 27, 2018 11:53:32.836 [0296] DEBUG - Sync: updating status for sync list 25669848, sync item 30116959, generator 2308
Oct 27, 2018 11:53:32.867 [6264] DEBUG - Request: [127.0.0.1:49908 (Loopback)] GET /servers (11 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:32.867 [3788] DEBUG - Completed: [127.0.0.1:49908] 200 GET /servers (11 live) GZIP 2ms 489 bytes
Oct 27, 2018 11:53:32.867 [6264] DEBUG - Request: [127.0.0.1:49909 (Loopback)] GET / (11 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:32.961 [0296] DEBUG - BPQ: generator 2308 is in complete state
Oct 27, 2018 11:53:32.961 [0296] DEBUG - Sync: sync list 25669848, sync item 30116959 is in complete state
Oct 27, 2018 11:53:32.961 [0296] DEBUG - Sync: updating status for sync list 25669848, sync item 30116965, generator 2309
Oct 27, 2018 11:53:32.961 [0296] DEBUG - BPQ: generator 2309 is in complete state
Oct 27, 2018 11:53:32.961 [0296] DEBUG - Sync: sync list 25669848, sync item 30116965 is in complete state
Oct 27, 2018 11:53:32.961 [0296] DEBUG - Sync: updating status for sync list 25669848, sync item 30168043, generator 2311
Oct 27, 2018 11:53:32.976 [0296] DEBUG - BPQ: generator 2311 is in complete state
Oct 27, 2018 11:53:32.976 [0296] DEBUG - Sync: sync list 25669848, sync item 30168043 is in complete state
Oct 27, 2018 11:53:33.539 [8504] DEBUG - Collections: Found 99 collections tags in section 13.
Oct 27, 2018 11:53:33.695 [8504] DEBUG - Collections: We had 99 collections in the library already.
Oct 27, 2018 11:53:33.695 [8504] DEBUG - Collections: Synced tags in section 13 in 3454ms.
Oct 27, 2018 11:53:33.914 [3948] DEBUG - NAT: UPnP, found device <http://192.168.1.254:49153/4451712f/gatedesc0b.xml> with private address <192.168.1.146>
Oct 27, 2018 11:53:33.914 [7100] DEBUG - Request: [127.0.0.1:49912 (Loopback)] GET /system/messaging/clear_events/com.plexapp.plugins.WebTools (12 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:33.914 [7100] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/messaging/clear_events/com.plexapp.plugins.WebTools
Oct 27, 2018 11:53:33.914 [7100] DEBUG - HTTP requesting GET http://127.0.0.1:49877/system/messaging/clear_events/com.plexapp.plugins.WebTools
Oct 27, 2018 11:53:33.914 [3948] DEBUG - NAT: UPnP, usable device <http://192.168.1.254:49153/4451712f/gatedesc0b.xml> with private address <192.168.1.146>.
Oct 27, 2018 11:53:33.914 [3948] DEBUG - NAT: UPnP, public address is 86.139.150.227
Oct 27, 2018 11:53:33.914 [4044] DEBUG - PublicAddressManager: Mapping succeeded for 192.168.1.146:13407.
Oct 27, 2018 11:53:33.914 [7100] DEBUG - HTTP 200 response from GET http://127.0.0.1:49877/system/messaging/clear_events/com.plexapp.plugins.WebTools
Oct 27, 2018 11:53:33.930 [7100] DEBUG - [com.plexapp.system] HTTP reply status 200, with 0 bytes of content.
Oct 27, 2018 11:53:33.930 [3788] DEBUG - Completed: [127.0.0.1:49912] 200 GET /system/messaging/clear_events/com.plexapp.plugins.WebTools (12 live) GZIP 12ms 330 bytes
Oct 27, 2018 11:53:33.945 [3788] DEBUG - Completed: [127.0.0.1:49909] 200 GET / (12 live) GZIP 1072ms 2453 bytes
Oct 27, 2018 11:53:33.945 [3788] DEBUG - Completed: [127.0.0.1:49906] 200 GET / (12 live) GZIP 2690ms 2453 bytes
Oct 27, 2018 11:53:33.945 [3788] DEBUG - Completed: [127.0.0.1:49875] 200 GET / (12 live) GZIP 4333ms 2453 bytes
Oct 27, 2018 11:53:33.945 [7844] DEBUG - (Capabilities) Platform 'Microsoft Edge' not matched by plugin platform requirements
Oct 27, 2018 11:53:33.945 [6344] DEBUG - (Capabilities) Platform 'Chrome' not matched by plugin platform requirements
Oct 27, 2018 11:53:33.945 [6348] DEBUG - (Capabilities) Platform 'Chrome' not matched by plugin platform requirements
Oct 27, 2018 11:53:33.961 [3844] DEBUG - MyPlex: Sending Server Info to myPlex (user=email@craigtubby.co.uk, ip=, port=13407)
Oct 27, 2018 11:53:33.961 [3788] DEBUG - Completed: [192.168.1.199:57211] 200 GET / (12 live) GZIP 1297ms 2424 bytes (pipelined: 1)
Oct 27, 2018 11:53:33.961 [3844] DEBUG - HTTP requesting POST https://plex.tv/servers.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&async=1&asyncIdentifier=32bd2f9f-817f-4307-b090-24a3e0f0d919
Oct 27, 2018 11:53:33.961 [3788] DEBUG - Completed: [192.168.1.199:57226] 200 GET / (12 live) GZIP 2632ms 2424 bytes (pipelined: 1)
Oct 27, 2018 11:53:33.961 [3788] DEBUG - Completed: [127.0.0.1:49873] 200 GET / (12 live) GZIP 4345ms 2453 bytes
Oct 27, 2018 11:53:33.961 [3788] DEBUG - Completed: [192.168.1.199:57212] 200 GET / (12 live) GZIP 1299ms 2497 bytes (pipelined: 1)
Oct 27, 2018 11:53:33.977 [8600] DEBUG - Request: [127.0.0.1:49918 (Loopback)] GET / (12 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:33.992 [3788] DEBUG - Completed: [127.0.0.1:49918] 200 GET / (12 live) GZIP 9ms 2451 bytes
Oct 27, 2018 11:53:33.992 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:33.992 [4044] DEBUG - MyPlex: Last published value didn't change, we're done.
Oct 27, 2018 11:53:33.992 [6264] DEBUG - Request: [192.168.1.199:57211 (Allowed Network)] GET /updater/status (11 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:33.992 [3788] DEBUG - Completed: [192.168.1.199:57211] 200 GET /updater/status (11 live) GZIP 2ms 447 bytes (pipelined: 2)
Oct 27, 2018 11:53:34.008 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:34.008 [10176] DEBUG - Request: [192.168.1.199:57237 (Allowed Network)] GET /:/websockets/notifications (11 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.008 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:34.008 [6876] DEBUG - Request: [192.168.1.199:57226 (Allowed Network)] GET /updater/status (10 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.008 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:34.008 [6348] DEBUG - Request: [192.168.1.199:57239 (Allowed Network)] GET /:/websockets/notifications (11 live) Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.008 [3788] DEBUG - Completed: [192.168.1.199:57226] 200 GET /updater/status (11 live) GZIP 4ms 447 bytes (pipelined: 2)
Oct 27, 2018 11:53:34.008 [6348] DEBUG - WebSocket: Performing handshake from origin http://192.168.1.146:32400
Oct 27, 2018 11:53:34.008 [6348] DEBUG - Beginning read from WebSocket
Oct 27, 2018 11:53:34.023 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:34.023 [7844] DEBUG - Request: [192.168.1.199:57226 (Allowed Network)] PUT /updater/check?download=0 (11 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.023 [7844] DEBUG - AutoUpdate: requesting check endpoint: /updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d, download: NO
Oct 27, 2018 11:53:34.023 [7844] DEBUG - Downloading document https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:53:34.023 [7844] DEBUG - HTTP requesting GET https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:53:34.023 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:34.023 [6092] DEBUG - Request: [192.168.1.199:57241 (Allowed Network)] GET /activities (11 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.039 [3788] DEBUG - Completed: [192.168.1.199:57241] 200 GET /activities (11 live) GZIP 2ms 350 bytes (pipelined: 1)
Oct 27, 2018 11:53:34.039 [6344] DEBUG - Request: [192.168.1.199:57212 (Allowed Network)] OPTIONS /updater/check?download=0 (11 live) GZIP Signed-in Token ()
Oct 27, 2018 11:53:34.039 [3788] DEBUG - Completed: [192.168.1.199:57212] 200 OPTIONS /updater/check?download=0 (11 live) GZIP 1ms 349 bytes (pipelined: 2)
Oct 27, 2018 11:53:34.055 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:34.055 [7100] DEBUG - Request: [192.168.1.199:57242 (Allowed Network)] PUT /updater/check?download=0 (11 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.086 [8600] DEBUG - Request: [127.0.0.1:49920 (Loopback)] GET /library/sections (12 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.086 [6264] DEBUG - Request: [127.0.0.1:49921 (Loopback)] GET /library/sections (12 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.102 [10176] DEBUG - WebSocket: Performing handshake from origin http://juno:32400
Oct 27, 2018 11:53:34.102 [10176] DEBUG - Beginning read from WebSocket
Oct 27, 2018 11:53:34.133 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:34.133 [6876] DEBUG - Request: [192.168.1.199:57243 (Allowed Network)] GET /activities (13 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.133 [3788] DEBUG - Completed: [192.168.1.199:57243] 200 GET /activities (13 live) GZIP 2ms 423 bytes (pipelined: 1)
Oct 27, 2018 11:53:34.148 [6348] DEBUG - Request: [127.0.0.1:49922 (Loopback)] GET /:/plugins/com.plexapp.system/resourceHashes (14 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.148 [6348] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /:/plugins/com.plexapp.system/resourceHashes
Oct 27, 2018 11:53:34.148 [6348] DEBUG - HTTP requesting GET http://127.0.0.1:49877/:/plugins/com.plexapp.system/resourceHashes
Oct 27, 2018 11:53:34.164 [3844] DEBUG - HTTP 201 response from POST https://plex.tv/servers.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&async=1&asyncIdentifier=32bd2f9f-817f-4307-b090-24a3e0f0d919
Oct 27, 2018 11:53:34.164 [3844] DEBUG - MyPlex: Published Mapping State response was 201
Oct 27, 2018 11:53:34.164 [3844] DEBUG - MyPlex: Got response for 7e0d395b9e4a10d7fb39e3151eecdf3274164576 ~ registered :0
Oct 27, 2018 11:53:34.164 [3776] WARN - PubSub: Received notifyConnectivity event with incorrect async identifier (d78af6b0-3169-483d-b6f7-50e96b0ef8c0, expected 32bd2f9f-817f-4307-b090-24a3e0f0d919)
Oct 27, 2018 11:53:34.164 [3776] DEBUG - EventSource: Got event [data] '<Message host="139.162.226.171" port="443" command="startRelay"/>'
Oct 27, 2018 11:53:34.164 [3776] DEBUG - HTTP requesting GET https://downloads.plex.tv/relay/relay_v1.pub
Oct 27, 2018 11:53:34.180 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:34.180 [6092] DEBUG - Request: [192.168.1.199:57241 (Allowed Network)] PUT /myplex/refreshReachability (14 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.180 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:34.180 [6344] DEBUG - Request: [192.168.1.199:57243 (Allowed Network)] PUT /myplex/refreshReachability (13 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.195 [7844] DEBUG - HTTP 200 response from GET https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:53:34.195 [7844] INFO - AutoUpdate: no updates available
Oct 27, 2018 11:53:34.195 [7100] DEBUG - AutoUpdate: requesting check endpoint: /updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d, download: NO
Oct 27, 2018 11:53:34.195 [7100] DEBUG - Downloading document https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:53:34.195 [3788] DEBUG - Completed: [192.168.1.199:57226] 200 PUT /updater/check?download=0 (13 live) GZIP 174ms 268 bytes (pipelined: 3)
Oct 27, 2018 11:53:34.195 [7100] DEBUG - HTTP requesting GET https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:53:34.195 [3948] DEBUG - MyPlex: Sending Server Info to myPlex (user=email@craigtubby.co.uk, ip=, port=13407)
Oct 27, 2018 11:53:34.195 [3948] DEBUG - HTTP requesting POST https://plex.tv/servers.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&async=1&asyncIdentifier=edef97f6-3b45-4a15-afd1-7e48bbdfe693
Oct 27, 2018 11:53:34.195 [3844] DEBUG - MyPlex: Last published value didn't change, we're done.
Oct 27, 2018 11:53:34.273 [3776] DEBUG - HTTP 200 response from GET https://downloads.plex.tv/relay/relay_v1.pub
Oct 27, 2018 11:53:34.273 [3776] DEBUG - Relay: refreshed host key from https://downloads.plex.tv/relay/relay_v1.pub
Oct 27, 2018 11:53:34.273 [3776] DEBUG - Relay: starting relay.
Oct 27, 2018 11:53:34.289 [8504] WARN - Held transaction for too long (..\Library\MetadataCollection.cpp:236): 0.578125 seconds
Oct 27, 2018 11:53:34.305 [10176] DEBUG - Request: [34.245.172.51:35718 (WAN)] GET /identity (14 live) TLS Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.305 [3788] DEBUG - Completed: [34.245.172.51:35718] 200 GET /identity (14 live) TLS 1ms 386 bytes
Oct 27, 2018 11:53:34.305 [3776] DEBUG - Job running: PLEXTOKEN='xxxxxxxxxxxxxxxxxxxx' C:\Program Files (x86)\Plex\Plex Media Server\PlexRelay.exe -p 443 -N -R 0:localhost:32401 -o StrictHostKeyChecking=yes -o "UserKnownHostsFile=C:\Users\craig\AppData\Local\Plex Media Server\Cache\relayHostKey.txt" -o NoneSwitch=yes -o NoneEnabled=yes -o LogLevel=VERBOSE -o PreferredAuthentications=password -o PubkeyAuthentication=no -l tubs74 139.162.226.171 
Oct 27, 2018 11:53:34.336 [7100] DEBUG - HTTP 200 response from GET https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:53:34.336 [7100] INFO - AutoUpdate: no updates available
Oct 27, 2018 11:53:34.336 [3788] DEBUG - Completed: [192.168.1.199:57242] 200 PUT /updater/check?download=0 (14 live) GZIP 286ms 268 bytes (pipelined: 1)
Oct 27, 2018 11:53:34.367 [8504] DEBUG - Collections: Refreshed attributes for 99 collections in section 13 in 670ms.
Oct 27, 2018 11:53:34.367 [3788] DEBUG - Completed: [127.0.0.1:49920] 200 GET /library/sections (14 live) GZIP 281ms 1215 bytes
Oct 27, 2018 11:53:34.367 [3788] DEBUG - Completed: [127.0.0.1:49921] 200 GET /library/sections (14 live) GZIP 281ms 1215 bytes
Oct 27, 2018 11:53:34.398 [3948] DEBUG - HTTP 201 response from POST https://plex.tv/servers.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&async=1&asyncIdentifier=edef97f6-3b45-4a15-afd1-7e48bbdfe693
Oct 27, 2018 11:53:34.398 [3948] DEBUG - MyPlex: Published Mapping State response was 201
Oct 27, 2018 11:53:34.398 [3948] DEBUG - MyPlex: Got response for 7e0d395b9e4a10d7fb39e3151eecdf3274164576 ~ registered :0
Oct 27, 2018 11:53:34.398 [6092] DEBUG - MyPlex: Requesting reachability check.
Oct 27, 2018 11:53:34.414 [6092] DEBUG - HTTP requesting PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=7be8cebc-d142-4b44-9fcc-33df21bec0fc
Oct 27, 2018 11:53:34.414 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:34.414 [7844] DEBUG - Request: [192.168.1.199:57242 (Allowed Network)] PUT /myplex/refreshReachability (14 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.414 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:34.414 [7100] DEBUG - Request: [192.168.1.199:57226 (Allowed Network)] PUT /myplex/refreshReachability (14 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.430 [3948] DEBUG - MyPlex: Last published value didn't change, we're done.
Oct 27, 2018 11:53:34.461 [3776] DEBUG - Jobs: Starting child process with pid 6460
Oct 27, 2018 11:53:34.461 [3788] DEBUG - EventSource: Got event [data] '<Message host="139.162.226.171" port="443" command="startRelay"/>'
Oct 27, 2018 11:53:34.461 [3788] DEBUG - Relay: already have an active relay connection for this server
Oct 27, 2018 11:53:34.461 [3788] DEBUG - EventSource: Got event [data] '<Message host="178.79.186.187" port="443" command="startRelay"/>'
Oct 27, 2018 11:53:34.461 [3788] DEBUG - Relay: reused an existing key for https://downloads.plex.tv/relay/relay_v1.pub
Oct 27, 2018 11:53:34.461 [3788] DEBUG - Relay: starting relay.
Oct 27, 2018 11:53:34.461 [3788] DEBUG - Job running: PLEXTOKEN='xxxxxxxxxxxxxxxxxxxx' C:\Program Files (x86)\Plex\Plex Media Server\PlexRelay.exe -p 443 -N -R 0:localhost:32401 -o StrictHostKeyChecking=yes -o "UserKnownHostsFile=C:\Users\craig\AppData\Local\Plex Media Server\Cache\relayHostKey.txt" -o NoneSwitch=yes -o NoneEnabled=yes -o LogLevel=VERBOSE -o PreferredAuthentications=password -o PubkeyAuthentication=no -l tubs74 178.79.186.187 
Oct 27, 2018 11:53:34.461 [8504] DEBUG - Collection: Refreshed visibility in section 13 in 98ms.
Oct 27, 2018 11:53:34.461 [8504] DEBUG - Collections: Found 51 collections tags in section 14.
Oct 27, 2018 11:53:34.477 [6348] DEBUG - HTTP 200 response from GET http://127.0.0.1:49877/:/plugins/com.plexapp.system/resourceHashes
Oct 27, 2018 11:53:34.477 [6348] DEBUG - [com.plexapp.system] HTTP reply status 200, with 13276 bytes of content.
Oct 27, 2018 11:53:34.477 [3776] DEBUG - Completed: [127.0.0.1:49922] 200 GET /:/plugins/com.plexapp.system/resourceHashes (15 live) GZIP 330ms 3498 bytes
Oct 27, 2018 11:53:34.477 [6876] DEBUG - Request: [127.0.0.1:49929 (Loopback)] GET /channels/all (17 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.477 [3776] DEBUG - Completed: [127.0.0.1:49929] 200 GET /channels/all (17 live) GZIP 3ms 838 bytes
Oct 27, 2018 11:53:34.477 [6264] DEBUG - Request: [127.0.0.1:49930 (Loopback)] GET /channels/all (16 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.492 [3776] DEBUG - Completed: [127.0.0.1:49930] 200 GET /channels/all (16 live) GZIP 2ms 838 bytes
Oct 27, 2018 11:53:34.492 [8504] DEBUG - Collections: We had 52 collections in the library already.
Oct 27, 2018 11:53:34.492 [8504] DEBUG - Collections: Synced tags in section 14 in 28ms.
Oct 27, 2018 11:53:34.508 [10176] DEBUG - Request: [34.247.38.195:45890 (WAN)] GET /identity (15 live) TLS Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.508 [3776] DEBUG - Completed: [34.247.38.195:45890] 200 GET /identity (15 live) TLS 1ms 386 bytes
Oct 27, 2018 11:53:34.523 [7524] DEBUG - HTTP 200 response from GET http://127.0.0.1:49877/system/notify/serverUpdated?host=192.168.1.146
Oct 27, 2018 11:53:34.523 [7524] DEBUG - [com.plexapp.system] HTTP reply status 200, with 0 bytes of content.
Oct 27, 2018 11:53:34.523 [8600] DEBUG - Request: [127.0.0.1:49931 (Loopback)] GET /library/sections (16 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.523 [3776] DEBUG - Completed: [127.0.0.1:49931] 200 GET /library/sections (16 live) GZIP 3ms 1215 bytes
Oct 27, 2018 11:53:34.539 [6348] DEBUG - Request: [127.0.0.1:49932 (Loopback)] GET /channels/all (16 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.539 [3776] DEBUG - Completed: [127.0.0.1:49932] 200 GET /channels/all (16 live) GZIP 2ms 838 bytes
Oct 27, 2018 11:53:34.539 [3788] DEBUG - Jobs: Starting child process with pid 6708
Oct 27, 2018 11:53:34.539 [3776] DEBUG - EventSource: Got event [data] '<Message address="86.139.150.227" port="13407" asyncIdentifier="32bd2f9f-817f-4307-b090-24a3e0f0d919" connectivity="1" command="notifyConnectivity"/>'
Oct 27, 2018 11:53:34.555 [6876] DEBUG - Request: [127.0.0.1:49933 (Loopback)] GET /:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_ (17 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.555 [6876] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_
Oct 27, 2018 11:53:34.555 [6876] DEBUG - HTTP requesting GET http://127.0.0.1:49877/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_
Oct 27, 2018 11:53:34.555 [6264] DEBUG - Request: [127.0.0.1:49934 (Loopback)] GET / (16 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.570 [3788] DEBUG - Completed: [127.0.0.1:49934] 200 GET / (16 live) GZIP 4ms 2451 bytes
Oct 27, 2018 11:53:34.570 [6092] DEBUG - HTTP 200 response from PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=7be8cebc-d142-4b44-9fcc-33df21bec0fc
Oct 27, 2018 11:53:34.570 [6344] DEBUG - MyPlex: Requesting reachability check.
Oct 27, 2018 11:53:34.570 [3788] DEBUG - Completed: [192.168.1.199:57241] 200 PUT /myplex/refreshReachability (16 live) GZIP 391ms 268 bytes (pipelined: 2)
Oct 27, 2018 11:53:34.570 [6344] DEBUG - HTTP requesting PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=3ee6fdff-d601-4da6-a2f3-72341534e70b
Oct 27, 2018 11:53:34.648 [8504] WARN - Held transaction for too long (..\Library\MetadataCollection.cpp:236): 0.140625 seconds
Oct 27, 2018 11:53:34.664 [6876] DEBUG - HTTP 200 response from GET http://127.0.0.1:49877/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_
Oct 27, 2018 11:53:34.664 [6876] DEBUG - [com.plexapp.system] HTTP reply status 200, with 62566 bytes of content.
Oct 27, 2018 11:53:34.664 [3788] DEBUG - Completed: [127.0.0.1:49933] 200 GET /:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_ (17 live) GZIP 106ms 20198 bytes
Oct 27, 2018 11:53:34.680 [10176] DEBUG - Request: [54.171.49.143:55888 (WAN)] GET /identity (16 live) TLS Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.680 [3788] DEBUG - Completed: [54.171.49.143:55888] 200 GET /identity (16 live) TLS 2ms 386 bytes
Oct 27, 2018 11:53:34.711 [6344] DEBUG - HTTP 200 response from PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=3ee6fdff-d601-4da6-a2f3-72341534e70b
Oct 27, 2018 11:53:34.711 [7844] DEBUG - MyPlex: Requesting reachability check.
Oct 27, 2018 11:53:34.711 [3788] DEBUG - Completed: [192.168.1.199:57243] 200 PUT /myplex/refreshReachability (16 live) GZIP 532ms 268 bytes (pipelined: 2)
Oct 27, 2018 11:53:34.711 [7844] DEBUG - HTTP requesting PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=93967183-a68b-4c76-96f5-4fb1cfe0881b
Oct 27, 2018 11:53:34.727 [8504] DEBUG - Collections: Refreshed attributes for 51 collections in section 14 in 237ms.
Oct 27, 2018 11:53:34.773 [8504] DEBUG - Collection: Refreshed visibility in section 14 in 42ms.
Oct 27, 2018 11:53:34.805 [8504] DEBUG - Collections: Found 0 collections tags in section 17.
Oct 27, 2018 11:53:34.820 [8600] DEBUG - Request: [34.248.59.52:38914 (WAN)] GET /identity (16 live) TLS Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.820 [3788] DEBUG - Completed: [34.248.59.52:38914] 200 GET /identity (16 live) TLS 2ms 386 bytes
Oct 27, 2018 11:53:34.836 [8504] DEBUG - Collections: We had 0 collections in the library already.
Oct 27, 2018 11:53:34.836 [8504] DEBUG - Collections: Synced tags in section 17 in 66ms.
Oct 27, 2018 11:53:34.836 [8504] DEBUG - Collections: Refreshed attributes for 0 collections in section 17 in 1ms.
Oct 27, 2018 11:53:34.836 [8504] DEBUG - Collection: Refreshed visibility in section 17 in 2ms.
Oct 27, 2018 11:53:34.836 [8504] DEBUG - Running database fix-ups completed in 4.0 seconds.
Oct 27, 2018 11:53:34.836 [8504] DEBUG - HTTP requesting GET https://plex.tv/api/v2/release_channels?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:34.867 [3920] DEBUG - HTTP requesting GET https://plex.tv/services/pubsub/servers
Oct 27, 2018 11:53:34.883 [7844] DEBUG - HTTP 200 response from PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=93967183-a68b-4c76-96f5-4fb1cfe0881b
Oct 27, 2018 11:53:34.883 [7100] DEBUG - MyPlex: Requesting reachability check.
Oct 27, 2018 11:53:34.883 [3788] DEBUG - Completed: [192.168.1.199:57242] 200 PUT /myplex/refreshReachability (16 live) GZIP 460ms 268 bytes (pipelined: 2)
Oct 27, 2018 11:53:34.883 [7100] DEBUG - HTTP requesting PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=3147775b-cdcb-4e85-885d-21005a2715f9
Oct 27, 2018 11:53:34.992 [6348] DEBUG - Request: [34.248.59.52:53890 (WAN)] GET /identity (16 live) TLS Signed-in Token (tubs74)
Oct 27, 2018 11:53:34.992 [3788] DEBUG - Completed: [34.248.59.52:53890] 200 GET /identity (16 live) TLS 2ms 386 bytes
Oct 27, 2018 11:53:34.992 [8504] DEBUG - HTTP 200 response from GET https://plex.tv/api/v2/release_channels?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:35.008 [3844] DEBUG - DVR: Starting up.
Oct 27, 2018 11:53:35.008 [8504] DEBUG - PublicAddressManager: Obtaining public address and mapping port.
Oct 27, 2018 11:53:35.008 [3948] DEBUG - PublicAddressManager: Obtaining public IP.
Oct 27, 2018 11:53:35.008 [0736] DEBUG - NAT: UPnP, attempting port mapping.
Oct 27, 2018 11:53:35.008 [3388] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:35.008 [3948] DEBUG - HTTP requesting GET http://plex.tv/pms/:/ip
Oct 27, 2018 11:53:35.023 [3920] DEBUG - HTTP 200 response from GET https://plex.tv/services/pubsub/servers
Oct 27, 2018 11:53:35.055 [3948] DEBUG - HTTP 200 response from GET http://plex.tv/pms/:/ip
Oct 27, 2018 11:53:35.055 [7100] DEBUG - HTTP 200 response from PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=3147775b-cdcb-4e85-885d-21005a2715f9
Oct 27, 2018 11:53:35.055 [3948] DEBUG - PublicAddressManager: Got public IP from http://plex.tv: 86.139.150.227
Oct 27, 2018 11:53:35.055 [3776] WARN - PubSub: Received notifyConnectivity event with incorrect async identifier (32bd2f9f-817f-4307-b090-24a3e0f0d919, expected 3147775b-cdcb-4e85-885d-21005a2715f9)
Oct 27, 2018 11:53:35.055 [3776] DEBUG - Completed: [192.168.1.199:57226] 200 PUT /myplex/refreshReachability (16 live) GZIP 640ms 268 bytes (pipelined: 4)
Oct 27, 2018 11:53:35.055 [3776] DEBUG - EventSource: Got event [data] '<Message address="86.139.150.227" port="13407" asyncIdentifier="edef97f6-3b45-4a15-afd1-7e48bbdfe693" connectivity="1" command="notifyConnectivity"/>'
Oct 27, 2018 11:53:35.055 [3776] WARN - PubSub: Received notifyConnectivity event with incorrect async identifier (edef97f6-3b45-4a15-afd1-7e48bbdfe693, expected 3147775b-cdcb-4e85-885d-21005a2715f9)
Oct 27, 2018 11:53:35.055 [3776] DEBUG - EventSource: Got event [data] '<Message address="86.139.150.227" port="13407" asyncIdentifier="7be8cebc-d142-4b44-9fcc-33df21bec0fc" connectivity="1" command="notifyConnectivity"/>'
Oct 27, 2018 11:53:35.055 [3776] WARN - PubSub: Received notifyConnectivity event with incorrect async identifier (7be8cebc-d142-4b44-9fcc-33df21bec0fc, expected 3147775b-cdcb-4e85-885d-21005a2715f9)
Oct 27, 2018 11:53:35.055 [3776] DEBUG - EventSource: Got event [data] '<Message address="86.139.150.227" port="13407" asyncIdentifier="3ee6fdff-d601-4da6-a2f3-72341534e70b" connectivity="1" command="notifyConnectivity"/>'
Oct 27, 2018 11:53:35.055 [3776] WARN - PubSub: Received notifyConnectivity event with incorrect async identifier (3ee6fdff-d601-4da6-a2f3-72341534e70b, expected 3147775b-cdcb-4e85-885d-21005a2715f9)
Oct 27, 2018 11:53:35.086 [3776] DEBUG - EventSource: Got event [data] '<Message address="86.139.150.227" port="13407" asyncIdentifier="93967183-a68b-4c76-96f5-4fb1cfe0881b" connectivity="1" command="notifyConnectivity"/>'
Oct 27, 2018 11:53:35.086 [3776] WARN - PubSub: Received notifyConnectivity event with incorrect async identifier (93967183-a68b-4c76-96f5-4fb1cfe0881b, expected 3147775b-cdcb-4e85-885d-21005a2715f9)
Oct 27, 2018 11:53:35.117 [3844] DEBUG - Activity: registered new activity c157d43b-ddf7-44f4-9ec0-7709ab1ce257 - Processing subscriptions
Oct 27, 2018 11:53:35.180 [3388] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:53:35.305 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:35.305 [6264] DEBUG - Request: [192.168.1.199:57226 (Allowed Network)] GET /:/prefs (16 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:35.305 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:35.305 [6092] DEBUG - Request: [192.168.1.199:57241 (Allowed Network)] GET /accounts/1 (17 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:35.305 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:35.305 [6876] DEBUG - Request: [192.168.1.199:57248 (Allowed Network)] GET /myplex/account (17 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:35.305 [3776] DEBUG - Completed: [192.168.1.199:57241] 200 GET /accounts/1 (17 live) GZIP 4ms 510 bytes (pipelined: 3)
Oct 27, 2018 11:53:35.320 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:35.320 [6344] DEBUG - Request: [192.168.1.199:57249 (Allowed Network)] GET /system/:/prefs (17 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:35.320 [6344] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/:/prefs
Oct 27, 2018 11:53:35.320 [6344] DEBUG - HTTP requesting GET http://127.0.0.1:49877/system/:/prefs
Oct 27, 2018 11:53:35.320 [3776] DEBUG - Completed: [192.168.1.199:57248] 200 GET /myplex/account (17 live) GZIP 5ms 1684 bytes (pipelined: 1)
Oct 27, 2018 11:53:35.383 [3788] DEBUG - Completed: [192.168.1.199:57226] 200 GET /:/prefs (17 live) GZIP 81ms 7465 bytes (pipelined: 5)
Oct 27, 2018 11:53:35.523 [7844] DEBUG - Request: [52.49.250.227:49840 (WAN)] GET /identity (17 live) TLS Signed-in Token (tubs74)
Oct 27, 2018 11:53:35.523 [3788] DEBUG - Completed: [52.49.250.227:49840] 200 GET /identity (17 live) TLS 3ms 386 bytes
Oct 27, 2018 11:53:35.586 [6344] DEBUG - HTTP 304 response from GET http://127.0.0.1:49877/system/:/prefs
Oct 27, 2018 11:53:35.602 [6344] DEBUG - [com.plexapp.system] HTTP reply status 304, with 0 bytes of content.
Oct 27, 2018 11:53:35.602 [3776] DEBUG - Completed: [192.168.1.199:57249] 304 GET /system/:/prefs (17 live) GZIP 281ms 324 bytes (pipelined: 1)
Oct 27, 2018 11:53:35.758 [3920] DEBUG - PubSubManager: Time to connect to 139.162.245.220 was 36 ms.
Oct 27, 2018 11:53:35.758 [3920] DEBUG - PubSubManager: Time to connect to 139.162.227.137 was 47 ms.
Oct 27, 2018 11:53:35.758 [3920] DEBUG - PubSubManager: Time to connect to 82.94.168.52 was 48 ms.
Oct 27, 2018 11:53:35.758 [3920] DEBUG - PubSubManager: Time to connect to 139.162.164.202 was 60 ms.
Oct 27, 2018 11:53:35.758 [3920] DEBUG - PubSubManager: Time to connect to 50.116.59.4 was 180 ms.
Oct 27, 2018 11:53:35.758 [3920] DEBUG - PubSubManager: Time to connect to 45.79.211.86 was 214 ms.
Oct 27, 2018 11:53:35.758 [3920] DEBUG - PubSubManager: Time to connect to 66.228.52.149 was 249 ms.
Oct 27, 2018 11:53:35.758 [3920] DEBUG - PubSubManager: Time to connect to 184.105.148.102 was 305 ms.
Oct 27, 2018 11:53:35.758 [3920] DEBUG - PubSubManager: Time to connect to 172.104.173.210 was 386 ms.
Oct 27, 2018 11:53:35.758 [3920] DEBUG - PubSubManager: Time to connect to 139.162.117.249 was 490 ms.
Oct 27, 2018 11:53:35.758 [3920] DEBUG - PubSubManager: Updating best ping time for 139.162.227.137 to 47 ms.
Oct 27, 2018 11:53:35.773 [3788] DEBUG - EventSource: Got event [data] '<Message address="86.139.150.227" port="13407" asyncIdentifier="3147775b-cdcb-4e85-885d-21005a2715f9" connectivity="1" command="notifyConnectivity"/>'
Oct 27, 2018 11:53:35.773 [3788] DEBUG - PubSub: Got notified of reachability: 1 for 86.139.150.227:13407
Oct 27, 2018 11:53:35.789 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:35.789 [10176] DEBUG - Request: [192.168.1.199:57249 (Allowed Network)] GET /myplex/account (16 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:35.789 [3788] DEBUG - Completed: [192.168.1.199:57249] 200 GET /myplex/account (16 live) GZIP 2ms 1684 bytes (pipelined: 2)
Oct 27, 2018 11:53:35.805 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:35.805 [8600] DEBUG - Request: [192.168.1.199:57242 (Allowed Network)] GET /:/prefs (15 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:35.805 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:35.805 [6092] DEBUG - Request: [192.168.1.199:57243 (Allowed Network)] GET /accounts/1 (15 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:35.805 [3788] DEBUG - Completed: [192.168.1.199:57243] 200 GET /accounts/1 (15 live) GZIP 2ms 583 bytes (pipelined: 3)
Oct 27, 2018 11:53:35.805 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:35.805 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:35.805 [6348] DEBUG - Request: [192.168.1.199:57251 (Allowed Network)] GET /system/:/prefs (16 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:35.805 [7100] DEBUG - Request: [192.168.1.199:57250 (Allowed Network)] GET /myplex/account (16 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:35.805 [6348] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/:/prefs
Oct 27, 2018 11:53:35.820 [6348] DEBUG - HTTP requesting GET http://127.0.0.1:49877/system/:/prefs
Oct 27, 2018 11:53:35.820 [3776] DEBUG - Completed: [192.168.1.199:57250] 200 GET /myplex/account (16 live) GZIP 3ms 1757 bytes (pipelined: 1)
Oct 27, 2018 11:53:35.820 [6348] DEBUG - HTTP 304 response from GET http://127.0.0.1:49877/system/:/prefs
Oct 27, 2018 11:53:35.820 [6348] DEBUG - [com.plexapp.system] HTTP reply status 304, with 0 bytes of content.
Oct 27, 2018 11:53:35.820 [3776] DEBUG - Completed: [192.168.1.199:57251] 304 GET /system/:/prefs (16 live) GZIP 14ms 397 bytes (pipelined: 1)
Oct 27, 2018 11:53:35.836 [3776] DEBUG - Completed: [192.168.1.199:57242] 200 GET /:/prefs (16 live) GZIP 31ms 7538 bytes (pipelined: 3)
Oct 27, 2018 11:53:35.961 [6876] DEBUG - [PlexRelay] Authenticated to 178.79.186.187 ([178.79.186.187]:443).
Oct 27, 2018 11:53:35.977 [6264] DEBUG - [PlexRelay] Authenticated to 139.162.226.171 ([139.162.226.171]:443).
Oct 27, 2018 11:53:36.102 [10176] ERROR - [PlexRelay] kex protocol error: type 7 seq 11
Oct 27, 2018 11:53:36.117 [7100] ERROR - [PlexRelay] kex protocol error: type 7 seq 11
Oct 27, 2018 11:53:36.195 [6092] INFO - [PlexRelay] Allocated port 22623 for remote forward to localhost:32401
Oct 27, 2018 11:53:36.276 [8600] INFO - [PlexRelay] Allocated port 22775 for remote forward to localhost:32401
Oct 27, 2018 11:53:36.308 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:36.308 [6344] DEBUG - Request: [192.168.1.199:57249 (Allowed Network)] PUT /myplex/refreshReachability (25 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:36.308 [6344] DEBUG - MyPlex: Requesting reachability check.
Oct 27, 2018 11:53:36.323 [6344] DEBUG - HTTP requesting PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=2cedd66c-6c9d-4e4d-ac82-3f30ac7de504
Oct 27, 2018 11:53:36.355 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:36.355 [7844] DEBUG - Request: [192.168.1.199:57226 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:36.355 [7844] DEBUG - [CompanionProxy] registered new player: nyn5ygo80ujfy1rvk7b27znn (192.168.1.199)
Oct 27, 2018 11:53:36.355 [7844] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:53:36.464 [6344] DEBUG - HTTP 200 response from PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=2cedd66c-6c9d-4e4d-ac82-3f30ac7de504
Oct 27, 2018 11:53:36.464 [3776] DEBUG - Completed: [192.168.1.199:57249] 200 PUT /myplex/refreshReachability (24 live) GZIP 154ms 268 bytes (pipelined: 3)
Oct 27, 2018 11:53:36.558 [6348] DEBUG - Request: [54.171.49.143:38678 (WAN)] GET /identity (25 live) TLS Signed-in Token (tubs74)
Oct 27, 2018 11:53:36.558 [3788] DEBUG - Completed: [54.171.49.143:38678] 200 GET /identity (25 live) TLS 2ms 386 bytes
Oct 27, 2018 11:53:36.808 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:36.808 [6264] DEBUG - Request: [192.168.1.199:57242 (Allowed Network)] PUT /myplex/refreshReachability (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:36.808 [6264] DEBUG - MyPlex: Requesting reachability check.
Oct 27, 2018 11:53:36.808 [6264] DEBUG - HTTP requesting PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=bcabc093-ae11-47aa-a5a7-a5dc7e9b7378
Oct 27, 2018 11:53:36.823 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:36.823 [7100] DEBUG - Request: [192.168.1.199:57251 (Allowed Network)] GET /updater/status (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:36.823 [3788] DEBUG - Completed: [192.168.1.199:57251] 200 GET /updater/status (23 live) GZIP 2ms 528 bytes (pipelined: 2)
Oct 27, 2018 11:53:36.886 [3788] DEBUG - EventSource: Got event [data] '<Message address="86.139.150.227" port="13407" asyncIdentifier="2cedd66c-6c9d-4e4d-ac82-3f30ac7de504" connectivity="1" command="notifyConnectivity"/>'
Oct 27, 2018 11:53:36.948 [6264] DEBUG - HTTP 200 response from PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=bcabc093-ae11-47aa-a5a7-a5dc7e9b7378
Oct 27, 2018 11:53:36.948 [3788] WARN - PubSub: Received notifyConnectivity event with incorrect async identifier (2cedd66c-6c9d-4e4d-ac82-3f30ac7de504, expected bcabc093-ae11-47aa-a5a7-a5dc7e9b7378)
Oct 27, 2018 11:53:36.948 [3776] DEBUG - Completed: [192.168.1.199:57242] 200 PUT /myplex/refreshReachability (23 live) GZIP 134ms 268 bytes (pipelined: 4)
Oct 27, 2018 11:53:37.089 [6092] DEBUG - Request: [54.171.49.143:44554 (WAN)] GET /identity (23 live) TLS Signed-in Token (tubs74)
Oct 27, 2018 11:53:37.105 [3788] DEBUG - Completed: [54.171.49.143:44554] 200 GET /identity (23 live) TLS 2ms 386 bytes
Oct 27, 2018 11:53:37.198 [3788] DEBUG - EventSource: Got event [data] '<Message address="86.139.150.227" port="13407" asyncIdentifier="bcabc093-ae11-47aa-a5a7-a5dc7e9b7378" connectivity="1" command="notifyConnectivity"/>'
Oct 27, 2018 11:53:37.198 [3788] DEBUG - PubSub: Got notified of reachability: 1 for 86.139.150.227:13407
Oct 27, 2018 11:53:37.214 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:37.214 [6876] DEBUG - Request: [192.168.1.199:57249 (Allowed Network)] GET /myplex/account (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:37.214 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:37.214 [3788] DEBUG - Completed: [192.168.1.199:57249] 200 GET /myplex/account (21 live) GZIP 3ms 1684 bytes (pipelined: 4)
Oct 27, 2018 11:53:37.214 [10176] DEBUG - Request: [192.168.1.199:57242 (Allowed Network)] GET /myplex/account (21 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:37.214 [3788] DEBUG - Completed: [192.168.1.199:57242] 200 GET /myplex/account (21 live) GZIP 3ms 1757 bytes (pipelined: 5)
Oct 27, 2018 11:53:37.792 [7524] DEBUG - NetworkServiceBrowser: PLAYER arrived: 192.168.1.146
Oct 27, 2018 11:53:37.792 [7524] DEBUG - NetworkServiceBrowser: Parsing SSDP schema for http://192.168.1.254:1990/5b06f496-755d-4e16-92f1-ad4f06187872/WFADevice.xml
Oct 27, 2018 11:53:37.792 [7524] DEBUG - HTTP requesting GET http://192.168.1.254:1990/5b06f496-755d-4e16-92f1-ad4f06187872/WFADevice.xml
Oct 27, 2018 11:53:37.792 [7524] DEBUG - HTTP 200 response from GET http://192.168.1.254:1990/5b06f496-755d-4e16-92f1-ad4f06187872/WFADevice.xml
Oct 27, 2018 11:53:37.792 [7524] DEBUG - NetworkServiceBrowser: found 1 SSDP devices via http://192.168.1.254:1990/5b06f496-755d-4e16-92f1-ad4f06187872/WFADevice.xml
Oct 27, 2018 11:53:37.792 [7524] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.1.254 (WFADevice)
Oct 27, 2018 11:53:37.792 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:37.792 [6348] DEBUG - Request: [192.168.1.199:57242 (Allowed Network)] PUT /updater/check?download=0 (21 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:37.792 [6348] DEBUG - AutoUpdate: requesting check endpoint: /updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d, download: NO
Oct 27, 2018 11:53:37.792 [6348] DEBUG - Downloading document https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:53:37.792 [6348] DEBUG - HTTP requesting GET https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:53:37.933 [6348] DEBUG - HTTP 200 response from GET https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:53:37.933 [6348] INFO - AutoUpdate: no updates available
Oct 27, 2018 11:53:37.933 [3788] DEBUG - Completed: [192.168.1.199:57242] 200 PUT /updater/check?download=0 (21 live) GZIP 133ms 268 bytes (pipelined: 6)
Oct 27, 2018 11:53:38.011 [0736] DEBUG - NAT: UPnP, found device <http://192.168.1.254:49153/4451712f/gatedesc0b.xml> with private address <192.168.1.146>
Oct 27, 2018 11:53:38.011 [0736] DEBUG - NAT: UPnP, usable device <http://192.168.1.254:49153/4451712f/gatedesc0b.xml> with private address <192.168.1.146>.
Oct 27, 2018 11:53:38.073 [3948] DEBUG - NAT: UPnP, found device <http://192.168.1.254:49153/4451712f/gatedesc0b.xml> with private address <192.168.1.146>
Oct 27, 2018 11:53:38.120 [7524] DEBUG - NetworkServiceBrowser: Parsing SSDP schema for http://192.168.1.118:1503/
Oct 27, 2018 11:53:38.120 [7524] DEBUG - HTTP requesting GET http://192.168.1.118:1503/
Oct 27, 2018 11:53:38.198 [7524] DEBUG - HTTP 200 response from GET http://192.168.1.118:1503/
Oct 27, 2018 11:53:38.198 [7524] DEBUG - NetworkServiceBrowser: found 1 SSDP devices via http://192.168.1.118:1503/
Oct 27, 2018 11:53:38.198 [7524] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.1.118 ([TV][LG]Main_TV)
Oct 27, 2018 11:53:38.198 [7524] DEBUG - NetworkServiceBrowser: Parsing SSDP schema for http://192.168.1.83:80/upnpd/description.xml
Oct 27, 2018 11:53:38.198 [7524] DEBUG - HTTP requesting GET http://192.168.1.83:80/upnpd/description.xml
Oct 27, 2018 11:53:38.261 [0736] DEBUG - NAT: UPnP, mapped port 13407 to 192.168.1.146:32400.
Oct 27, 2018 11:53:38.277 [3948] DEBUG - NAT: UPnP, usable device <http://192.168.1.254:49153/4451712f/gatedesc0b.xml> with private address <192.168.1.146>.
Oct 27, 2018 11:53:38.277 [3948] DEBUG - NAT: UPnP, public address is 86.139.150.227
Oct 27, 2018 11:53:38.292 [0736] DEBUG - PublicAddressManager: Mapping succeeded for 192.168.1.146:13407.
Oct 27, 2018 11:53:38.308 [7524] DEBUG - HTTP 200 response from GET http://192.168.1.83:80/upnpd/description.xml
Oct 27, 2018 11:53:38.308 [7524] DEBUG - NetworkServiceBrowser: found 1 SSDP devices via http://192.168.1.83:80/upnpd/description.xml
Oct 27, 2018 11:53:38.308 [7524] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.1.83 (NC328SW-1080P (192.168.1.83) (7c:dd:90:e2:18:f3))
Oct 27, 2018 11:53:38.308 [7524] DEBUG - NetworkServiceBrowser: Parsing SSDP schema for http://192.168.1.99:80/upnpd/description.xml
Oct 27, 2018 11:53:38.308 [7524] DEBUG - HTTP requesting GET http://192.168.1.99:80/upnpd/description.xml
Oct 27, 2018 11:53:38.323 [3948] DEBUG - MyPlex: Last published value didn't change, we're done.
Oct 27, 2018 11:53:38.323 [0736] DEBUG - MyPlex: Last published value didn't change, we're done.
Oct 27, 2018 11:53:38.355 [7524] DEBUG - HTTP 200 response from GET http://192.168.1.99:80/upnpd/description.xml
Oct 27, 2018 11:53:38.355 [7524] DEBUG - NetworkServiceBrowser: found 1 SSDP devices via http://192.168.1.99:80/upnpd/description.xml
Oct 27, 2018 11:53:38.355 [7524] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.1.99 (NC328SW-1080P (192.168.1.99) (7c:dd:90:e2:18:fb))
Oct 27, 2018 11:53:38.355 [7524] DEBUG - NetworkServiceBrowser: Parsing SSDP schema for http://192.168.1.61:80/upnpd/description.xml
Oct 27, 2018 11:53:38.355 [7524] DEBUG - HTTP requesting GET http://192.168.1.61:80/upnpd/description.xml
Oct 27, 2018 11:53:38.417 [7524] DEBUG - HTTP 200 response from GET http://192.168.1.61:80/upnpd/description.xml
Oct 27, 2018 11:53:38.417 [7524] DEBUG - NetworkServiceBrowser: found 1 SSDP devices via http://192.168.1.61:80/upnpd/description.xml
Oct 27, 2018 11:53:38.417 [7524] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.1.61 (NC308SW-1080P (192.168.1.61) (7c:dd:90:e5:3d:19))
Oct 27, 2018 11:53:39.792 [7524] DEBUG - NetworkServiceBrowser: Parsing SSDP schema for http://192.168.1.147:50001/
Oct 27, 2018 11:53:39.792 [7524] DEBUG - HTTP requesting GET http://192.168.1.147:50001/
Oct 27, 2018 11:53:39.792 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:39.792 [8600] DEBUG - Request: [192.168.1.199:57242 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (20 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:39.808 [8600] DEBUG - [CompanionProxy] registered new player: 5j71glbtk9j3hevefwsrod2t (192.168.1.199)
Oct 27, 2018 11:53:39.808 [7524] DEBUG - HTTP 200 response from GET http://192.168.1.147:50001/
Oct 27, 2018 11:53:39.808 [7524] DEBUG - NetworkServiceBrowser: found 1 SSDP devices via http://192.168.1.147:50001/
Oct 27, 2018 11:53:39.808 [7524] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.1.147 (HDR-FOX T2 Media Server)
Oct 27, 2018 11:53:39.808 [8600] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:53:40.074 [7524] DEBUG - NetworkServiceBrowser: Parsing SSDP schema for http://192.168.1.64:60000/upnp/dev/423d2a59-a4a7-a2c6-ffff-ffffb178e7cd/desc
Oct 27, 2018 11:53:40.074 [7524] DEBUG - HTTP requesting GET http://192.168.1.64:60000/upnp/dev/423d2a59-a4a7-a2c6-ffff-ffffb178e7cd/desc
Oct 27, 2018 11:53:40.105 [7524] DEBUG - HTTP 200 response from GET http://192.168.1.64:60000/upnp/dev/423d2a59-a4a7-a2c6-ffff-ffffb178e7cd/desc
Oct 27, 2018 11:53:40.120 [7524] DEBUG - NetworkServiceBrowser: found 1 SSDP devices via http://192.168.1.64:60000/upnp/dev/423d2a59-a4a7-a2c6-ffff-ffffb178e7cd/desc
Oct 27, 2018 11:53:40.120 [7524] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.49.1 (Mr's Fire TV stick)
Oct 27, 2018 11:53:40.573 [7524] DEBUG - NetworkServiceBrowser: Parsing SSDP schema for http://192.168.1.82:49153/description.xml
Oct 27, 2018 11:53:40.573 [7524] DEBUG - HTTP requesting GET http://192.168.1.82:49153/description.xml
Oct 27, 2018 11:53:40.589 [7524] DEBUG - HTTP 200 response from GET http://192.168.1.82:49153/description.xml
Oct 27, 2018 11:53:40.589 [7524] DEBUG - NetworkServiceBrowser: found 1 SSDP devices via http://192.168.1.82:49153/description.xml
Oct 27, 2018 11:53:40.589 [7524] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.1.82 (NV808 (192.168.1.82) (7c:dd:90:b0:53:15))
Oct 27, 2018 11:53:41.842 [7524] DEBUG - NetworkServiceBrowser: Parsing SSDP schema for http://192.168.1.146:32469/DeviceDescription.xml
Oct 27, 2018 11:53:41.842 [7524] DEBUG - HTTP requesting GET http://192.168.1.146:32469/DeviceDescription.xml
Oct 27, 2018 11:53:41.842 [7524] DEBUG - HTTP 200 response from GET http://192.168.1.146:32469/DeviceDescription.xml
Oct 27, 2018 11:53:41.857 [7524] DEBUG - NetworkServiceBrowser: found 1 SSDP devices via http://192.168.1.146:32469/DeviceDescription.xml
Oct 27, 2018 11:53:41.857 [7524] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.1.146 (Plex Media Server: Juno)
Oct 27, 2018 11:53:41.998 [8364] DEBUG - Reading 455 bytes in the body, code is 200
Oct 27, 2018 11:53:41.998 [8364] DEBUG - [com.plexapp.plugins.WebTools] Plug-in running on port 50158.
Oct 27, 2018 11:53:41.998 [8364] DEBUG -  * Plug-in handles prefix: /applications/webtools
Oct 27, 2018 11:53:41.998 [8364] DEBUG - Read configuration for [com.plexapp.plugins.WebTools], had 1 prefixes
Oct 27, 2018 11:53:42.123 [4000] DEBUG - Starting scheduled updates, every 86400 seconds
Oct 27, 2018 11:53:42.123 [4000] INFO - Refreshing paths watched by LibraryUpdateManager
Oct 27, 2018 11:53:42.123 [4000] DEBUG - LibraryUpdateManager will start watching \\network2\audiobooks
Oct 27, 2018 11:53:42.123 [4000] DEBUG - LibraryUpdateManager will start watching \\network2\video\Childrens
Oct 27, 2018 11:53:42.123 [4000] DEBUG - LibraryUpdateManager will start watching \\network2\video\Movies
Oct 27, 2018 11:53:42.123 [4000] DEBUG - LibraryUpdateManager will start watching \\network2\music
Oct 27, 2018 11:53:42.123 [4000] DEBUG - LibraryUpdateManager will start watching \\network2\photo
Oct 27, 2018 11:53:42.123 [4000] DEBUG - LibraryUpdateManager will start watching \\network2\video\TV Programs
Oct 27, 2018 11:53:43.342 [4000] DEBUG - Done waiting for all plug-ins to start.
Oct 27, 2018 11:53:43.358 [4000] DEBUG - PluginRepository::setStartState: 3, complete
Oct 27, 2018 11:53:43.358 [8928] DEBUG - Downloading document http://127.0.0.1:32400/:/plugins/com.plexapp.agents.imdb/prefs
Oct 27, 2018 11:53:43.405 [8928] DEBUG - Starting file watcher for com.plexapp.agents.imdb
Oct 27, 2018 11:53:43.405 [8928] DEBUG - Plugin::createProcess: Creating plugin process: "C:\Program Files (x86)\Plex\Plex Media Server\PlexScriptHost.exe" "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\Framework.bundle\Contents\Resources\Versions\2\Python\bootstrap.py" "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\PlexMovie.bundle"
Oct 27, 2018 11:53:43.436 [8928] DEBUG - Spawned plug-in com.plexapp.agents.imdb with PID 8956
Oct 27, 2018 11:53:43.436 [8928] DEBUG - [com.plexapp.agents.imdb] Sending command: GET /:/prefixes

Oct 27, 2018 11:53:45.124 [4044] DEBUG - Activity: registered new activity 162252f4-da0e-4b92-aaa6-0709d963bf3f - Processing subscriptions
Oct 27, 2018 11:53:45.124 [4044] DEBUG - DVR:Subscription: Scheduling subscriptions.
Oct 27, 2018 11:53:45.124 [4044] DEBUG - DVR:Subscription: Initialized 0 schedulers.
Oct 27, 2018 11:53:45.124 [4044] DEBUG - DVR:Subscription: Starting with 0 grabs, scheduled 0 active ones preemptively.
Oct 27, 2018 11:53:45.124 [4044] DEBUG - DVR:Subscription: Scheduled all subscriptions in 13 ms.
Oct 27, 2018 11:53:45.124 [4044] DEBUG - Activity: Ended activity 162252f4-da0e-4b92-aaa6-0709d963bf3f.
Oct 27, 2018 11:53:45.139 [4044] DEBUG - DVR:Subscription: There are 0 active grabs at the end.
Oct 27, 2018 11:53:45.139 [4044] DEBUG - Activity: Ended activity c157d43b-ddf7-44f4-9ec0-7709ab1ce257.
Oct 27, 2018 11:53:45.139 [4044] DEBUG - DVR:Subscription: Refreshed all content in 16 ms.
Oct 27, 2018 11:53:45.249 [7844] DEBUG - Request: [127.0.0.1:50168 (Loopback)] GET /system/messaging/clear_events/com.plexapp.agents.imdb (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:45.249 [7844] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/messaging/clear_events/com.plexapp.agents.imdb
Oct 27, 2018 11:53:45.249 [7844] DEBUG - HTTP requesting GET http://127.0.0.1:49877/system/messaging/clear_events/com.plexapp.agents.imdb
Oct 27, 2018 11:53:45.264 [7844] DEBUG - HTTP 200 response from GET http://127.0.0.1:49877/system/messaging/clear_events/com.plexapp.agents.imdb
Oct 27, 2018 11:53:45.264 [7844] DEBUG - [com.plexapp.system] HTTP reply status 200, with 0 bytes of content.
Oct 27, 2018 11:53:45.264 [3776] DEBUG - Completed: [127.0.0.1:50168] 200 GET /system/messaging/clear_events/com.plexapp.agents.imdb (23 live) GZIP 9ms 330 bytes
Oct 27, 2018 11:53:45.389 [7100] DEBUG - Request: [127.0.0.1:50170 (Loopback)] GET /:/plugins/com.plexapp.system/resourceHashes (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:45.389 [7100] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /:/plugins/com.plexapp.system/resourceHashes
Oct 27, 2018 11:53:45.389 [7100] DEBUG - HTTP requesting GET http://127.0.0.1:49877/:/plugins/com.plexapp.system/resourceHashes
Oct 27, 2018 11:53:45.389 [7100] DEBUG - HTTP 200 response from GET http://127.0.0.1:49877/:/plugins/com.plexapp.system/resourceHashes
Oct 27, 2018 11:53:45.389 [7100] DEBUG - [com.plexapp.system] HTTP reply status 200, with 13276 bytes of content.
Oct 27, 2018 11:53:45.389 [3776] DEBUG - Completed: [127.0.0.1:50170] 200 GET /:/plugins/com.plexapp.system/resourceHashes (24 live) GZIP 12ms 3498 bytes
Oct 27, 2018 11:53:45.421 [6344] DEBUG - Request: [127.0.0.1:50172 (Loopback)] GET /:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_ (26 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:45.421 [6344] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_
Oct 27, 2018 11:53:45.421 [6344] DEBUG - HTTP requesting GET http://127.0.0.1:49877/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_
Oct 27, 2018 11:53:45.421 [6264] DEBUG - Request: [127.0.0.1:50173 (Loopback)] GET / (26 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:45.421 [3776] DEBUG - Completed: [127.0.0.1:50173] 200 GET / (26 live) GZIP 3ms 2449 bytes
Oct 27, 2018 11:53:45.452 [6344] DEBUG - HTTP 200 response from GET http://127.0.0.1:49877/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_
Oct 27, 2018 11:53:45.452 [6344] DEBUG - [com.plexapp.system] HTTP reply status 200, with 62566 bytes of content.
Oct 27, 2018 11:53:45.452 [3788] DEBUG - Completed: [127.0.0.1:50172] 200 GET /:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_ (26 live) GZIP 40ms 20198 bytes
Oct 27, 2018 11:53:46.952 [6876] DEBUG - Request: [127.0.0.1:50176 (Loopback)] GET /:/plugins/com.plexapp.system/messaging/function/X0FnZW50U2VydmljZTpVcGRhdGVJbmZv/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQo3CmRpY3QKbGlzdApkaWN0Cmxpc3QKbGlzdApsaXN0Cmxpc3QKMgpzMjMKY29tLnBsZXhhcHAuYWdlbnRzLmltZGJzMTAKaWRlbnRpZmllcnIxCnMxMAphZ2VudF9pbmZvMQpyMgoxMApyMwpzMTEKbWVkaWFfdHlwZXNyNApzMTIKYWNjZXB0c19mcm9tbnMxNApmYWxsYmFja19hZ2VudHI1CnMxNApjb250cmlidXRlc190b3I2CnM5Cmxhbmd1YWdlc2IxczIwCnBlcnNpc3Rfc3RvcmVkX2ZpbGVzaTAKczcKdmVyc2lvbmIxczE2CnByaW1hcnlfcHJvdmlkZXJiMXM1CnByZWZzczEwClBsZXggTW92aWVzNApuYW1lMQpzNQpNb3ZpZTEKczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhMQpzMjkKY29tLnBsZXhhcHAuYWdlbnRzLnRoZW1vdmllZGIzMwpzMgplbnMyCnN2czIKZnJzMgplc3MyCm5sczIKZGVzMgppdHMyCmRhczIKYXJzMgpjYXMyCnpoczIKY3NzMgpldHMyCmZpczIKZWxzMgpoZXMyCmhpczIKaHVzMgppZHMyCmphczIKa29zMgpsdnMyCm5vczIKZmFzMgpwbHMyCnB0czIKcm9zMgpydXMyCnNrczIKdGhzMgp0cnMyCnVrczIKdmlyMAo_ (28 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:46.952 [6876] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /:/plugins/com.plexapp.system/messaging/function/X0FnZW50U2VydmljZTpVcGRhdGVJbmZv/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQo3CmRpY3QKbGlzdApkaWN0Cmxpc3QKbGlzdApsaXN0Cmxpc3QKMgpzMjMKY29tLnBsZXhhcHAuYWdlbnRzLmltZGJzMTAKaWRlbnRpZmllcnIxCnMxMAphZ2VudF9pbmZvMQpyMgoxMApyMwpzMTEKbWVkaWFfdHlwZXNyNApzMTIKYWNjZXB0c19mcm9tbnMxNApmYWxsYmFja19hZ2VudHI1CnMxNApjb250cmlidXRlc190b3I2CnM5Cmxhbmd1YWdlc2IxczIwCnBlcnNpc3Rfc3RvcmVkX2ZpbGVzaTAKczcKdmVyc2lvbmIxczE2CnByaW1hcnlfcHJvdmlkZXJiMXM1CnByZWZzczEwClBsZXggTW92aWVzNApuYW1lMQpzNQpNb3ZpZTEKczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhMQpzMjkKY29tLnBsZXhhcHAuYWdlbnRzLnRoZW1vdmllZGIzMwpzMgplbnMyCnN2czIKZnJzMgplc3MyCm5sczIKZGVzMgppdHMyCmRhczIKYXJzMgpjYXMyCnpoczIKY3NzMgpldHMyCmZpczIKZWxzMgpoZXMyCmhpczIKaHVzMgppZHMyCmphczIKa29zMgpsdnMyCm5vczIKZmFzMgpwbHMyCnB0czIKcm9zMgpydXMyCnNrczIKdGhzMgp0cnMyCnVrczIKdmlyMAo_
Oct 27, 2018 11:53:46.952 [6876] DEBUG - HTTP requesting GET http://127.0.0.1:49877/:/plugins/com.plexapp.system/messaging/function/X0FnZW50U2VydmljZTpVcGRhdGVJbmZv/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQo3CmRpY3QKbGlzdApkaWN0Cmxpc3QKbGlzdApsaXN0Cmxpc3QKMgpzMjMKY29tLnBsZXhhcHAuYWdlbnRzLmltZGJzMTAKaWRlbnRpZmllcnIxCnMxMAphZ2VudF9pbmZvMQpyMgoxMApyMwpzMTEKbWVkaWFfdHlwZXNyNApzMTIKYWNjZXB0c19mcm9tbnMxNApmYWxsYmFja19hZ2VudHI1CnMxNApjb250cmlidXRlc190b3I2CnM5Cmxhbmd1YWdlc2IxczIwCnBlcnNpc3Rfc3RvcmVkX2ZpbGVzaTAKczcKdmVyc2lvbmIxczE2CnByaW1hcnlfcHJvdmlkZXJiMXM1CnByZWZzczEwClBsZXggTW92aWVzNApuYW1lMQpzNQpNb3ZpZTEKczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhMQpzMjkKY29tLnBsZXhhcHAuYWdlbnRzLnRoZW1vdmllZGIzMwpzMgplbnMyCnN2czIKZnJzMgplc3MyCm5sczIKZGVzMgppdHMyCmRhczIKYXJzMgpjYXMyCnpoczIKY3NzMgpldHMyCmZpczIKZWxzMgpoZXMyCmhpczIKaHVzMgppZHMyCmphczIKa29zMgpsdnMyCm5vczIKZmFzMgpwbHMyCnB0czIKcm9zMgpydXMyCnNrczIKdGhzMgp0cnMyCnVrczIKdmlyMAo_
Oct 27, 2018 11:53:46.983 [6876] DEBUG - HTTP 200 response from GET http://127.0.0.1:49877/:/plugins/com.plexapp.system/messaging/function/X0FnZW50U2VydmljZTpVcGRhdGVJbmZv/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQo3CmRpY3QKbGlzdApkaWN0Cmxpc3QKbGlzdApsaXN0Cmxpc3QKMgpzMjMKY29tLnBsZXhhcHAuYWdlbnRzLmltZGJzMTAKaWRlbnRpZmllcnIxCnMxMAphZ2VudF9pbmZvMQpyMgoxMApyMwpzMTEKbWVkaWFfdHlwZXNyNApzMTIKYWNjZXB0c19mcm9tbnMxNApmYWxsYmFja19hZ2VudHI1CnMxNApjb250cmlidXRlc190b3I2CnM5Cmxhbmd1YWdlc2IxczIwCnBlcnNpc3Rfc3RvcmVkX2ZpbGVzaTAKczcKdmVyc2lvbmIxczE2CnByaW1hcnlfcHJvdmlkZXJiMXM1CnByZWZzczEwClBsZXggTW92aWVzNApuYW1lMQpzNQpNb3ZpZTEKczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhMQpzMjkKY29tLnBsZXhhcHAuYWdlbnRzLnRoZW1vdmllZGIzMwpzMgplbnMyCnN2czIKZnJzMgplc3MyCm5sczIKZGVzMgppdHMyCmRhczIKYXJzMgpjYXMyCnpoczIKY3NzMgpldHMyCmZpczIKZWxzMgpoZXMyCmhpczIKaHVzMgppZHMyCmphczIKa29zMgpsdnMyCm5vczIKZmFzMgpwbHMyCnB0czIKcm9zMgpydXMyCnNrczIKdGhzMgp0cnMyCnVrczIKdmlyMAo_
Oct 27, 2018 11:53:46.983 [6876] DEBUG - [com.plexapp.system] HTTP reply status 200, with 16 bytes of content.
Oct 27, 2018 11:53:46.983 [3776] DEBUG - Completed: [127.0.0.1:50176] 200 GET /:/plugins/com.plexapp.system/messaging/function/X0FnZW50U2VydmljZTpVcGRhdGVJbmZv/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQo3CmRpY3QKbGlzdApkaWN0Cmxpc3QKbGlzdApsaXN0Cmxpc3QKMgpzMjMKY29tLnBsZXhhcHAuYWdlbnRzLmltZGJzMTAKaWRlbnRpZmllcnIxCnMxMAphZ2VudF9pbmZvMQpyMgoxMApyMwpzMTEKbWVkaWFfdHlwZXNyNApzMTIKYWNjZXB0c19mcm9tbnMxNApmYWxsYmFja19hZ2VudHI1CnMxNApjb250cmlidXRlc190b3I2CnM5Cmxhbmd1YWdlc2IxczIwCnBlcnNpc3Rfc3RvcmVkX2ZpbGVzaTAKczcKdmVyc2lvbmIxczE2CnByaW1hcnlfcHJvdmlkZXJiMXM1CnByZWZzczEwClBsZXggTW92aWVzNApuYW1lMQpzNQpNb3ZpZTEKczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhMQpzMjkKY29tLnBsZXhhcHAuYWdlbnRzLnRoZW1vdmllZGIzMwpzMgplbnMyCnN2czIKZnJzMgplc3MyCm5sczIKZGVzMgppdHMyCmRhczIKYXJzMgpjYXMyCnpoczIKY3NzMgpldHMyCmZpczIKZWxzMgpoZXMyCmhpczIKaHVzMgppZHMyCmphczIKa29zMgpsdnMyCm5vczIKZmFzMgpwbHMyCnB0czIKcm9zMgpydXMyCnNrczIKdGhzMgp0cnMyCnVrczIKdmlyMAo_ (28 live) GZIP 26ms 465 bytes
Oct 27, 2018 11:53:47.046 [8928] DEBUG - Reading 148 bytes in the body, code is 200
Oct 27, 2018 11:53:47.046 [8928] DEBUG - [com.plexapp.agents.imdb] Plug-in running on port 50178.
Oct 27, 2018 11:53:47.046 [8928] DEBUG - Read configuration for [com.plexapp.agents.imdb], had 0 prefixes
Oct 27, 2018 11:53:47.077 [8928] DEBUG - [com.plexapp.agents.imdb] Sending command over HTTP (GET): /:/plugins/com.plexapp.agents.imdb/prefs
Oct 27, 2018 11:53:47.077 [8928] DEBUG - HTTP requesting GET http://127.0.0.1:50178/:/plugins/com.plexapp.agents.imdb/prefs
Oct 27, 2018 11:53:47.218 [8928] DEBUG - HTTP 200 response from GET http://127.0.0.1:50178/:/plugins/com.plexapp.agents.imdb/prefs
Oct 27, 2018 11:53:47.218 [8928] DEBUG - [com.plexapp.agents.imdb] HTTP reply status 200, with 2223 bytes of content.
Oct 27, 2018 11:53:47.218 [8928] DEBUG - Caching document http://127.0.0.1:32400/:/plugins/com.plexapp.agents.imdb/prefs as f020f3040781b065d704d7088517d31aaee4d370
Oct 27, 2018 11:53:47.218 [8928] DEBUG - IVA: Downloading trailer lists.
Oct 27, 2018 11:53:47.327 [8928] DEBUG - IVA: Downloaded 29 trailers for source 1.
Oct 27, 2018 11:53:47.437 [8928] DEBUG - IVA: Downloaded 33 trailers for source 2.
Oct 27, 2018 11:53:56.361 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:53:56.361 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:56.361 [9052] DEBUG - Request: [192.168.1.199:57249 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:56.376 [9052] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:53:59.814 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:53:59.830 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:53:59.830 [3684] DEBUG - Request: [192.168.1.199:57255 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (17 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:53:59.830 [3684] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:54:09.802 [3920] DEBUG - NetworkServiceBrowser: SSDP departed after not being seen for 21.818329 seconds: 192.168.1.99 (NC328SW-1080P (192.168.1.99) (7c:dd:90:e2:18:fb))
Oct 27, 2018 11:54:16.382 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:54:16.382 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:54:16.382 [6556] DEBUG - Request: [192.168.1.199:57257 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:54:16.382 [6556] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:54:19.836 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:54:19.852 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:54:19.852 [6556] DEBUG - Request: [192.168.1.199:57260 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:54:19.867 [6556] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:54:20.945 [3788] DEBUG - Request: [86.139.150.227:51319 (WAN)] GET /resources (25 live) GZIP Signed-in
Oct 27, 2018 11:54:20.945 [3776] DEBUG - Completed: [86.139.150.227:51319] 401 GET /resources (25 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:54:20.961 [3788] DEBUG - Request: [86.139.150.227:51320 (WAN)] GET /resources (25 live) GZIP Signed-in
Oct 27, 2018 11:54:20.961 [3776] DEBUG - Completed: [86.139.150.227:51320] 401 GET /resources (25 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:54:22.930 [3788] DEBUG - Request: [86.139.150.227:51327 (WAN)] GET /resources (29 live) GZIP Signed-in
Oct 27, 2018 11:54:22.930 [3776] DEBUG - Completed: [86.139.150.227:51327] 401 GET /resources (29 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:54:22.946 [3788] DEBUG - Request: [86.139.150.227:51328 (WAN)] GET /resources (30 live) GZIP Signed-in
Oct 27, 2018 11:54:22.946 [3776] DEBUG - Completed: [86.139.150.227:51328] 401 GET /resources (30 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:54:22.961 [3788] DEBUG - Request: [86.139.150.227:51329 (WAN)] GET /resources (31 live) GZIP Signed-in
Oct 27, 2018 11:54:22.961 [3776] DEBUG - Completed: [86.139.150.227:51329] 401 GET /resources (31 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:54:22.977 [3788] DEBUG - Request: [86.139.150.227:51330 (WAN)] GET /resources (32 live) GZIP Signed-in
Oct 27, 2018 11:54:22.977 [3776] DEBUG - Completed: [86.139.150.227:51330] 401 GET /resources (32 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:54:27.963 [7524] DEBUG - NetworkServiceBrowser: Parsing SSDP schema for http://192.168.1.99:80/upnpd/description.xml
Oct 27, 2018 11:54:27.963 [7524] DEBUG - HTTP requesting GET http://192.168.1.99:80/upnpd/description.xml
Oct 27, 2018 11:54:28.041 [7524] DEBUG - HTTP 200 response from GET http://192.168.1.99:80/upnpd/description.xml
Oct 27, 2018 11:54:28.041 [7524] DEBUG - NetworkServiceBrowser: found 1 SSDP devices via http://192.168.1.99:80/upnpd/description.xml
Oct 27, 2018 11:54:28.041 [7524] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.1.99 (NC328SW-1080P (192.168.1.99) (7c:dd:90:e2:18:fb))
Oct 27, 2018 11:54:36.386 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:54:36.386 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:54:36.386 [9552] DEBUG - Request: [192.168.1.199:57262 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (37 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:54:36.386 [9552] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:54:37.089 [3788] DEBUG - Request: [86.139.150.227:51345 (WAN)] GET /resources (38 live) GZIP Signed-in
Oct 27, 2018 11:54:37.089 [3776] DEBUG - Completed: [86.139.150.227:51345] 401 GET /resources (38 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:54:37.120 [3788] DEBUG - Request: [86.139.150.227:51348 (WAN)] GET /resources (42 live) GZIP Signed-in
Oct 27, 2018 11:54:37.120 [3776] DEBUG - Request: [86.139.150.227:51350 (WAN)] GET /resources (42 live) GZIP Signed-in
Oct 27, 2018 11:54:37.120 [3788] DEBUG - Completed: [86.139.150.227:51348] 401 GET /resources (42 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:54:37.120 [3788] DEBUG - Completed: [86.139.150.227:51350] 401 GET /resources (41 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:54:37.136 [3788] DEBUG - Request: [86.139.150.227:51353 (WAN)] GET /resources (44 live) GZIP Signed-in
Oct 27, 2018 11:54:37.136 [3776] DEBUG - Completed: [86.139.150.227:51353] 401 GET /resources (44 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:54:39.871 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:54:39.871 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:54:39.887 [6532] DEBUG - Request: [192.168.1.199:57263 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (45 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:54:39.887 [6532] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:54:49.108 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:54:49.108 [9552] DEBUG - Request: [86.139.150.227:51357 (WAN)] GET / (41 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:54:49.108 [9552] DEBUG - (Capabilities) Platform 'Windows' not matched by plugin platform requirements
Oct 27, 2018 11:54:49.108 [3788] DEBUG - Completed: [86.139.150.227:51357] 200 GET / (41 live) GZIP 4ms 2423 bytes (pipelined: 1)
Oct 27, 2018 11:54:56.391 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:54:56.407 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:54:56.407 [6532] DEBUG - Request: [192.168.1.199:57267 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (36 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:54:56.407 [6532] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:54:59.892 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:54:59.892 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:54:59.892 [9552] DEBUG - Request: [192.168.1.199:57268 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (37 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:54:59.892 [9552] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:55:13.989 [6780] DEBUG - BPQ: [Starting] -> [Processing]
Oct 27, 2018 11:55:14.098 [6780] DEBUG - BPQ: generating queue items from 18 generator(s)
Oct 27, 2018 11:55:14.098 [6780] DEBUG - Sync: skipping sync list 26054734 from device Emma’s iPhone because it's snoozing
Oct 27, 2018 11:55:14.098 [6780] DEBUG - Sync: updating status for sync list 26054734, sync item 28989790, generator 2216
Oct 27, 2018 11:55:14.755 [6780] DEBUG - Sync: skipping sync list 26054734 from device Emma’s iPhone because it's snoozing
Oct 27, 2018 11:55:14.755 [6780] DEBUG - Sync: updating status for sync list 26054734, sync item 28989793, generator 2217
Oct 27, 2018 11:55:15.427 [6780] DEBUG - Sync: skipping sync list 26054734 from device Emma’s iPhone because it's snoozing
Oct 27, 2018 11:55:15.427 [6780] DEBUG - Sync: updating status for sync list 26054734, sync item 28989804, generator 2218
Oct 27, 2018 11:55:15.615 [6780] DEBUG - Sync: skipping sync list 26054734 from device Emma’s iPhone because it's snoozing
Oct 27, 2018 11:55:15.615 [6780] DEBUG - Sync: updating status for sync list 26054734, sync item 28989810, generator 2219
Oct 27, 2018 11:55:15.834 [6780] DEBUG - Sync: updating status for sync list 24750675, sync item 29255612, generator 2240
Oct 27, 2018 11:55:15.865 [6780] DEBUG - Sync: updating status for sync list 24750675, sync item 29433922, generator 2257
Oct 27, 2018 11:55:15.927 [6780] DEBUG - Sync: updating status for sync list 24750675, sync item 29433930, generator 2258
Oct 27, 2018 11:55:15.959 [6780] DEBUG - Sync: updating status for sync list 24750675, sync item 29433931, generator 2259
Oct 27, 2018 11:55:15.974 [6780] DEBUG - Sync: updating status for sync list 24750675, sync item 29433934, generator 2260
Oct 27, 2018 11:55:15.990 [6780] DEBUG - Sync: updating status for sync list 25669848, sync item 30074073, generator 2296
Oct 27, 2018 11:55:15.990 [6780] DEBUG - Sync: updating status for sync list 25669848, sync item 30074170, generator 2297
Oct 27, 2018 11:55:16.005 [6780] DEBUG - Sync: updating status for sync list 25669848, sync item 30074197, generator 2298
Oct 27, 2018 11:55:16.021 [6780] DEBUG - Sync: updating status for sync list 25669848, sync item 30074212, generator 2299
Oct 27, 2018 11:55:16.037 [6780] DEBUG - Sync: updating status for sync list 25669848, sync item 30074237, generator 2300
Oct 27, 2018 11:55:16.052 [6780] DEBUG - Sync: updating status for sync list 25669848, sync item 30115400, generator 2307
Oct 27, 2018 11:55:16.052 [6780] DEBUG - Sync: updating status for sync list 25669848, sync item 30116959, generator 2308
Oct 27, 2018 11:55:16.068 [6780] DEBUG - Sync: updating status for sync list 25669848, sync item 30116965, generator 2309
Oct 27, 2018 11:55:16.084 [6780] DEBUG - Sync: updating status for sync list 25669848, sync item 30168043, generator 2311
Oct 27, 2018 11:55:16.084 [6780] DEBUG - BPQ: generated 0 item(s) for queue
Oct 27, 2018 11:55:16.130 [6780] DEBUG - PlayQueue: 0 generated IDs compressed down to a 2 byte blob.
Oct 27, 2018 11:55:16.130 [6780] DEBUG - PlayQueue: 0 generated IDs compressed down to a 2 byte blob.
Oct 27, 2018 11:55:16.240 [6780] DEBUG - BPQ: [Processing] -> [Idle]
Oct 27, 2018 11:55:16.412 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:55:16.412 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:55:16.412 [6532] DEBUG - Request: [192.168.1.199:57269 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (19 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:55:16.412 [6532] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:55:19.897 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:55:19.913 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:55:19.913 [9928] DEBUG - Request: [192.168.1.199:57272 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (20 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:55:19.913 [9928] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:55:27.264 [6532] DEBUG - Request: [127.0.0.1:50611 (Loopback)] GET /servers (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:55:27.264 [3788] DEBUG - Completed: [127.0.0.1:50611] 200 GET /servers (23 live) GZIP 3ms 489 bytes
Oct 27, 2018 11:55:27.279 [9928] DEBUG - Request: [127.0.0.1:50612 (Loopback)] GET /library/sections (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:55:27.295 [3788] DEBUG - Completed: [127.0.0.1:50612] 200 GET /library/sections (24 live) GZIP 6ms 1215 bytes
Oct 27, 2018 11:55:27.295 [6532] DEBUG - Request: [127.0.0.1:50613 (Loopback)] GET /channels/all (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:55:27.295 [3788] DEBUG - Completed: [127.0.0.1:50613] 200 GET /channels/all (24 live) GZIP 2ms 927 bytes
Oct 27, 2018 11:55:27.310 [9928] DEBUG - Request: [127.0.0.1:50614 (Loopback)] GET /library/sections (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:55:27.310 [3776] DEBUG - Completed: [127.0.0.1:50614] 200 GET /library/sections (24 live) GZIP 4ms 1215 bytes
Oct 27, 2018 11:55:27.326 [6532] DEBUG - Request: [127.0.0.1:50615 (Loopback)] GET /channels/all (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:55:27.326 [3788] DEBUG - Completed: [127.0.0.1:50615] 200 GET /channels/all (24 live) GZIP 2ms 927 bytes
Oct 27, 2018 11:55:36.424 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:55:36.424 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:55:36.424 [9928] DEBUG - Request: [192.168.1.199:57274 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (21 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:55:36.424 [9928] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:55:39.925 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:55:39.941 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:55:39.941 [6532] DEBUG - Request: [192.168.1.199:57275 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:55:39.941 [6532] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:55:44.770 [7524] DEBUG - NetworkServiceBrowser: PLAYER arrived: 192.168.1.80
Oct 27, 2018 11:55:53.522 [3776] DEBUG - CERT: incomplete TLS handshake: short read
Oct 27, 2018 11:55:53.522 [3788] DEBUG - CERT: incomplete TLS handshake: short read
Oct 27, 2018 11:55:53.522 [3776] DEBUG - CERT: incomplete TLS handshake: short read
Oct 27, 2018 11:55:56.430 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:55:56.430 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:55:56.430 [9928] DEBUG - Request: [192.168.1.199:57286 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:55:56.445 [9928] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:55:59.946 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:55:59.946 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:55:59.946 [8796] DEBUG - Request: [192.168.1.199:57287 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (19 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:55:59.962 [8796] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:56:05.909 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:05.909 [9928] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET / (17 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:05.916 [9928] DEBUG - (Capabilities) Platform 'iOS' not matched by plugin platform requirements
Oct 27, 2018 11:56:05.916 [3776] DEBUG - Completed: [127.0.0.1:50778] 200 GET / (17 live) TLS GZIP 9ms 2489 bytes (pipelined: 1)
Oct 27, 2018 11:56:06.637 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:06.637 [8796] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /media/providers (20 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:06.737 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 GET /media/providers (20 live) TLS GZIP 107ms 1186 bytes (pipelined: 2)
Oct 27, 2018 11:56:07.439 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:07.439 [9928] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /channels/all (22 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:07.454 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 GET /channels/all (22 live) TLS GZIP 7ms 956 bytes (pipelined: 3)
Oct 27, 2018 11:56:08.040 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:08.040 [8796] DEBUG - Request: [127.0.0.1:50787 (WAN)] GET /activities (22 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:08.056 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:08.056 [9928] DEBUG - Request: [127.0.0.1:50789 (WAN)] GET /library/sections (22 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:08.056 [3776] DEBUG - Completed: [127.0.0.1:50787] 200 GET /activities (22 live) TLS GZIP 5ms 397 bytes (pipelined: 1)
Oct 27, 2018 11:56:08.056 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:08.056 [3788] DEBUG - Completed: [127.0.0.1:50789] 200 GET /library/sections (22 live) TLS GZIP 8ms 1244 bytes (pipelined: 1)
Oct 27, 2018 11:56:08.056 [8796] DEBUG - Request: [127.0.0.1:50790 (WAN)] GET /playQueues/1282 (22 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:08.056 [8796] DEBUG - PlayQueue: total generated: 37, before cursor: 21, after cursor: 15
Oct 27, 2018 11:56:08.056 [8796] DEBUG - PlayQueue: No need to refresh, active window is operational.
Oct 27, 2018 11:56:08.156 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:08.156 [9928] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /hubs/sections/19?count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1 (23 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:08.218 [9928] DEBUG - HubCache: Adding '1/music.recent.played.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' to the cache (1/music.recent.played.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1).
Oct 27, 2018 11:56:08.387 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:08.387 [5292] DEBUG - Request: [127.0.0.1:50788 (WAN)] GET /:/eventsource/notifications (23 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:08.588 [9928] DEBUG - HubCache: Computed '1/music.recent.played.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' in 376 ms.
Oct 27, 2018 11:56:08.588 [9928] DEBUG - HubCache: 1 hubs cached, 0.0% hit ratio.
Oct 27, 2018 11:56:08.588 [9928] DEBUG - HubCache: Adding '1/music.quicklinks.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' to the cache (1/music.quicklinks.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1).
Oct 27, 2018 11:56:08.641 [9928] DEBUG - HubCache: Computed '1/music.quicklinks.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' in 49 ms.
Oct 27, 2018 11:56:08.641 [9928] DEBUG - HubCache: Adding '1/music.recent.added.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' to the cache (1/music.recent.added.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1).
Oct 27, 2018 11:56:08.719 [9928] DEBUG - HubCache: Computed '1/music.recent.added.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' in 77 ms.
Oct 27, 2018 11:56:08.719 [9928] DEBUG - HubCache: Adding '1/recent.library.playlists.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' to the cache (1/recent.library.playlists.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1).
Oct 27, 2018 11:56:08.735 [9928] DEBUG - HubCache: Computed '1/recent.library.playlists.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' in 8 ms.
Oct 27, 2018 11:56:08.735 [9928] DEBUG - HubCache: Adding '1/music.stations.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' to the cache (1/music.stations.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1).
Oct 27, 2018 11:56:08.735 [9928] DEBUG - HubCache: Computed '1/music.stations.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' in 0 ms.
Oct 27, 2018 11:56:08.735 [9928] DEBUG - HubCache: Adding '1/music.recent.artist.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' to the cache (1/music.recent.artist.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1).
Oct 27, 2018 11:56:08.920 [8796] DEBUG - It took 109.375000 ms to retrieve 36 items.
Oct 27, 2018 11:56:09.159 [3776] DEBUG - Completed: [127.0.0.1:50790] 200 GET /playQueues/1282 (23 live) TLS GZIP 1094ms 4875 bytes (pipelined: 1)
Oct 27, 2018 11:56:09.692 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:09.692 [2284] DEBUG - Request: [127.0.0.1:50787 (WAN)] GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (23 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:09.746 [2284] DEBUG - Client [CA59F2C9-6404-464D-9F3A-CD769CA78600] reporting timeline state paused, progress of 1626143/2432546ms for guid=, ratingKey=172774 url=, key=/library/metadata/172774, containerKey=, metadataId=172774
Oct 27, 2018 11:56:09.761 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:09.761 [5292] DEBUG - Request: [127.0.0.1:50790 (WAN)] GET /photo/:/transcode/?height=1024&minSize=0&url=http%3A%2F%2F127.0.0.1%3A32400%2Flibrary%2Fmetadata%2F172583%2Fthumb%2F1536114720&width=1024 (23 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:09.824 [5292] DEBUG - Photo transcoder: Request for url [http://127.0.0.1:32400/library/metadata/172583/thumb/1536114720] (is local: 1 upscaled: 0)
Oct 27, 2018 11:56:09.978 [2284] DEBUG - Play progress on 172774 'Chapter 22 - The Deathly Hallows' - got played 1626143 ms by account 1!
Oct 27, 2018 11:56:10.179 [5292] DEBUG - Content-Length of C:\Users\craig\AppData\Local\Plex Media Server\Cache\PhotoTranscoder\cb\cb921870de61432cd7a11dc08573ae2b6c3888c7.jpg is 180219.
Oct 27, 2018 11:56:10.310 [2284] DEBUG - [Now] User is tubs74 (ID: 1)
Oct 27, 2018 11:56:10.310 [2284] DEBUG - [Now] Device is iOS (iPhone).
Oct 27, 2018 11:56:10.310 [2284] DEBUG - [Now] Profile is iOS
Oct 27, 2018 11:56:10.310 [2284] DEBUG - [Now] Updated play state for /library/metadata/172774.
Oct 27, 2018 11:56:10.326 [3776] DEBUG - Completed: [127.0.0.1:50790] 200 GET /photo/:/transcode/?height=1024&minSize=0&url=http%3A%2F%2F127.0.0.1%3A32400%2Flibrary%2Fmetadata%2F172583%2Fthumb%2F1536114720&width=1024 (22 live) TLS GZIP 556ms 180219 bytes (pipelined: 2)
Oct 27, 2018 11:56:14.176 [9928] DEBUG - HubCache: Computed '1/music.recent.artist.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' in 5442 ms.
Oct 27, 2018 11:56:14.176 [2284] DEBUG - HubCache: Expiring '1/music.recent.artist.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' because of event plex.event.play.session.state.update.
Oct 27, 2018 11:56:14.176 [2284] DEBUG - HubCache: Expiring '1/music.recent.played.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' because of event plex.event.play.session.state.update.
Oct 27, 2018 11:56:14.176 [9928] DEBUG - HubCache: Adding '1/music.top.period.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' to the cache (1/music.top.period.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1).
Oct 27, 2018 11:56:14.176 [2284] DEBUG - Statistics: (CA59F2C9-6404-464D-9F3A-CD769CA78600) Reporting active playback in state 1 of type 10 (scrobble: 0) for account 1
Oct 27, 2018 11:56:14.192 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:14.192 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:14.192 [8796] DEBUG - Request: [192.168.1.199:57288 (Allowed Network)] GET /status/sessions (26 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:14.192 [5292] DEBUG - Request: [192.168.1.199:57289 (Allowed Network)] GET /status/sessions (26 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:14.239 [9928] DEBUG - HubCache: Computed '1/music.top.period.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' in 67 ms.
Oct 27, 2018 11:56:14.239 [9928] DEBUG - HubCache: Adding '1/music.recent.genre.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' to the cache (1/music.recent.genre.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1).
Oct 27, 2018 11:56:14.408 [8796] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:56:14.408 [5292] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:56:14.408 [3776] DEBUG - Completed: [192.168.1.199:57288] 200 GET /status/sessions (26 live) GZIP 217ms 397 bytes (pipelined: 1)
Oct 27, 2018 11:56:14.408 [3788] DEBUG - Completed: [192.168.1.199:57289] 200 GET /status/sessions (26 live) GZIP 217ms 470 bytes (pipelined: 1)
Oct 27, 2018 11:56:14.424 [3788] DEBUG - Completed: [127.0.0.1:50787] 200 GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (26 live) TLS GZIP 4724ms 455 bytes (pipelined: 2)
Oct 27, 2018 11:56:14.555 [9928] DEBUG - HubCache: Computed '1/music.recent.genre.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' in 309 ms.
Oct 27, 2018 11:56:14.555 [9928] DEBUG - HubCache: Adding '1/music.popular.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' to the cache (1/music.popular.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1).
Oct 27, 2018 11:56:15.095 [9928] DEBUG - HubCache: Computed '1/music.popular.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' in 541 ms.
Oct 27, 2018 11:56:15.095 [9928] DEBUG - HubCache: Adding '1/music.vault.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' to the cache (1/music.vault.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1).
Oct 27, 2018 11:56:15.095 [9928] DEBUG - HubCache: Computed '1/music.vault.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' in 3 ms.
Oct 27, 2018 11:56:15.095 [9928] DEBUG - HubCache: Adding '1/music.recent.label.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' to the cache (1/music.recent.label.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1).
Oct 27, 2018 11:56:15.164 [9928] DEBUG - HubCache: Adding '1/music.touring.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' to the cache (1/music.touring.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1).
Oct 27, 2018 11:56:15.281 [9928] DEBUG - HubCache: Computed '1/music.touring.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' in 116 ms.
Oct 27, 2018 11:56:15.281 [9928] DEBUG - HubCache: Adding '1/music.videos.new.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' to the cache (1/music.videos.new.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1).
Oct 27, 2018 11:56:15.343 [9928] DEBUG - HubCache: Computed '1/music.videos.new.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' in 70 ms.
Oct 27, 2018 11:56:15.365 [3776] DEBUG - Completed: [127.0.0.1:50778] 200 GET /hubs/sections/19?count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1 (26 live) TLS GZIP 7213ms 4503 bytes (pipelined: 4)
Oct 27, 2018 11:56:16.430 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:56:16.430 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:16.430 [7316] DEBUG - Request: [192.168.1.199:57288 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:16.430 [7316] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:56:19.971 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:56:19.971 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:19.971 [8796] DEBUG - Request: [192.168.1.199:57289 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:19.971 [8796] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:56:23.687 [3776] DEBUG - CERT: incomplete TLS handshake: short read
Oct 27, 2018 11:56:29.733 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:29.733 [7316] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (21 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:29.733 [7316] DEBUG - Client [CA59F2C9-6404-464D-9F3A-CD769CA78600] reporting timeline state paused, progress of 1626143/2432546ms for guid=, ratingKey=172774 url=, key=/library/metadata/172774, containerKey=, metadataId=172774
Oct 27, 2018 11:56:29.795 [7316] DEBUG - Play progress on 172774 'Chapter 22 - The Deathly Hallows' - got played 1626143 ms by account 1!
Oct 27, 2018 11:56:29.880 [7316] DEBUG - [Now] User is tubs74 (ID: 1)
Oct 27, 2018 11:56:29.896 [7316] DEBUG - [Now] Device is iOS (iPhone).
Oct 27, 2018 11:56:29.896 [7316] DEBUG - [Now] Profile is iOS
Oct 27, 2018 11:56:29.896 [7316] DEBUG - [Now] Updated play state for /library/metadata/172774.
Oct 27, 2018 11:56:29.896 [7316] DEBUG - HubCache: Expiring '1/music.recent.genre.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' because of event plex.event.play.session.state.update.
Oct 27, 2018 11:56:29.896 [7316] DEBUG - HubCache: Expiring '1/music.top.period.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1' because of event plex.event.play.session.state.update.
Oct 27, 2018 11:56:29.896 [7316] DEBUG - Statistics: (CA59F2C9-6404-464D-9F3A-CD769CA78600) Reporting active playback in state 1 of type 10 (scrobble: 0) for account 1
Oct 27, 2018 11:56:29.918 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:29.918 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:29.918 [8796] DEBUG - Request: [192.168.1.199:57296 (Allowed Network)] GET /status/sessions (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:29.918 [7316] DEBUG - Request: [192.168.1.199:57297 (Allowed Network)] GET /status/sessions (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:29.918 [8796] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:56:29.918 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (23 live) TLS GZIP 190ms 455 bytes (pipelined: 5)
Oct 27, 2018 11:56:29.918 [7316] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:56:29.918 [3788] DEBUG - Completed: [192.168.1.199:57296] 200 GET /status/sessions (23 live) GZIP 5ms 397 bytes (pipelined: 1)
Oct 27, 2018 11:56:29.918 [3788] DEBUG - Completed: [192.168.1.199:57297] 200 GET /status/sessions (23 live) GZIP 4ms 470 bytes (pipelined: 1)
Oct 27, 2018 11:56:35.010 [3788] DEBUG - CERT: incomplete TLS handshake: An established connection was aborted by the software in your host machine
Oct 27, 2018 11:56:36.430 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:56:36.430 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:36.430 [2612] DEBUG - Request: [192.168.1.199:57296 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:36.430 [2612] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:56:38.576 [3788] DEBUG - Request: [86.139.150.227:51377 (WAN)] GET /resources (24 live) GZIP Signed-in
Oct 27, 2018 11:56:38.576 [3776] DEBUG - Request: [86.139.150.227:51378 (WAN)] GET /resources (24 live) GZIP Signed-in
Oct 27, 2018 11:56:38.576 [3776] DEBUG - Completed: [86.139.150.227:51377] 401 GET /resources (25 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:56:38.576 [3788] DEBUG - Completed: [86.139.150.227:51378] 401 GET /resources (25 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:56:38.576 [3788] DEBUG - Request: [86.139.150.227:51382 (WAN)] GET /resources (26 live) GZIP Signed-in
Oct 27, 2018 11:56:38.576 [3788] DEBUG - Completed: [86.139.150.227:51382] 401 GET /resources (26 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:56:38.576 [3776] DEBUG - Request: [86.139.150.227:51383 (WAN)] GET /resources (25 live) GZIP Signed-in
Oct 27, 2018 11:56:38.591 [3776] DEBUG - Completed: [86.139.150.227:51383] 401 GET /resources (25 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:56:39.979 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:56:39.979 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:39.979 [8796] DEBUG - Request: [192.168.1.199:57297 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:39.979 [8796] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:56:49.683 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:49.683 [2612] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (20 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:49.683 [2612] DEBUG - Client [CA59F2C9-6404-464D-9F3A-CD769CA78600] reporting timeline state paused, progress of 1626143/2432546ms for guid=, ratingKey=172774 url=, key=/library/metadata/172774, containerKey=, metadataId=172774
Oct 27, 2018 11:56:49.868 [2612] DEBUG - Play progress on 172774 'Chapter 22 - The Deathly Hallows' - got played 1626143 ms by account 1!
Oct 27, 2018 11:56:50.085 [2612] DEBUG - [Now] User is tubs74 (ID: 1)
Oct 27, 2018 11:56:50.100 [2612] DEBUG - [Now] Device is iOS (iPhone).
Oct 27, 2018 11:56:50.100 [2612] DEBUG - [Now] Profile is iOS
Oct 27, 2018 11:56:50.100 [2612] DEBUG - [Now] Updated play state for /library/metadata/172774.
Oct 27, 2018 11:56:50.100 [2612] DEBUG - Statistics: (CA59F2C9-6404-464D-9F3A-CD769CA78600) Reporting active playback in state 1 of type 10 (scrobble: 0) for account 1
Oct 27, 2018 11:56:50.116 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:50.116 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:50.116 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (22 live) TLS GZIP 432ms 455 bytes (pipelined: 6)
Oct 27, 2018 11:56:50.116 [8796] DEBUG - Request: [192.168.1.199:57305 (Allowed Network)] GET /status/sessions (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:50.116 [2612] DEBUG - Request: [192.168.1.199:57306 (Allowed Network)] GET /status/sessions (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:50.116 [8796] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:56:50.132 [2612] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:56:50.132 [3788] DEBUG - Completed: [192.168.1.199:57305] 200 GET /status/sessions (22 live) GZIP 9ms 397 bytes (pipelined: 1)
Oct 27, 2018 11:56:50.132 [3776] DEBUG - Completed: [192.168.1.199:57306] 200 GET /status/sessions (22 live) GZIP 7ms 470 bytes (pipelined: 1)
Oct 27, 2018 11:56:56.436 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:56:56.436 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:56.436 [7120] DEBUG - Request: [192.168.1.199:57305 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (21 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:56.436 [7120] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:56:57.208 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:57.208 [8796] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /hubs/sections/19?count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1 (21 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:57.208 [8796] DEBUG - HubCache: Adding '1/music.recent.played.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1' to the cache (1/music.recent.played.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1).
Oct 27, 2018 11:56:57.224 [8796] DEBUG - HubCache: Computed '1/music.recent.played.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1' in 1 ms.
Oct 27, 2018 11:56:57.224 [8796] DEBUG - HubCache: Adding '1/music.recent.added.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1' to the cache (1/music.recent.added.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1).
Oct 27, 2018 11:56:57.224 [8796] DEBUG - HubCache: Computed '1/music.recent.added.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1' in 6 ms.
Oct 27, 2018 11:56:57.224 [8796] DEBUG - HubCache: Adding '1/recent.library.playlists.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1' to the cache (1/recent.library.playlists.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1).
Oct 27, 2018 11:56:57.224 [8796] DEBUG - HubCache: Computed '1/recent.library.playlists.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1' in 3 ms.
Oct 27, 2018 11:56:57.224 [8796] DEBUG - HubCache: Adding '1/music.stations.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1' to the cache (1/music.stations.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1).
Oct 27, 2018 11:56:57.224 [8796] DEBUG - HubCache: Computed '1/music.stations.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1' in 0 ms.
Oct 27, 2018 11:56:57.239 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 GET /hubs/sections/19?count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1 (21 live) TLS GZIP 24ms 4140 bytes (pipelined: 7)
Oct 27, 2018 11:56:58.474 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:58.474 [2612] DEBUG - Request: [127.0.0.1:51013 (WAN)] GET /:/eventsource/notifications (22 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:58.612 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:56:58.612 [7120] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /sync/CA59F2C9-6404-464D-9F3A-CD769CA78600/status (22 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:56:58.697 [3776] DEBUG - Completed: [127.0.0.1:50778] 200 GET /sync/CA59F2C9-6404-464D-9F3A-CD769CA78600/status (22 live) TLS GZIP 84ms 1140 bytes (pipelined: 8)
Oct 27, 2018 11:56:59.995 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:57:00.001 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:00.001 [2612] DEBUG - Request: [192.168.1.199:57306 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:00.001 [2612] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:57:02.309 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:02.309 [7120] DEBUG - Request: [127.0.0.1:51014 (WAN)] GET /activities (21 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:02.324 [3788] DEBUG - Completed: [127.0.0.1:51014] 200 GET /activities (21 live) TLS GZIP 7ms 397 bytes (pipelined: 1)
Oct 27, 2018 11:57:02.355 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:02.355 [2612] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /sync/CA59F2C9-6404-464D-9F3A-CD769CA78600/package?changestamp=1639313&limit=25&onlyDeletes=1 (21 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:02.440 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 GET /sync/CA59F2C9-6404-464D-9F3A-CD769CA78600/package?changestamp=1639313&limit=25&onlyDeletes=1 (21 live) TLS GZIP 91ms 454 bytes (pipelined: 9)
Oct 27, 2018 11:57:03.877 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:03.877 [8796] DEBUG - Request: [127.0.0.1:50778 (WAN)] PUT /sync/refreshSynclists (21 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:03.877 [8796] DEBUG - Sync: refreshSyncLists
Oct 27, 2018 11:57:03.877 [8796] DEBUG - HTTP requesting GET https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/sync_lists?auth_token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:57:04.131 [8796] DEBUG - HTTP 200 response from GET https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/sync_lists?auth_token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:57:04.162 [8796] DEBUG - Sync: downloaded 3 sync lists, analyzing now...
Oct 27, 2018 11:57:04.162 [8796] DEBUG - Sync: sync list 26054734: user 1 (tubs74), device Emma’s iPhone, profile iOS, id C3E425F6-5BBD-48D9-808F-6D0ECA92A45C, sync item(s): 28989790,28989793,28989804,28989810
Oct 27, 2018 11:57:04.162 [8796] DEBUG - Sync: sync list 24750675: user 1 (tubs74), device iPhone, profile iOS, id CA59F2C9-6404-464D-9F3A-CD769CA78600, sync item(s): 29255612,29433922,29433930,29433931,29433934
Oct 27, 2018 11:57:04.162 [8796] DEBUG - Sync: sync list 25669848: user 18823418 (Seb), device Seb?s iPhone, profile iOS, id 035146E6-B486-4FE3-AB8B-B6B9D5FAAF75, sync item(s): 30074073,30074170,30074197,30074212,30074237,30115400,30116959,30116965,30168043
Oct 27, 2018 11:57:04.162 [8796] DEBUG - Sync: synchronizing 3 sync lists to generators
Oct 27, 2018 11:57:04.162 [8796] DEBUG - Sync: synchronized 3 sync list(s) to 18 generators
Oct 27, 2018 11:57:04.162 [8796] INFO - Sync: downloaded 3 sync list(s) with 18 sync items(s): 0 new, 0 updated, 0 deleted
Oct 27, 2018 11:57:04.162 [10684] DEBUG - BPQ: garbageCollect - sync - forced - 8
Oct 27, 2018 11:57:04.162 [10684] DEBUG - Sync: starting Sync garbage collection: 8, forced
Oct 27, 2018 11:57:04.162 [10684] DEBUG - Sync: scanning for items to reprocess in sync list 26054734
Oct 27, 2018 11:57:04.178 [10684] DEBUG - Sync: scanned for items to reprocess in sync list 26054734
Oct 27, 2018 11:57:04.178 [10684] DEBUG - Sync: scanning for items to reprocess in sync list 24750675
Oct 27, 2018 11:57:04.178 [3776] DEBUG - Completed: [127.0.0.1:50778] 200 PUT /sync/refreshSynclists (21 live) TLS GZIP 298ms 195 bytes (pipelined: 10)
Oct 27, 2018 11:57:04.178 [10684] DEBUG - Sync: scanned for items to reprocess in sync list 24750675
Oct 27, 2018 11:57:04.178 [10684] DEBUG - Sync: scanning for items to reprocess in sync list 25669848
Oct 27, 2018 11:57:04.178 [10684] DEBUG - Sync: scanned for items to reprocess in sync list 25669848
Oct 27, 2018 11:57:04.178 [10684] DEBUG - Sync: finished Sync garbage collection: 8
Oct 27, 2018 11:57:04.478 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:04.478 [7120] DEBUG - Request: [127.0.0.1:50778 (WAN)] PUT /sync/refreshContent (20 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:04.478 [7120] DEBUG - Sync: refreshContent
Oct 27, 2018 11:57:04.478 [7120] DEBUG - HTTP requesting GET https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/sync_lists?auth_token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:57:04.716 [7120] DEBUG - HTTP 200 response from GET https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/sync_lists?auth_token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:57:04.732 [7120] DEBUG - Sync: downloaded 3 sync lists, analyzing now...
Oct 27, 2018 11:57:04.732 [7120] DEBUG - Sync: sync list 26054734: user 1 (tubs74), device Emma’s iPhone, profile iOS, id C3E425F6-5BBD-48D9-808F-6D0ECA92A45C, sync item(s): 28989790,28989793,28989804,28989810
Oct 27, 2018 11:57:04.732 [7120] DEBUG - Sync: sync list 24750675: user 1 (tubs74), device iPhone, profile iOS, id CA59F2C9-6404-464D-9F3A-CD769CA78600, sync item(s): 29255612,29433922,29433930,29433931,29433934
Oct 27, 2018 11:57:04.732 [7120] DEBUG - Sync: sync list 25669848: user 18823418 (Seb), device Seb?s iPhone, profile iOS, id 035146E6-B486-4FE3-AB8B-B6B9D5FAAF75, sync item(s): 30074073,30074170,30074197,30074212,30074237,30115400,30116959,30116965,30168043
Oct 27, 2018 11:57:04.732 [7120] DEBUG - Sync: synchronizing 3 sync lists to generators
Oct 27, 2018 11:57:04.748 [7120] DEBUG - Sync: synchronized 3 sync list(s) to 18 generators
Oct 27, 2018 11:57:04.748 [10684] DEBUG - BPQ: garbageCollect - sync - forced - 8
Oct 27, 2018 11:57:04.748 [7120] INFO - Sync: downloaded 3 sync list(s) with 18 sync items(s): 0 new, 0 updated, 0 deleted
Oct 27, 2018 11:57:04.748 [10684] DEBUG - Sync: starting Sync garbage collection: 8, forced
Oct 27, 2018 11:57:04.748 [10684] DEBUG - Sync: scanning for items to reprocess in sync list 26054734
Oct 27, 2018 11:57:04.748 [10684] DEBUG - Sync: scanned for items to reprocess in sync list 26054734
Oct 27, 2018 11:57:04.748 [10684] DEBUG - Sync: scanning for items to reprocess in sync list 24750675
Oct 27, 2018 11:57:04.748 [10684] DEBUG - Sync: scanned for items to reprocess in sync list 24750675
Oct 27, 2018 11:57:04.748 [10684] DEBUG - Sync: scanning for items to reprocess in sync list 25669848
Oct 27, 2018 11:57:04.748 [10684] DEBUG - Sync: scanned for items to reprocess in sync list 25669848
Oct 27, 2018 11:57:04.748 [3776] DEBUG - Completed: [127.0.0.1:50778] 200 PUT /sync/refreshContent (20 live) TLS GZIP 270ms 195 bytes (pipelined: 11)
Oct 27, 2018 11:57:04.748 [10684] DEBUG - Sync: finished Sync garbage collection: 8
Oct 27, 2018 11:57:09.711 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:09.711 [2612] DEBUG - Request: [127.0.0.1:51014 (WAN)] GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (22 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:09.711 [2612] DEBUG - Client [CA59F2C9-6404-464D-9F3A-CD769CA78600] reporting timeline state paused, progress of 1626143/2432546ms for guid=, ratingKey=172774 url=, key=/library/metadata/172774, containerKey=, metadataId=172774
Oct 27, 2018 11:57:09.833 [2612] DEBUG - Play progress on 172774 'Chapter 22 - The Deathly Hallows' - got played 1626143 ms by account 1!
Oct 27, 2018 11:57:09.965 [2612] DEBUG - [Now] User is tubs74 (ID: 1)
Oct 27, 2018 11:57:09.965 [2612] DEBUG - [Now] Device is iOS (iPhone).
Oct 27, 2018 11:57:09.965 [2612] DEBUG - [Now] Profile is iOS
Oct 27, 2018 11:57:09.965 [2612] DEBUG - [Now] Updated play state for /library/metadata/172774.
Oct 27, 2018 11:57:09.965 [2612] DEBUG - HubCache: Expiring '1/music.recent.played.19/1/hubs/sections/19/en-GB;q=1/count=50&includeCollections=1&includeLibraryPlaylists=1&includeStations=1&includeTrailers=1&includeTypeFirst=1&onlyTransient=1' because of event plex.event.play.session.state.update.
Oct 27, 2018 11:57:09.965 [3776] DEBUG - handleStreamWrite code 10053: An established connection was aborted by the software in your host machine
Oct 27, 2018 11:57:09.965 [3776] DEBUG - NotificationStream: Removing because of error
Oct 27, 2018 11:57:09.965 [2612] DEBUG - Statistics: (CA59F2C9-6404-464D-9F3A-CD769CA78600) Reporting active playback in state 1 of type 10 (scrobble: 0) for account 1
Oct 27, 2018 11:57:09.980 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:09.980 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:09.980 [7120] DEBUG - Request: [192.168.1.199:57309 (Allowed Network)] GET /status/sessions (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:09.980 [3788] DEBUG - Completed: [127.0.0.1:51014] 200 GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (23 live) TLS GZIP 261ms 455 bytes (pipelined: 2)
Oct 27, 2018 11:57:09.980 [8796] DEBUG - Request: [192.168.1.199:57308 (Allowed Network)] GET /status/sessions (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:09.980 [7120] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:57:09.980 [8796] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:57:09.980 [3788] DEBUG - Completed: [192.168.1.199:57309] 200 GET /status/sessions (23 live) GZIP 4ms 470 bytes (pipelined: 1)
Oct 27, 2018 11:57:09.980 [3776] DEBUG - Completed: [192.168.1.199:57308] 200 GET /status/sessions (23 live) GZIP 6ms 397 bytes (pipelined: 1)
Oct 27, 2018 11:57:11.840 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:11.840 [2612] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /sync/CA59F2C9-6404-464D-9F3A-CD769CA78600/status (23 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:11.872 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 GET /sync/CA59F2C9-6404-464D-9F3A-CD769CA78600/status (23 live) TLS GZIP 19ms 1140 bytes (pipelined: 12)
Oct 27, 2018 11:57:12.474 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:12.474 [7120] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /sync/CA59F2C9-6404-464D-9F3A-CD769CA78600/package?changestamp=1639313&limit=25 (23 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:12.505 [7120] DEBUG - Sync: packaging update at 1639402 for sync list 24750675, metadata item 172774: MetadataItemSettings
Oct 27, 2018 11:57:12.606 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 GET /sync/CA59F2C9-6404-464D-9F3A-CD769CA78600/package?changestamp=1639313&limit=25 (23 live) TLS GZIP 141ms 646 bytes (pipelined: 13)
Oct 27, 2018 11:57:16.447 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:57:16.454 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:16.454 [8796] DEBUG - Request: [192.168.1.199:57308 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (20 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:16.454 [8796] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:57:18.006 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:18.006 [7120] DEBUG - Request: [127.0.0.1:50778 (WAN)] PUT /sync/CA59F2C9-6404-464D-9F3A-CD769CA78600/package?changestamp=1639402 (18 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:18.006 [7120] DEBUG - Sync: acknowledgeChangestamp for sync list 24750675: 1639402
Oct 27, 2018 11:57:18.106 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 PUT /sync/CA59F2C9-6404-464D-9F3A-CD769CA78600/package?changestamp=1639402 (18 live) TLS GZIP 98ms 397 bytes (pipelined: 14)
Oct 27, 2018 11:57:19.142 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:19.142 [2612] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /sync/transcodeQueue (18 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:19.180 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 GET /sync/transcodeQueue (18 live) TLS GZIP 32ms 397 bytes (pipelined: 15)
Oct 27, 2018 11:57:20.029 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:57:20.029 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:20.029 [8796] DEBUG - Request: [192.168.1.199:57309 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (17 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:20.029 [8796] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:57:29.699 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:29.699 [2612] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (22 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:29.699 [2612] DEBUG - Client [CA59F2C9-6404-464D-9F3A-CD769CA78600] reporting timeline state paused, progress of 1626143/2432546ms for guid=, ratingKey=172774 url=, key=/library/metadata/172774, containerKey=, metadataId=172774
Oct 27, 2018 11:57:29.783 [2612] DEBUG - Play progress on 172774 'Chapter 22 - The Deathly Hallows' - got played 1626143 ms by account 1!
Oct 27, 2018 11:57:29.868 [2612] DEBUG - [Now] User is tubs74 (ID: 1)
Oct 27, 2018 11:57:29.868 [2612] DEBUG - [Now] Device is iOS (iPhone).
Oct 27, 2018 11:57:29.868 [2612] DEBUG - [Now] Profile is iOS
Oct 27, 2018 11:57:29.868 [2612] DEBUG - [Now] Updated play state for /library/metadata/172774.
Oct 27, 2018 11:57:29.868 [2612] DEBUG - Statistics: (CA59F2C9-6404-464D-9F3A-CD769CA78600) Reporting active playback in state 1 of type 10 (scrobble: 0) for account 1
Oct 27, 2018 11:57:29.884 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:29.884 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:29.899 [8796] DEBUG - Request: [192.168.1.199:57312 (Allowed Network)] GET /status/sessions (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:29.899 [2612] DEBUG - Request: [192.168.1.199:57313 (Allowed Network)] GET /status/sessions (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:29.899 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (24 live) TLS GZIP 193ms 455 bytes (pipelined: 16)
Oct 27, 2018 11:57:29.899 [8796] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:57:29.899 [2612] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:57:29.899 [3788] DEBUG - Completed: [192.168.1.199:57312] 200 GET /status/sessions (24 live) GZIP 7ms 397 bytes (pipelined: 1)
Oct 27, 2018 11:57:29.899 [3776] DEBUG - Completed: [192.168.1.199:57313] 200 GET /status/sessions (24 live) GZIP 4ms 470 bytes (pipelined: 1)
Oct 27, 2018 11:57:36.456 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:57:36.456 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:36.471 [2056] DEBUG - Request: [192.168.1.199:57312 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:36.471 [2056] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:57:40.037 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:57:40.052 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:40.052 [8796] DEBUG - Request: [192.168.1.199:57313 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:40.052 [8796] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:57:49.694 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:49.710 [2056] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (23 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:49.710 [2056] DEBUG - Client [CA59F2C9-6404-464D-9F3A-CD769CA78600] reporting timeline state paused, progress of 1626143/2432546ms for guid=, ratingKey=172774 url=, key=/library/metadata/172774, containerKey=, metadataId=172774
Oct 27, 2018 11:57:49.848 [2056] DEBUG - Play progress on 172774 'Chapter 22 - The Deathly Hallows' - got played 1626143 ms by account 1!
Oct 27, 2018 11:57:49.926 [2056] DEBUG - [Now] User is tubs74 (ID: 1)
Oct 27, 2018 11:57:49.932 [2056] DEBUG - [Now] Device is iOS (iPhone).
Oct 27, 2018 11:57:49.932 [2056] DEBUG - [Now] Profile is iOS
Oct 27, 2018 11:57:49.932 [2056] DEBUG - [Now] Updated play state for /library/metadata/172774.
Oct 27, 2018 11:57:49.948 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:49.948 [8796] DEBUG - Request: [192.168.1.199:57316 (Allowed Network)] GET /status/sessions (25 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:49.948 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:49.948 [10708] DEBUG - Request: [192.168.1.199:57317 (Allowed Network)] GET /status/sessions (25 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:49.979 [2056] DEBUG - Statistics: (CA59F2C9-6404-464D-9F3A-CD769CA78600) Reporting active playback in state 1 of type 10 (scrobble: 0) for account 1
Oct 27, 2018 11:57:49.979 [8796] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:57:49.979 [10708] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:57:49.979 [3788] DEBUG - Completed: [192.168.1.199:57316] 200 GET /status/sessions (25 live) GZIP 29ms 397 bytes (pipelined: 1)
Oct 27, 2018 11:57:49.979 [3776] DEBUG - Completed: [192.168.1.199:57317] 200 GET /status/sessions (25 live) GZIP 28ms 470 bytes (pipelined: 1)
Oct 27, 2018 11:57:49.995 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (25 live) TLS GZIP 292ms 455 bytes (pipelined: 17)
Oct 27, 2018 11:57:56.475 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:57:56.475 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:57:56.491 [10696] DEBUG - Request: [192.168.1.199:57316 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (26 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:57:56.491 [10696] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:58:00.055 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:58:00.055 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:58:00.055 [8796] DEBUG - Request: [192.168.1.199:57317 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:58:00.055 [8796] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:58:00.510 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:58:00.510 [10696] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /sync/CA59F2C9-6404-464D-9F3A-CD769CA78600/status (24 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:58:00.526 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 GET /sync/CA59F2C9-6404-464D-9F3A-CD769CA78600/status (24 live) TLS GZIP 19ms 1140 bytes (pipelined: 18)
Oct 27, 2018 11:58:01.059 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:58:01.059 [8796] DEBUG - Request: [127.0.0.1:50778 (WAN)] PUT /sync/refreshSynclists (23 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:58:01.059 [8796] DEBUG - Sync: refreshSyncLists
Oct 27, 2018 11:58:01.059 [8796] DEBUG - HTTP requesting GET https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/sync_lists?auth_token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:58:01.281 [8796] DEBUG - HTTP 200 response from GET https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/sync_lists?auth_token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:58:01.313 [8796] DEBUG - Sync: downloaded 3 sync lists, analyzing now...
Oct 27, 2018 11:58:01.313 [8796] DEBUG - Sync: sync list 26054734: user 1 (tubs74), device Emma’s iPhone, profile iOS, id C3E425F6-5BBD-48D9-808F-6D0ECA92A45C, sync item(s): 28989790,28989793,28989804,28989810
Oct 27, 2018 11:58:01.313 [8796] DEBUG - Sync: sync list 24750675: user 1 (tubs74), device iPhone, profile iOS, id CA59F2C9-6404-464D-9F3A-CD769CA78600, sync item(s): 29255612,29433922,29433930,29433931,29433934
Oct 27, 2018 11:58:01.313 [8796] DEBUG - Sync: sync list 25669848: user 18823418 (Seb), device Seb?s iPhone, profile iOS, id 035146E6-B486-4FE3-AB8B-B6B9D5FAAF75, sync item(s): 30074073,30074170,30074197,30074212,30074237,30115400,30116959,30116965,30168043
Oct 27, 2018 11:58:01.313 [8796] DEBUG - Sync: synchronizing 3 sync lists to generators
Oct 27, 2018 11:58:01.313 [8796] DEBUG - Sync: synchronized 3 sync list(s) to 18 generators
Oct 27, 2018 11:58:01.313 [8796] INFO - Sync: downloaded 3 sync list(s) with 18 sync items(s): 0 new, 0 updated, 0 deleted
Oct 27, 2018 11:58:01.313 [10832] DEBUG - BPQ: garbageCollect - sync - forced - 8
Oct 27, 2018 11:58:01.313 [10832] DEBUG - Sync: starting Sync garbage collection: 8, forced
Oct 27, 2018 11:58:01.313 [10832] DEBUG - Sync: scanning for items to reprocess in sync list 26054734
Oct 27, 2018 11:58:01.313 [10832] DEBUG - Sync: scanned for items to reprocess in sync list 26054734
Oct 27, 2018 11:58:01.313 [10832] DEBUG - Sync: scanning for items to reprocess in sync list 24750675
Oct 27, 2018 11:58:01.313 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 PUT /sync/refreshSynclists (23 live) TLS GZIP 263ms 195 bytes (pipelined: 19)
Oct 27, 2018 11:58:01.313 [10832] DEBUG - Sync: scanned for items to reprocess in sync list 24750675
Oct 27, 2018 11:58:01.313 [10832] DEBUG - Sync: scanning for items to reprocess in sync list 25669848
Oct 27, 2018 11:58:01.313 [10832] DEBUG - Sync: scanned for items to reprocess in sync list 25669848
Oct 27, 2018 11:58:01.313 [10832] DEBUG - Sync: finished Sync garbage collection: 8
Oct 27, 2018 11:58:01.413 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:58:01.413 [10696] DEBUG - Request: [127.0.0.1:50778 (WAN)] PUT /sync/refreshContent (21 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:58:01.413 [10696] DEBUG - Sync: refreshContent
Oct 27, 2018 11:58:01.413 [10696] DEBUG - HTTP requesting GET https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/sync_lists?auth_token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:58:01.630 [10696] DEBUG - HTTP 200 response from GET https://plex.tv/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/sync_lists?auth_token=xxxxxxxxxxxxxxxxxxxx
Oct 27, 2018 11:58:01.645 [10696] DEBUG - Sync: downloaded 3 sync lists, analyzing now...
Oct 27, 2018 11:58:01.645 [10696] DEBUG - Sync: sync list 26054734: user 1 (tubs74), device Emma’s iPhone, profile iOS, id C3E425F6-5BBD-48D9-808F-6D0ECA92A45C, sync item(s): 28989790,28989793,28989804,28989810
Oct 27, 2018 11:58:01.645 [10696] DEBUG - Sync: sync list 24750675: user 1 (tubs74), device iPhone, profile iOS, id CA59F2C9-6404-464D-9F3A-CD769CA78600, sync item(s): 29255612,29433922,29433930,29433931,29433934
Oct 27, 2018 11:58:01.645 [10696] DEBUG - Sync: sync list 25669848: user 18823418 (Seb), device Seb?s iPhone, profile iOS, id 035146E6-B486-4FE3-AB8B-B6B9D5FAAF75, sync item(s): 30074073,30074170,30074197,30074212,30074237,30115400,30116959,30116965,30168043
Oct 27, 2018 11:58:01.645 [10696] DEBUG - Sync: synchronizing 3 sync lists to generators
Oct 27, 2018 11:58:01.661 [10696] DEBUG - Sync: synchronized 3 sync list(s) to 18 generators
Oct 27, 2018 11:58:01.661 [10832] DEBUG - BPQ: garbageCollect - sync - forced - 8
Oct 27, 2018 11:58:01.661 [10696] INFO - Sync: downloaded 3 sync list(s) with 18 sync items(s): 0 new, 0 updated, 0 deleted
Oct 27, 2018 11:58:01.661 [10832] DEBUG - Sync: starting Sync garbage collection: 8, forced
Oct 27, 2018 11:58:01.661 [10832] DEBUG - Sync: scanning for items to reprocess in sync list 26054734
Oct 27, 2018 11:58:01.677 [10832] DEBUG - Sync: scanned for items to reprocess in sync list 26054734
Oct 27, 2018 11:58:01.677 [10832] DEBUG - Sync: scanning for items to reprocess in sync list 24750675
Oct 27, 2018 11:58:01.677 [10832] DEBUG - Sync: scanned for items to reprocess in sync list 24750675
Oct 27, 2018 11:58:01.677 [10832] DEBUG - Sync: scanning for items to reprocess in sync list 25669848
Oct 27, 2018 11:58:01.677 [3788] DEBUG - Completed: [127.0.0.1:50778] 200 PUT /sync/refreshContent (21 live) TLS GZIP 259ms 195 bytes (pipelined: 20)
Oct 27, 2018 11:58:01.677 [10832] DEBUG - Sync: scanned for items to reprocess in sync list 25669848
Oct 27, 2018 11:58:01.677 [10832] DEBUG - Sync: finished Sync garbage collection: 8
Oct 27, 2018 11:58:09.697 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:58:09.697 [8796] DEBUG - Request: [127.0.0.1:50778 (WAN)] GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (20 live) TLS GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:58:09.697 [8796] DEBUG - Client [CA59F2C9-6404-464D-9F3A-CD769CA78600] reporting timeline state paused, progress of 1626143/2432546ms for guid=, ratingKey=172774 url=, key=/library/metadata/172774, containerKey=, metadataId=172774
Oct 27, 2018 11:58:09.766 [8796] DEBUG - Play progress on 172774 'Chapter 22 - The Deathly Hallows' - got played 1626143 ms by account 1!
Oct 27, 2018 11:58:09.820 [8796] DEBUG - [Now] User is tubs74 (ID: 1)
Oct 27, 2018 11:58:09.820 [8796] DEBUG - [Now] Device is iOS (iPhone).
Oct 27, 2018 11:58:09.820 [8796] DEBUG - [Now] Profile is iOS
Oct 27, 2018 11:58:09.820 [8796] DEBUG - [Now] Updated play state for /library/metadata/172774.
Oct 27, 2018 11:58:09.820 [8796] DEBUG - Statistics: (CA59F2C9-6404-464D-9F3A-CD769CA78600) Reporting active playback in state 1 of type 10 (scrobble: 0) for account 1
Oct 27, 2018 11:58:09.835 [3776] DEBUG - Completed: [127.0.0.1:50778] 200 GET /:/timeline?bufferedTime=0&duration=2432546&key=%2Flibrary%2Fmetadata%2F172774&location=wan&playQueueItemID=40181&playbackTime=0&ratingKey=172774&state=paused&time=1626143 (20 live) TLS GZIP 136ms 455 bytes (pipelined: 21)
Oct 27, 2018 11:58:09.835 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:58:09.835 [10696] DEBUG - Request: [192.168.1.199:57319 (Allowed Network)] GET /status/sessions (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:58:09.835 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:58:09.851 [10696] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:58:09.851 [8796] DEBUG - Request: [192.168.1.199:57320 (Allowed Network)] GET /status/sessions (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:58:09.851 [8796] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:58:09.851 [3788] DEBUG - Completed: [192.168.1.199:57319] 200 GET /status/sessions (22 live) GZIP 4ms 397 bytes (pipelined: 1)
Oct 27, 2018 11:58:09.851 [3788] DEBUG - Completed: [192.168.1.199:57320] 200 GET /status/sessions (22 live) GZIP 4ms 470 bytes (pipelined: 1)
Oct 27, 2018 11:58:16.505 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:58:16.505 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:58:16.505 [9080] DEBUG - Request: [192.168.1.199:57319 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (21 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:58:16.520 [9080] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:58:17.926 [3776] DEBUG - Request: [86.139.150.227:51422 (WAN)] GET /resources (26 live) GZIP Signed-in
Oct 27, 2018 11:58:17.926 [3788] DEBUG - Request: [86.139.150.227:51426 (WAN)] GET /resources (26 live) GZIP Signed-in
Oct 27, 2018 11:58:17.926 [3776] DEBUG - Completed: [86.139.150.227:51422] 401 GET /resources (27 live) GZIP 1ms 338 bytes
Oct 27, 2018 11:58:17.926 [3776] DEBUG - Completed: [86.139.150.227:51426] 401 GET /resources (29 live) GZIP 1ms 338 bytes
Oct 27, 2018 11:58:20.071 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:58:20.071 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:58:20.071 [10696] DEBUG - Request: [192.168.1.199:57320 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:58:20.071 [10696] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:58:28.178 [3844] WARN - SLOW QUERY: It took 265.625000 ms to retrieve 0 items.
Oct 27, 2018 11:58:36.529 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:58:36.529 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:58:36.529 [9080] DEBUG - Request: [192.168.1.199:57324 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:58:36.544 [9080] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:58:40.081 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:58:40.097 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:58:40.097 [7112] DEBUG - Request: [192.168.1.199:57325 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:58:40.097 [7112] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:58:48.566 [3788] DEBUG - handleStreamWrite code 10053: An established connection was aborted by the software in your host machine
Oct 27, 2018 11:58:48.566 [3788] DEBUG - NotificationStream: Removing because of error
Oct 27, 2018 11:58:50.358 [3776] DEBUG - Request: [86.139.150.227:51439 (WAN)] GET /resources (21 live) GZIP Signed-in
Oct 27, 2018 11:58:50.358 [3788] DEBUG - Completed: [86.139.150.227:51439] 401 GET /resources (21 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:58:55.397 [3776] DEBUG - Request: [86.139.150.227:51451 (WAN)] GET /resources (33 live) GZIP Signed-in
Oct 27, 2018 11:58:55.397 [3788] DEBUG - Completed: [86.139.150.227:51451] 401 GET /resources (33 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:58:55.899 [3788] DEBUG - Request: [86.139.150.227:51454 (WAN)] GET /resources (34 live) GZIP Signed-in
Oct 27, 2018 11:58:55.899 [3776] DEBUG - Completed: [86.139.150.227:51454] 401 GET /resources (34 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:58:56.533 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:58:56.539 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:58:56.539 [9080] DEBUG - Request: [192.168.1.199:57327 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (34 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:58:56.539 [9080] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:58:56.904 [3788] DEBUG - Request: [86.139.150.227:51455 (WAN)] GET /resources (32 live) GZIP Signed-in
Oct 27, 2018 11:58:56.904 [3776] DEBUG - Request: [86.139.150.227:51456 (WAN)] GET /resources (32 live) GZIP Signed-in
Oct 27, 2018 11:58:56.904 [3788] DEBUG - Completed: [86.139.150.227:51455] 401 GET /resources (32 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:58:56.904 [3776] DEBUG - Completed: [86.139.150.227:51456] 401 GET /resources (31 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:58:57.507 [3788] DEBUG - Request: [86.139.150.227:51458 (WAN)] GET /resources (33 live) GZIP Signed-in
Oct 27, 2018 11:58:57.507 [3776] DEBUG - Request: [86.139.150.227:51457 (WAN)] GET /resources (33 live) GZIP Signed-in
Oct 27, 2018 11:58:57.522 [3788] DEBUG - Completed: [86.139.150.227:51458] 401 GET /resources (33 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:58:57.522 [3776] DEBUG - Completed: [86.139.150.227:51457] 401 GET /resources (33 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:58:57.845 [3788] DEBUG - Request: [86.139.150.227:51463 (WAN)] GET /resources (35 live) GZIP Signed-in
Oct 27, 2018 11:58:57.845 [3776] DEBUG - Completed: [86.139.150.227:51463] 401 GET /resources (35 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:58:58.850 [3788] DEBUG - Request: [86.139.150.227:51466 (WAN)] GET /resources (36 live) GZIP Signed-in
Oct 27, 2018 11:58:58.850 [3776] DEBUG - Request: [86.139.150.227:51465 (WAN)] GET /resources (36 live) GZIP Signed-in
Oct 27, 2018 11:58:58.850 [3788] DEBUG - Completed: [86.139.150.227:51466] 401 GET /resources (36 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:58:58.850 [3776] DEBUG - Completed: [86.139.150.227:51465] 401 GET /resources (36 live) GZIP 0ms 338 bytes
Oct 27, 2018 11:58:59.902 [10452] DEBUG - [PlexRelay] Transferred: sent 15256, received 5856 bytes, in 323.9 seconds
Oct 27, 2018 11:58:59.902 [9080] DEBUG - [PlexRelay] Bytes per second: sent 47.1, received 18.1
Oct 27, 2018 11:58:59.917 [3920] DEBUG - Jobs: 'C:\Program Files (x86)\Plex\Plex Media Server\PlexRelay.exe' exit code for process 6708 is 255 (failure)
Oct 27, 2018 11:59:00.103 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:59:00.103 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:00.103 [10452] DEBUG - Request: [192.168.1.199:57328 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (37 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:00.118 [10452] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:59:16.543 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:59:16.543 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:16.543 [9080] DEBUG - Request: [192.168.1.199:57339 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (37 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:16.543 [9080] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:59:20.106 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:59:20.106 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:20.122 [2612] DEBUG - Request: [192.168.1.199:57341 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (35 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:20.122 [2612] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:59:36.545 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:59:36.557 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:36.558 [9080] DEBUG - Request: [192.168.1.199:57346 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:36.559 [9080] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:59:40.137 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:59:40.137 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:40.152 [11892] DEBUG - Request: [192.168.1.199:57347 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (17 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:40.152 [11892] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:59:42.331 [9080] DEBUG - Request: [192.168.1.146:51730 (Allowed Network)] GET /web/index.html (20 live) GZIP Signed-in
Oct 27, 2018 11:59:42.332 [9080] DEBUG - Final path: "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\index.html"
Oct 27, 2018 11:59:42.333 [9080] DEBUG - Content-Length of C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\index.html is 9330.
Oct 27, 2018 11:59:42.334 [3788] DEBUG - Completed: [192.168.1.146:51730] 200 GET /web/index.html (20 live) GZIP 3ms 9330 bytes (pipelined: 1)
Oct 27, 2018 11:59:42.535 [11892] DEBUG - Request: [192.168.1.146:51730 (Allowed Network)] GET /web/main.v3.283be5c01ff8c07b4804ab49d28656a0.css (21 live) GZIP Signed-in
Oct 27, 2018 11:59:42.535 [9080] DEBUG - Request: [192.168.1.146:51731 (Allowed Network)] GET /web/main.41148bad7397de5c0c8c0808d352b6ce.css (21 live) GZIP Signed-in
Oct 27, 2018 11:59:42.536 [11892] DEBUG - Final path: "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\main.v3.283be5c01ff8c07b4804ab49d28656a0.css"
Oct 27, 2018 11:59:42.536 [9080] DEBUG - Final path: "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\main.41148bad7397de5c0c8c0808d352b6ce.css"
Oct 27, 2018 11:59:42.537 [11892] DEBUG - Content-Length of C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\main.v3.283be5c01ff8c07b4804ab49d28656a0.css is 264668.
Oct 27, 2018 11:59:42.538 [12092] DEBUG - Request: [192.168.1.146:51741 (Allowed Network)] GET /web/js/vendors-2-b7a919cdc391f9ae02b7-plex-3.67.1-f20e61c.js (21 live) GZIP Signed-in
Oct 27, 2018 11:59:42.538 [9080] DEBUG - Content-Length of C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\main.41148bad7397de5c0c8c0808d352b6ce.css is 760328.
Oct 27, 2018 11:59:42.539 [12092] DEBUG - Final path: "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\js\vendors-2-b7a919cdc391f9ae02b7-plex-3.67.1-f20e61c.js"
Oct 27, 2018 11:59:42.542 [12092] DEBUG - Content-Length of C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\js\vendors-2-b7a919cdc391f9ae02b7-plex-3.67.1-f20e61c.js is 304503.
Oct 27, 2018 11:59:42.545 [3776] DEBUG - Completed: [192.168.1.146:51730] 200 GET /web/main.v3.283be5c01ff8c07b4804ab49d28656a0.css (21 live) GZIP 10ms 264668 bytes (pipelined: 2)
Oct 27, 2018 11:59:42.550 [3788] DEBUG - Completed: [192.168.1.146:51731] 200 GET /web/main.41148bad7397de5c0c8c0808d352b6ce.css (21 live) GZIP 14ms 760328 bytes (pipelined: 1)
Oct 27, 2018 11:59:42.551 [3776] DEBUG - Completed: [192.168.1.146:51741] 200 GET /web/js/vendors-2-b7a919cdc391f9ae02b7-plex-3.67.1-f20e61c.js (21 live) GZIP 13ms 304503 bytes (pipelined: 1)
Oct 27, 2018 11:59:42.581 [12096] DEBUG - Request: [192.168.1.146:51730 (Allowed Network)] GET /web/js/main-1-fa80bcd42150aaf7134d-plex-3.67.1-f20e61c.js (21 live) GZIP Signed-in
Oct 27, 2018 11:59:42.582 [12096] DEBUG - Final path: "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\js\main-1-fa80bcd42150aaf7134d-plex-3.67.1-f20e61c.js"
Oct 27, 2018 11:59:42.585 [12096] DEBUG - Content-Length of C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\js\main-1-fa80bcd42150aaf7134d-plex-3.67.1-f20e61c.js is 3765512.
Oct 27, 2018 11:59:43.052 [3776] DEBUG - Completed: [192.168.1.146:51730] 200 GET /web/js/main-1-fa80bcd42150aaf7134d-plex-3.67.1-f20e61c.js (21 live) GZIP 472ms 3765512 bytes (pipelined: 3)
Oct 27, 2018 11:59:44.428 [9080] DEBUG - Request: [192.168.1.146:51730 (Allowed Network)] GET /web/translations/en.json (18 live) GZIP Signed-in
Oct 27, 2018 11:59:44.429 [9080] DEBUG - Final path: "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\translations\en.json"
Oct 27, 2018 11:59:44.430 [9080] DEBUG - Content-Length of C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\translations\en.json is 2.
Oct 27, 2018 11:59:44.431 [3776] DEBUG - Completed: [192.168.1.146:51730] 200 GET /web/translations/en.json (18 live) GZIP 3ms 2 bytes (pipelined: 4)
Oct 27, 2018 11:59:44.495 [12096] DEBUG - Request: [192.168.1.146:51731 (Allowed Network)] GET /web/common/img/backgrounds/preset-dark.64cc1c942221cd2c153244bd8ecfb67a.png (18 live) GZIP Signed-in
Oct 27, 2018 11:59:44.495 [12092] DEBUG - Request: [192.168.1.146:51741 (Allowed Network)] GET /web/common/img/backgrounds/noise.8b05ce45d0df59343e206bc9ae78d85d.png (18 live) GZIP Signed-in
Oct 27, 2018 11:59:44.496 [12092] DEBUG - Final path: "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\common\img\backgrounds\noise.8b05ce45d0df59343e206bc9ae78d85d.png"
Oct 27, 2018 11:59:44.496 [12096] DEBUG - Final path: "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\common\img\backgrounds\preset-dark.64cc1c942221cd2c153244bd8ecfb67a.png"
Oct 27, 2018 11:59:44.497 [12092] DEBUG - Content-Length of C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\common\img\backgrounds\noise.8b05ce45d0df59343e206bc9ae78d85d.png is 54413.
Oct 27, 2018 11:59:44.498 [12096] DEBUG - Content-Length of C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\common\img\backgrounds\preset-dark.64cc1c942221cd2c153244bd8ecfb67a.png is 31365.
Oct 27, 2018 11:59:44.499 [3788] DEBUG - Completed: [192.168.1.146:51741] 200 GET /web/common/img/backgrounds/noise.8b05ce45d0df59343e206bc9ae78d85d.png (18 live) GZIP 4ms 54413 bytes (pipelined: 2)
Oct 27, 2018 11:59:44.499 [3776] DEBUG - Completed: [192.168.1.146:51731] 200 GET /web/common/img/backgrounds/preset-dark.64cc1c942221cd2c153244bd8ecfb67a.png (18 live) GZIP 4ms 31365 bytes (pipelined: 2)
Oct 27, 2018 11:59:44.775 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:44.776 [11892] DEBUG - Request: [127.0.0.1:51804 (Loopback)] GET / (20 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:44.779 [11892] DEBUG - (Capabilities) Platform 'Chrome' not matched by plugin platform requirements
Oct 27, 2018 11:59:44.782 [3788] DEBUG - Completed: [127.0.0.1:51804] 200 GET / (20 live) GZIP 6ms 2549 bytes (pipelined: 1)
Oct 27, 2018 11:59:44.799 [3788] DEBUG - Request: [127.0.0.1:51804 (Loopback)] GET / (20 live) GZIP Signed-in
Oct 27, 2018 11:59:44.801 [3776] DEBUG - Completed: [127.0.0.1:51804] 401 GET / (20 live) GZIP 0ms 489 bytes (pipelined: 2)
Oct 27, 2018 11:59:44.802 [9080] DEBUG - Request: [192.168.1.146:51731 (Allowed Network)] GET / (20 live) GZIP Signed-in
Oct 27, 2018 11:59:44.805 [9080] DEBUG - (Capabilities) Platform 'Chrome' not matched by plugin platform requirements
Oct 27, 2018 11:59:44.808 [3788] DEBUG - Completed: [192.168.1.146:51731] 200 GET / (20 live) GZIP 7ms 2421 bytes (pipelined: 3)
Oct 27, 2018 11:59:44.934 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:44.936 [12096] DEBUG - Request: [127.0.0.1:51806 (Loopback)] GET /:/websockets/notifications (21 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:44.937 [12096] DEBUG - WebSocket: Performing handshake from origin http://juno:32400
Oct 27, 2018 11:59:44.938 [12096] DEBUG - Beginning read from WebSocket
Oct 27, 2018 11:59:44.958 [11892] DEBUG - Request: [127.0.0.1:51804 (Loopback)] GET /identity (21 live) GZIP Signed-in
Oct 27, 2018 11:59:44.960 [3776] DEBUG - Completed: [127.0.0.1:51804] 200 GET /identity (21 live) GZIP 1ms 544 bytes (pipelined: 3)
Oct 27, 2018 11:59:44.996 [3776] DEBUG - WebSocket: client initiated close
Oct 27, 2018 11:59:44.997 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:59:44.997 [3788] DEBUG - NotificationStream: Removing because of error
Oct 27, 2018 11:59:45.002 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:45.003 [12092] DEBUG - Request: [127.0.0.1:51807 (Loopback)] GET /:/websockets/notifications (21 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:45.004 [12092] DEBUG - WebSocket: Performing handshake from origin http://juno:32400
Oct 27, 2018 11:59:45.005 [12092] DEBUG - Beginning read from WebSocket
Oct 27, 2018 11:59:45.028 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:45.029 [12096] DEBUG - Request: [127.0.0.1:51804 (Loopback)] GET /:/prefs (21 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:45.031 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:45.033 [11892] DEBUG - Request: [127.0.0.1:51808 (Loopback)] GET /status/sessions (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:45.034 [11892] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:59:45.035 [3788] DEBUG - Completed: [127.0.0.1:51808] 200 GET /status/sessions (22 live) GZIP 2ms 470 bytes (pipelined: 1)
Oct 27, 2018 11:59:45.042 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:45.044 [9080] DEBUG - Request: [127.0.0.1:51808 (Loopback)] GET /updater/status (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:45.046 [3776] DEBUG - Completed: [127.0.0.1:51808] 200 GET /updater/status (22 live) GZIP 3ms 528 bytes (pipelined: 2)
Oct 27, 2018 11:59:45.063 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:45.064 [12092] DEBUG - Request: [192.168.1.146:51731 (Allowed Network)] GET / (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:45.073 [9080] DEBUG - Request: [192.168.1.146:51741 (Allowed Network)] GET /web/favicon.ico (22 live) GZIP Signed-in
Oct 27, 2018 11:59:45.074 [9080] DEBUG - Final path: "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\favicon.ico"
Oct 27, 2018 11:59:45.075 [9080] DEBUG - Content-Length of C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\favicon.ico is 5430.
Oct 27, 2018 11:59:45.078 [12092] DEBUG - (Capabilities) Platform 'Chrome' not matched by plugin platform requirements
Oct 27, 2018 11:59:45.081 [3776] DEBUG - Completed: [192.168.1.146:51731] 200 GET / (22 live) GZIP 17ms 2421 bytes (pipelined: 4)
Oct 27, 2018 11:59:45.082 [3776] DEBUG - Completed: [127.0.0.1:51804] 200 GET /:/prefs (22 live) GZIP 53ms 7538 bytes (pipelined: 4)
Oct 27, 2018 11:59:45.087 [3776] DEBUG - Completed: [192.168.1.146:51741] 200 GET /web/favicon.ico (22 live) GZIP 15ms 5430 bytes (pipelined: 3)
Oct 27, 2018 11:59:45.099 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:45.100 [11892] DEBUG - Request: [127.0.0.1:51804 (Loopback)] GET / (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:45.107 [11892] DEBUG - (Capabilities) Platform 'Chrome' not matched by plugin platform requirements
Oct 27, 2018 11:59:45.114 [3788] DEBUG - Completed: [127.0.0.1:51804] 200 GET / (22 live) GZIP 14ms 2549 bytes (pipelined: 5)
Oct 27, 2018 11:59:45.121 [3788] DEBUG - WebSocket: client initiated close
Oct 27, 2018 11:59:45.122 [3776] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:59:45.122 [3776] DEBUG - NotificationStream: Removing because of error
Oct 27, 2018 11:59:45.127 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:45.128 [12092] DEBUG - Request: [127.0.0.1:51809 (Loopback)] GET /:/websockets/notifications (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:45.129 [12092] DEBUG - WebSocket: Performing handshake from origin http://juno:32400
Oct 27, 2018 11:59:45.129 [12092] DEBUG - Beginning read from WebSocket
Oct 27, 2018 11:59:45.158 [11892] DEBUG - Request: [127.0.0.1:51804 (Loopback)] OPTIONS /updater/check?download=0 (22 live) GZIP Signed-in Token ()
Oct 27, 2018 11:59:45.159 [3776] DEBUG - Completed: [127.0.0.1:51804] 200 OPTIONS /updater/check?download=0 (22 live) GZIP 1ms 349 bytes (pipelined: 6)
Oct 27, 2018 11:59:45.303 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:45.304 [12092] DEBUG - Request: [127.0.0.1:51808 (Loopback)] GET /activities (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:45.307 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:45.308 [3788] DEBUG - Completed: [127.0.0.1:51808] 200 GET /activities (23 live) GZIP 4ms 423 bytes (pipelined: 3)
Oct 27, 2018 11:59:45.309 [12096] DEBUG - Request: [127.0.0.1:51810 (Loopback)] PUT /updater/check?download=0 (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:45.310 [12096] DEBUG - AutoUpdate: requesting check endpoint: /updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d, download: NO
Oct 27, 2018 11:59:45.311 [12096] DEBUG - Downloading document https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:59:45.311 [12096] DEBUG - HTTP requesting GET https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:59:45.462 [12096] DEBUG - HTTP 200 response from GET https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:59:45.463 [12096] INFO - AutoUpdate: no updates available
Oct 27, 2018 11:59:45.464 [3776] DEBUG - Completed: [127.0.0.1:51810] 200 PUT /updater/check?download=0 (23 live) GZIP 155ms 268 bytes (pipelined: 1)
Oct 27, 2018 11:59:45.817 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:45.819 [9080] DEBUG - Request: [127.0.0.1:51810 (Loopback)] GET /photo/:/transcode?url=https%3A%2F%2Fplex.tv%2Fusers%2F679c114df372edf0%2Favatar%3Fc%3D1539510304%26size%3D80&width=80&height=80&minSize=1 (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:45.821 [9080] DEBUG - Photo transcoder: Request for url [https://plex.tv/users/679c114df372edf0/avatar?c=1539510304&size=80] (is local: 0 upscaled: 0)
Oct 27, 2018 11:59:45.821 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:45.822 [11892] DEBUG - Request: [127.0.0.1:51808 (Loopback)] GET /photo/:/transcode?url=https%3A%2F%2Fplex.tv%2Fusers%2F679c114df372edf0%2Favatar%3Fc%3D1539510304%26size%3D120&width=120&height=120&minSize=1&blur=20&opacity=50&background=000000 (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:45.824 [11892] DEBUG - Photo transcoder: Request for url [https://plex.tv/users/679c114df372edf0/avatar?c=1539510304&size=120] (is local: 0 upscaled: 0)
Oct 27, 2018 11:59:45.825 [11892] DEBUG - Content-Length of C:\Users\craig\AppData\Local\Plex Media Server\Cache\PhotoTranscoder\73\733523e0e558f436d4f5dcccb186b1b2b0e510aa.jpg is 2577.
Oct 27, 2018 11:59:45.828 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:45.829 [12092] DEBUG - Request: [127.0.0.1:51817 (Loopback)] GET /photo/:/transcode?url=https%3A%2F%2Fplex.tv%2Fusers%2Fe1a40cc234f8a25c%2Favatar%3Fc%3D1527195739%26size%3D80&width=80&height=80&minSize=1 (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:45.831 [12092] DEBUG - Photo transcoder: Request for url [https://plex.tv/users/e1a40cc234f8a25c/avatar?c=1527195739&size=80] (is local: 0 upscaled: 0)
Oct 27, 2018 11:59:45.846 [3788] DEBUG - Completed: [127.0.0.1:51808] 200 GET /photo/:/transcode?url=https%3A%2F%2Fplex.tv%2Fusers%2F679c114df372edf0%2Favatar%3Fc%3D1539510304%26size%3D120&width=120&height=120&minSize=1&blur=20&opacity=50&background=000000 (23 live) GZIP 24ms 2577 bytes (pipelined: 4)
Oct 27, 2018 11:59:45.883 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:45.883 [12096] DEBUG - Request: [127.0.0.1:51808 (Loopback)] GET /photo/:/transcode?url=https%3A%2F%2Fplex.tv%2Fusers%2Fe1a40cc234f8a25c%2Favatar%3Fc%3D1527195739%26size%3D120&width=120&height=120&minSize=1&blur=20&opacity=50&background=000000 (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:45.884 [12096] DEBUG - Photo transcoder: Request for url [https://plex.tv/users/e1a40cc234f8a25c/avatar?c=1527195739&size=120] (is local: 0 upscaled: 0)
Oct 27, 2018 11:59:45.915 [12096] DEBUG - Content-Length of C:\Users\craig\AppData\Local\Plex Media Server\Cache\PhotoTranscoder\68\68c9be396d151e98fca06c5b835b9f577e8f2f79.jpg is 2875.
Oct 27, 2018 11:59:45.915 [12092] DEBUG - Content-Length of C:\Users\craig\AppData\Local\Plex Media Server\Cache\PhotoTranscoder\b9\b90992fce3b31fe237c62d1ee229d540b95090cd.jpg is 1416.
Oct 27, 2018 11:59:45.916 [9080] DEBUG - Content-Length of C:\Users\craig\AppData\Local\Plex Media Server\Cache\PhotoTranscoder\d8\d8799369f435f2d47d56041f5dc44cb99a0df678.jpg is 300.
Oct 27, 2018 11:59:45.917 [3776] DEBUG - Completed: [127.0.0.1:51810] 200 GET /photo/:/transcode?url=https%3A%2F%2Fplex.tv%2Fusers%2F679c114df372edf0%2Favatar%3Fc%3D1539510304%26size%3D80&width=80&height=80&minSize=1 (23 live) GZIP 99ms 300 bytes (pipelined: 2)
Oct 27, 2018 11:59:45.940 [3776] DEBUG - Completed: [127.0.0.1:51808] 200 GET /photo/:/transcode?url=https%3A%2F%2Fplex.tv%2Fusers%2Fe1a40cc234f8a25c%2Favatar%3Fc%3D1527195739%26size%3D120&width=120&height=120&minSize=1&blur=20&opacity=50&background=000000 (23 live) GZIP 56ms 2875 bytes (pipelined: 5)
Oct 27, 2018 11:59:45.945 [3776] DEBUG - Completed: [127.0.0.1:51817] 200 GET /photo/:/transcode?url=https%3A%2F%2Fplex.tv%2Fusers%2Fe1a40cc234f8a25c%2Favatar%3Fc%3D1527195739%26size%3D80&width=80&height=80&minSize=1 (23 live) GZIP 116ms 1416 bytes (pipelined: 1)
Oct 27, 2018 11:59:46.930 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:46.931 [11892] DEBUG - Request: [127.0.0.1:51817 (Loopback)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:46.932 [11892] DEBUG - [CompanionProxy] registered new player: jycf47t4lqaozrzm0jyhz1tt (127.0.0.1)
Oct 27, 2018 11:59:46.933 [11892] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:59:51.389 [3788] DEBUG - WebSocket: client initiated close
Oct 27, 2018 11:59:51.390 [3788] DEBUG - NotificationStream: Removing because of close
Oct 27, 2018 11:59:51.390 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:59:51.517 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:59:51.517 [3788] WARN - LongPoll: Got error, closing.
Oct 27, 2018 11:59:51.519 [9080] DEBUG - Request: [192.168.1.146:51741 (Allowed Network)] GET /web/common/img/backgrounds/preset-dark.64cc1c942221cd2c153244bd8ecfb67a.png (22 live) GZIP Signed-in
Oct 27, 2018 11:59:51.520 [9080] DEBUG - Final path: "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\common\img\backgrounds\preset-dark.64cc1c942221cd2c153244bd8ecfb67a.png"
Oct 27, 2018 11:59:51.521 [9080] DEBUG - Content-Length of C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-10d48da0d\WebClient.bundle\Contents\Resources\common\img\backgrounds\preset-dark.64cc1c942221cd2c153244bd8ecfb67a.png is 31365.
Oct 27, 2018 11:59:51.523 [3788] DEBUG - Completed: [192.168.1.146:51741] 200 GET /web/common/img/backgrounds/preset-dark.64cc1c942221cd2c153244bd8ecfb67a.png (22 live) GZIP 3ms 31365 bytes (pipelined: 4)
Oct 27, 2018 11:59:51.578 [3776] DEBUG - Request: [127.0.0.1:51808 (Loopback)] GET / (22 live) GZIP Signed-in
Oct 27, 2018 11:59:51.579 [12096] DEBUG - Request: [192.168.1.146:51741 (Allowed Network)] GET / (22 live) GZIP Signed-in
Oct 27, 2018 11:59:51.579 [3788] DEBUG - Completed: [127.0.0.1:51808] 401 GET / (22 live) GZIP 0ms 489 bytes (pipelined: 6)
Oct 27, 2018 11:59:51.582 [12096] DEBUG - (Capabilities) Platform 'Chrome' not matched by plugin platform requirements
Oct 27, 2018 11:59:51.585 [3776] DEBUG - Completed: [192.168.1.146:51741] 200 GET / (22 live) GZIP 6ms 2421 bytes (pipelined: 5)
Oct 27, 2018 11:59:51.739 [12092] DEBUG - Request: [127.0.0.1:51808 (Loopback)] GET /identity (21 live) GZIP Signed-in
Oct 27, 2018 11:59:51.741 [3788] DEBUG - Completed: [127.0.0.1:51808] 200 GET /identity (21 live) GZIP 2ms 544 bytes (pipelined: 7)
Oct 27, 2018 11:59:51.781 [9080] DEBUG - Request: [192.168.1.146:51731 (Allowed Network)] GET /status/sessions (21 live) GZIP Signed-in
Oct 27, 2018 11:59:51.782 [9080] DEBUG - [Now] Adding 1 sessions.
Oct 27, 2018 11:59:51.784 [3788] DEBUG - Completed: [192.168.1.146:51731] 200 GET /status/sessions (21 live) GZIP 2ms 397 bytes (pipelined: 5)
Oct 27, 2018 11:59:51.790 [12096] DEBUG - Request: [192.168.1.146:51731 (Allowed Network)] GET /:/prefs (21 live) GZIP Signed-in
Oct 27, 2018 11:59:51.801 [11892] DEBUG - Request: [192.168.1.146:51741 (Allowed Network)] GET /updater/status (21 live) GZIP Signed-in
Oct 27, 2018 11:59:51.815 [3776] DEBUG - Completed: [192.168.1.146:51741] 200 GET /updater/status (21 live) GZIP 35ms 455 bytes (pipelined: 6)
Oct 27, 2018 11:59:51.864 [3776] DEBUG - Completed: [192.168.1.146:51731] 200 GET /:/prefs (21 live) GZIP 74ms 7465 bytes (pipelined: 6)
Oct 27, 2018 11:59:51.894 [9080] DEBUG - Request: [192.168.1.146:51858 (Allowed Network)] GET /:/websockets/notifications (22 live) GZIP Signed-in
Oct 27, 2018 11:59:51.895 [9080] DEBUG - WebSocket: Performing handshake from origin http://juno:32400
Oct 27, 2018 11:59:51.896 [9080] DEBUG - Beginning read from WebSocket
Oct 27, 2018 11:59:52.075 [3788] DEBUG - Request: [127.0.0.1:51808 (Loopback)] GET / (22 live) GZIP Signed-in
Oct 27, 2018 11:59:52.077 [3776] DEBUG - Completed: [127.0.0.1:51808] 401 GET / (22 live) GZIP 0ms 489 bytes (pipelined: 8)
Oct 27, 2018 11:59:52.086 [3776] DEBUG - WebSocket: client initiated close
Oct 27, 2018 11:59:52.088 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:59:52.088 [3788] DEBUG - NotificationStream: Removing because of error
Oct 27, 2018 11:59:52.099 [12092] DEBUG - Request: [192.168.1.146:51865 (Allowed Network)] GET /:/websockets/notifications (23 live) GZIP Signed-in
Oct 27, 2018 11:59:52.100 [12092] DEBUG - WebSocket: Performing handshake from origin http://juno:32400
Oct 27, 2018 11:59:52.100 [12092] DEBUG - Beginning read from WebSocket
Oct 27, 2018 11:59:52.144 [12096] DEBUG - Request: [192.168.1.146:51731 (Allowed Network)] PUT /updater/check?download=0 (23 live) GZIP Signed-in
Oct 27, 2018 11:59:52.145 [12096] DEBUG - AutoUpdate: requesting check endpoint: /updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d, download: NO
Oct 27, 2018 11:59:52.146 [11892] DEBUG - Request: [192.168.1.146:51741 (Allowed Network)] PUT /updater/check?download=0 (22 live) GZIP Signed-in
Oct 27, 2018 11:59:52.146 [12096] DEBUG - Downloading document https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:59:52.147 [12096] DEBUG - HTTP requesting GET https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:59:52.327 [12096] DEBUG - HTTP 200 response from GET https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:59:52.328 [12096] INFO - AutoUpdate: no updates available
Oct 27, 2018 11:59:52.329 [11892] DEBUG - AutoUpdate: requesting check endpoint: /updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d, download: NO
Oct 27, 2018 11:59:52.329 [11892] DEBUG - Downloading document https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:59:52.330 [11892] DEBUG - HTTP requesting GET https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:59:52.330 [3776] DEBUG - Completed: [192.168.1.146:51731] 200 PUT /updater/check?download=0 (22 live) GZIP 186ms 268 bytes (pipelined: 7)
Oct 27, 2018 11:59:52.377 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:52.379 [12092] DEBUG - Request: [127.0.0.1:51808 (Loopback)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (22 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:52.382 [12092] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 11:59:52.383 [9080] DEBUG - Request: [192.168.1.146:51731 (Allowed Network)] GET /activities (22 live) GZIP Signed-in
Oct 27, 2018 11:59:52.388 [3776] DEBUG - Completed: [192.168.1.146:51731] 200 GET /activities (22 live) GZIP 14ms 350 bytes (pipelined: 8)
Oct 27, 2018 11:59:52.466 [12096] DEBUG - Request: [192.168.1.146:51731 (Allowed Network)] GET /:/prefs (22 live) GZIP Signed-in
Oct 27, 2018 11:59:52.510 [9080] DEBUG - Request: [192.168.1.146:51868 (Allowed Network)] GET /accounts/1 (24 live) GZIP Signed-in
Oct 27, 2018 11:59:52.513 [3788] DEBUG - Completed: [192.168.1.146:51868] 200 GET /accounts/1 (24 live) GZIP 6ms 510 bytes (pipelined: 1)
Oct 27, 2018 11:59:52.513 [12092] DEBUG - Request: [192.168.1.146:51730 (Allowed Network)] GET /myplex/account (24 live) GZIP Signed-in
Oct 27, 2018 11:59:52.514 [9556] DEBUG - Request: [192.168.1.146:51869 (Allowed Network)] GET /system/:/prefs (24 live) GZIP Signed-in
Oct 27, 2018 11:59:52.515 [9556] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/:/prefs
Oct 27, 2018 11:59:52.516 [3788] DEBUG - Completed: [192.168.1.146:51730] 200 GET /myplex/account (24 live) GZIP 9ms 1695 bytes (pipelined: 5)
Oct 27, 2018 11:59:52.517 [9556] DEBUG - HTTP requesting GET http://127.0.0.1:49877/system/:/prefs
Oct 27, 2018 11:59:52.530 [11892] DEBUG - HTTP 200 response from GET https://plex.tv/updater/products/1/check.xml?build=windows-i386&channel=16&distribution=english&version=1.13.8.5395-10d48da0d
Oct 27, 2018 11:59:52.531 [11892] INFO - AutoUpdate: no updates available
Oct 27, 2018 11:59:52.532 [3788] DEBUG - Completed: [192.168.1.146:51741] 200 PUT /updater/check?download=0 (24 live) GZIP 387ms 268 bytes (pipelined: 7)
Oct 27, 2018 11:59:52.541 [3776] DEBUG - Completed: [192.168.1.146:51731] 200 GET /:/prefs (24 live) GZIP 93ms 7465 bytes (pipelined: 9)
Oct 27, 2018 11:59:52.557 [9556] DEBUG - HTTP 304 response from GET http://127.0.0.1:49877/system/:/prefs
Oct 27, 2018 11:59:52.557 [9556] DEBUG - [com.plexapp.system] HTTP reply status 304, with 0 bytes of content.
Oct 27, 2018 11:59:52.558 [3776] DEBUG - Completed: [192.168.1.146:51869] 304 GET /system/:/prefs (24 live) GZIP 49ms 211 bytes (pipelined: 1)
Oct 27, 2018 11:59:52.720 [7604] DEBUG - Request: [192.168.1.146:51869 (Allowed Network)] PUT /myplex/refreshReachability (23 live) GZIP Signed-in
Oct 27, 2018 11:59:52.721 [7604] DEBUG - MyPlex: Requesting reachability check.
Oct 27, 2018 11:59:52.723 [7604] DEBUG - HTTP requesting PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=8e74dc91-5f63-4f62-bfc2-5e700f3f9a05
Oct 27, 2018 11:59:52.914 [7604] DEBUG - HTTP 200 response from PUT https://plex.tv/api/servers/7e0d395b9e4a10d7fb39e3151eecdf3274164576/connectivity?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx&asyncIdentifier=8e74dc91-5f63-4f62-bfc2-5e700f3f9a05
Oct 27, 2018 11:59:52.915 [3788] DEBUG - Completed: [192.168.1.146:51869] 200 PUT /myplex/refreshReachability (23 live) GZIP 211ms 268 bytes (pipelined: 2)
Oct 27, 2018 11:59:53.060 [9080] DEBUG - Request: [52.49.250.227:42210 (WAN)] GET /identity (22 live) TLS Signed-in Token (tubs74)
Oct 27, 2018 11:59:53.063 [3788] DEBUG - Completed: [52.49.250.227:42210] 200 GET /identity (22 live) TLS 3ms 357 bytes
Oct 27, 2018 11:59:53.160 [3788] DEBUG - EventSource: Got event [data] '<Message address="86.139.150.227" port="13407" asyncIdentifier="8e74dc91-5f63-4f62-bfc2-5e700f3f9a05" connectivity="1" command="notifyConnectivity"/>'
Oct 27, 2018 11:59:53.161 [3788] DEBUG - PubSub: Got notified of reachability: 1 for 86.139.150.227:13407
Oct 27, 2018 11:59:53.168 [12092] DEBUG - Request: [192.168.1.146:51869 (Allowed Network)] GET /myplex/account (23 live) GZIP Signed-in
Oct 27, 2018 11:59:53.171 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:53.176 [3788] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:53.177 [11892] DEBUG - Request: [192.168.1.199:57348 (Allowed Network)] GET /myplex/account (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:53.179 [12096] DEBUG - Request: [192.168.1.199:57349 (Allowed Network)] GET /myplex/account (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:53.180 [3776] DEBUG - Completed: [192.168.1.199:57348] 200 GET /myplex/account (24 live) GZIP 8ms 1684 bytes (pipelined: 1)
Oct 27, 2018 11:59:53.183 [3776] DEBUG - Completed: [192.168.1.199:57349] 200 GET /myplex/account (24 live) GZIP 5ms 1757 bytes (pipelined: 1)
Oct 27, 2018 11:59:53.184 [3776] DEBUG - Completed: [192.168.1.146:51869] 200 GET /myplex/account (24 live) GZIP 16ms 1684 bytes (pipelined: 3)
Oct 27, 2018 11:59:56.562 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 11:59:56.568 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 11:59:56.569 [9556] DEBUG - Request: [192.168.1.199:57348 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (24 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 11:59:56.570 [9556] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 12:00:00.164 [3788] DEBUG - handleStreamRead code 2: End of file
Oct 27, 2018 12:00:00.171 [3776] DEBUG - Auth: authenticated user 1 as tubs74
Oct 27, 2018 12:00:00.172 [7604] DEBUG - Request: [192.168.1.199:57349 (Allowed Network)] GET /player/proxy/poll?deviceClass=pc&protocolVersion=1&protocolCapabilities=timeline%2Cplayback%2Cnavigation%2Cmirror%2Cplayqueues&timeout=1 (23 live) GZIP Signed-in Token (tubs74)
Oct 27, 2018 12:00:00.174 [7604] DEBUG - Beginning read from two-way stream.
Oct 27, 2018 12:00:06.826 [7604] DEBUG - Request: [192.168.1.146:51731 (Allowed Network)] GET /accounts/1 (21 live) GZIP Signed-in
Oct 27, 2018 12:00:06.833 [3776] DEBUG - Completed: [192.168.1.146:51731] 200 GET /accounts/1 (21 live) GZIP 8ms 510 bytes (pipelined: 10)
Oct 27, 2018 12:00:06.835 [9556] DEBUG - Request: [192.168.1.146:51869 (Allowed Network)] GET /:/prefs (21 live) GZIP Signed-in
Oct 27, 2018 12:00:06.836 [7604] DEBUG - Request: [192.168.1.146:51730 (Allowed Network)] GET /system/:/prefs (21 live) GZIP Signed-in
Oct 27, 2018 12:00:06.836 [11252] DEBUG - Request: [192.168.1.146:51741 (Allowed Network)] GET /myplex/account (21 live) GZIP Signed-in
Oct 27, 2018 12:00:06.838 [7604] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/:/prefs
Oct 27, 2018 12:00:06.838 [7604] DEBUG - HTTP requesting GET http://127.0.0.1:49877/system/:/prefs
Oct 27, 2018 12:00:06.840 [3776] DEBUG - Completed: [192.168.1.146:51741] 200 GET /myplex/account (21 live) GZIP 12ms 1684 bytes (pipelined: 8)
Oct 27, 2018 12:00:06.853 [7604] DEBUG - HTTP 304 response from GET http://127.0.0.1:49877/system/:/prefs
Oct 27, 2018 12:00:06.854 [7604] DEBUG - [com.plexapp.system] HTTP reply status 304, with 0 bytes of content.
Oct 27, 2018 12:00:06.856 [3776] DEBUG - Completed: [192.168.1.146:51730] 304 GET /system/:/prefs (21 live) GZIP 20ms 211 bytes (pipelined: 6)
Oct 27, 2018 12:00:06.899 [3776] DEBUG - Completed: [192.168.1.146:51869] 200 GET /:/prefs (21 live) GZIP 77ms 7465 bytes (pipelined: 4)
Oct 27, 2018 12:00:10.375 [2356] DEBUG - Request: [192.168.1.146:51869 (Allowed Network)] GET /diagnostics/logs (22 live) GZIP Signed-in
Oct 27, 2018 12:00:10.376 [2356] DEBUG - Diagnostics: Building logfile zip
