Mar 18, 2013 18:29:47:946 [4852] INFO - LANGID = 0x409 Mar 18, 2013 18:29:47:946 [4852] DEBUG - LoadMUILibraryW(0) returned 0x740A0002 Mar 18, 2013 18:29:47:946 [4852] INFO - Windows version 6.1 (Build 7601) Mar 18, 2013 18:29:47:946 [4852] INFO - 4 2128 MHz processor(s): Architecture=0, Level=6, Revision=9474 Mar 18, 2013 18:29:47:946 [4852] INFO - PROCESSOR_IDENTIFIER=Intel64 Family 6 Model 37 Stepping 2, GenuineIntel Mar 18, 2013 18:29:47:946 [4852] INFO - Plex Media Server v0.9.7.17-1f0b170 Mar 18, 2013 18:29:47:946 [4852] DEBUG - Opening 10 database sessions to library, SQLite 3.7.15.2, threadsafe=1 Mar 18, 2013 18:29:47:977 [4852] DEBUG - Running migrations. Mar 18, 2013 18:29:47:977 [4852] DEBUG - Listening on port 32400 with queue of 2147483647 connections. Mar 18, 2013 18:29:48:071 [4852] DEBUG - Adding directory for site configurations: C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins/SiteConfigurations.bundle/Contents/Resources Mar 18, 2013 18:29:48:071 [4852] DEBUG - The path changed: C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins/SiteConfigurations.bundle/Contents/Resources. Mar 18, 2013 18:29:48:071 [4852] DEBUG - This corresponds to site configuration map: C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins/SiteConfigurations.bundle/Contents/Resources (directory: 1) Mar 18, 2013 18:29:48:087 [4852] DEBUG - Adding directory for site configurations: C:\Users\Administrator\AppData\Local\Plex Media Server\Site Configurations Mar 18, 2013 18:29:48:087 [4852] DEBUG - The path changed: C:\Users\Administrator\AppData\Local\Plex Media Server\Site Configurations. Mar 18, 2013 18:29:48:087 [4852] DEBUG - This corresponds to site configuration map: C:\Users\Administrator\AppData\Local\Plex Media Server\Site Configurations (directory: 1) Mar 18, 2013 18:29:48:087 [4052] DEBUG - File C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins/SiteConfigurations.bundle/Contents/Resources changed: -1 => -1. Mar 18, 2013 18:29:48:087 [4052] DEBUG - File C:\Users\Administrator\AppData\Local\Plex Media Server\Site Configurations changed: -1 => -1. Mar 18, 2013 18:29:48:087 [4052] DEBUG - The path changed: C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins/SiteConfigurations.bundle/Contents/Resources. Mar 18, 2013 18:29:48:087 [4052] DEBUG - This corresponds to site configuration map: C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins/SiteConfigurations.bundle/Contents/Resources (directory: 1) Mar 18, 2013 18:29:48:087 [4052] DEBUG - The path changed: C:\Users\Administrator\AppData\Local\Plex Media Server\Site Configurations. Mar 18, 2013 18:29:48:087 [4052] DEBUG - This corresponds to site configuration map: C:\Users\Administrator\AppData\Local\Plex Media Server\Site Configurations (directory: 1) Mar 18, 2013 18:29:48:414 [3196] DEBUG - WebKit supports Flash content Mar 18, 2013 18:29:48:414 [3196] DEBUG - WebKit supports Silverlight content Mar 18, 2013 18:29:48:414 [3196] INFO - Successfully initialized WebKit Mar 18, 2013 18:29:48:414 [4852] DEBUG - Setting up scheduled updates Mar 18, 2013 18:29:48:414 [4852] INFO - LibraryUpdateManager path watching is disabled Mar 18, 2013 18:29:48:414 [4180] DEBUG - Starting scheduled updates, every 21600 seconds Mar 18, 2013 18:29:48:430 [4852] DEBUG - Checking for blacklisted version for Framework.bundle (version 42865ab) Mar 18, 2013 18:29:48:430 [4852] DEBUG - Checking for blacklisted version for System.bundle (version 92ccaa6) Mar 18, 2013 18:29:48:430 [5228] DEBUG - File C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins changed: -1 => -1. Mar 18, 2013 18:29:48:430 [5228] DEBUG - Scanning for plug-ins in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins Mar 18, 2013 18:29:48:430 [4324] DEBUG - Loading CAs from 'C:\Program Files (x86)\Plex\Plex Media Server\Resources\cacert.pem' Mar 18, 2013 18:29:48:430 [5228] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\System.bundle. Mar 18, 2013 18:29:48:430 [5228] DEBUG - [com.plexapp.system] Setting plug-in to always running (daemon mode). Mar 18, 2013 18:29:48:446 [5228] DEBUG - Starting file watcher for com.plexapp.system Mar 18, 2013 18:29:48:449 [5228] DEBUG - Plugin::createProcess: Creating plugin process: "C:\Program Files (x86)\Plex\Plex Media Server\PlexScriptHost.exe" "C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Framework.bundle\Contents\Resources\Versions\2\Python/bootstrap.py" "C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\System.bundle" Mar 18, 2013 18:29:48:467 [5228] DEBUG - Spawned plug-in com.plexapp.system with PID 1428 Mar 18, 2013 18:29:48:467 [5228] DEBUG - [com.plexapp.system] Sent command: GET /:/prefixes Mar 18, 2013 18:29:52:502 [5228] DEBUG - Reading 323 bytes in the body, code is 200 Mar 18, 2013 18:29:52:502 [5228] DEBUG - [com.plexapp.system] Plug-in running on port 58479. Mar 18, 2013 18:29:52:502 [5228] DEBUG - * Plug-in handles prefix: /system Mar 18, 2013 18:29:52:502 [5228] DEBUG - Read configuration for [com.plexapp.system], had 1 prefixes Mar 18, 2013 18:29:52:611 [5228] DEBUG - Done with 1 synchronous plug-in starts, starting the rest in parallel. Mar 18, 2013 18:29:52:611 [5228] DEBUG - Updating the list of agents known by the system. Mar 18, 2013 18:29:52:611 [5228] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/agents Mar 18, 2013 18:29:52:611 [5228] DEBUG - HTTP requesting to: http://127.0.0.1:58479/system/agents Mar 18, 2013 18:29:52:705 [4852] WARN - iTunes library not found at expected location: C:\Users\Administrator\Music\iTunes\iTunes Music Library.xml (The system cannot find the path specified) Mar 18, 2013 18:29:52:705 [4852] DEBUG - Loading iTunes COM class to get library XML file path Mar 18, 2013 18:29:52:705 [4852] ERROR - Failed to create iTunes COM instance (-2147221164) Mar 18, 2013 18:29:52:705 [4852] DEBUG - Found 0 library files Mar 18, 2013 18:29:52:705 [4852] WARN - Failed to open iTunes registry key at CLSID\{DC0C2640-1415-4644-875C-6F4D769839BA}\LocalServer32 Mar 18, 2013 18:29:52:705 [4852] DEBUG - Image transcode cache directory: C:\Users\Administrator\AppData\Local\Plex Media Server\Cache\PhotoTranscoder Mar 18, 2013 18:29:52:720 [4852] DEBUG - Bonjour: DNSServiceBrowse succeeded Mar 18, 2013 18:29:52:752 [4852] DEBUG - Bonjour: DNSServiceBrowse succeeded Mar 18, 2013 18:29:52:752 [4852] INFO - Bonjour: registering PMS service Mar 18, 2013 18:29:52:752 [4852] INFO - Bonjour: serviceType = _plexmediasvr._tcp, friendlyName = YGGDRASIL, domain = NULL, hostname = NULL, servicePort = 32400 Mar 18, 2013 18:29:52:752 [4852] INFO - Bonjour: machineIdentifier = 6e186c42359e78e9c87c7998009a151e91cc6c8b, version = 0.9.7.17-1f0b170, playersModified = 1363645792.0 Mar 18, 2013 18:29:52:752 [3656] DEBUG - Bonjour: DNSServiceBrowse_Callback: sdRef = 0x03EC0EF8, flags = 2, interfaceIndex = 15, code = 0 Mar 18, 2013 18:29:52:752 [3656] DEBUG - Bonjour: DNSServiceBrowse_Callback: serviceName = MAPODOFU, regtype = _plexmediasvr._tcp., replyDomain = local. Mar 18, 2013 18:29:52:752 [3656] DEBUG - Bonjour: DNSServiceBrowse_Callback: calling DNSServiceResolve on MAPODOFU Mar 18, 2013 18:29:52:752 [4852] DEBUG - Bonjour: DNSServiceRegister succeeded Mar 18, 2013 18:29:52:752 [3656] DEBUG - Bonjour: DNSServiceResolve succeeded, adding reference 0x035680B0, new ResolveContext instance 0x28A7BB02 Mar 18, 2013 18:29:52:752 [3656] DEBUG - Bonjour: DNSServiceResolve_Callback: sdResolveRef = 0x03ECC8B0, flags = 0, interfaceIndex = 15, errorCode = 0 Mar 18, 2013 18:29:52:752 [3656] DEBUG - Bonjour: DNSServiceResolve_Callback: fullname = MAPODOFU._plexmediasvr._tcp.local., hosttarget = MAPODOFU.local., tcpport = 36990, txtLen = 113 Mar 18, 2013 18:29:52:752 [3656] DEBUG - Bonjour: DNSServiceResolve_Callback: resolved TXT record for MAPODOFU._plexmediasvr._tcp.local.: host = MAPODOFU.local., machineIdentifier = 57910a53873f40dbb5d840c429b206d18b8851ea, version = 0.9.7.17-1f0b170 Mar 18, 2013 18:29:52:752 [4852] DEBUG - NAT: Starting Mapping Thread. Mar 18, 2013 18:29:52:752 [1596] DEBUG - HTTP requesting to: https://my.plexapp.com/users/account.xml?auth_token=uwYZxRhtAoC5oyYRpaih Mar 18, 2013 18:29:52:752 [4852] DEBUG - NAT: Using manually specified port of 32400. Mar 18, 2013 18:29:52:752 [4852] DEBUG - NAT: Creating NAT puncher thread 03561E68 Mar 18, 2013 18:29:52:752 [4852] DEBUG - Creating NetworkServices singleton. Mar 18, 2013 18:29:52:752 [4852] DEBUG - NetworkServices: Initializing... Mar 18, 2013 18:29:52:752 [4852] DEBUG - NetworkInterface: Notified of network changed (force=0) Mar 18, 2013 18:29:52:752 [5916] DEBUG - NAT: Updating mapping in puncher thread 03561E68 Mar 18, 2013 18:29:52:752 [5916] DEBUG - NAT: Creating puncher. Mar 18, 2013 18:29:52:752 [5916] DEBUG - NAT: Switching to NAT-PMP strategy. Mar 18, 2013 18:29:52:752 [5916] DEBUG - NAT: Creating NATPmPPuncher. Mar 18, 2013 18:29:52:752 [5916] DEBUG - NAT: Initializing NAT-PMP, success=1 Mar 18, 2013 18:29:52:752 [5916] DEBUG - NAT: Finding public address from NAT-PMP. Mar 18, 2013 18:29:52:752 [5916] DEBUG - NAT: Finished NAT-PMP request, result was: NATPMP_ERR_RECVFROM Mar 18, 2013 18:29:52:752 [5916] DEBUG - NAT: Found public address (success=0): 0.0.0.0 Mar 18, 2013 18:29:52:752 [5916] DEBUG - NAT: Finding public address failed the first way, switching. Mar 18, 2013 18:29:52:752 [5916] DEBUG - NAT: Switching to UPnP strategy. Mar 18, 2013 18:29:52:752 [5916] DEBUG - NAT: Creating NATUPnPPuncher. Mar 18, 2013 18:29:52:767 [4852] DEBUG - Network interfaces: Mar 18, 2013 18:29:52:767 [4852] DEBUG - * 1 {065F0C42-703A-11DE-9954-806E6F6E6963} (127.0.0.1) (loopback: 1) Mar 18, 2013 18:29:52:767 [4852] DEBUG - * 15 {BA974BA7-3123-4855-B4EA-BBF61337B6BE} (192.168.1.100) (loopback: 0) Mar 18, 2013 18:29:52:767 [4852] DEBUG - 035AF700: Creating new Network Service and registering for notifications. Mar 18, 2013 18:29:52:767 [4852] DEBUG - 035AF700: NetworkService got notification of changed network (first change: 1) Mar 18, 2013 18:29:52:767 [4852] DEBUG - NetworkService: Quick dispatch of network change. Mar 18, 2013 18:29:52:767 [4852] DEBUG - 035B1740: Creating new Network Service and registering for notifications. Mar 18, 2013 18:29:52:767 [4852] DEBUG - 035B1740: NetworkService got notification of changed network (first change: 1) Mar 18, 2013 18:29:52:767 [4852] DEBUG - NetworkService: Quick dispatch of network change. Mar 18, 2013 18:29:52:767 [4852] DEBUG - 035B3780: Creating new Network Service and registering for notifications. Mar 18, 2013 18:29:52:767 [4852] DEBUG - 035B3780: NetworkService got notification of changed network (first change: 1) Mar 18, 2013 18:29:52:767 [4852] DEBUG - NetworkService: Quick dispatch of network change. Mar 18, 2013 18:29:52:767 [4852] DEBUG - 035B5830: Creating new Network Service and registering for notifications. Mar 18, 2013 18:29:52:767 [4852] DEBUG - 035B5830: NetworkService got notification of changed network (first change: 1) Mar 18, 2013 18:29:52:767 [4852] DEBUG - NetworkService: Quick dispatch of network change. Mar 18, 2013 18:29:52:767 [2528] DEBUG - Network change for advertiser. Mar 18, 2013 18:29:52:767 [4852] DEBUG - Starting HTTP server. Mar 18, 2013 18:29:52:767 [2528] DEBUG - NetworkService: Setting up multicast listener on 0.0.0.0:32414 (outbound: 0) Mar 18, 2013 18:29:52:767 [4852] DEBUG - Running server... Mar 18, 2013 18:29:52:767 [4852] DEBUG - Waiting for server condition to be signaled. Mar 18, 2013 18:29:52:767 [3912] DEBUG - DLNA server starting. Mar 18, 2013 18:29:52:767 [3912] DEBUG - Job running: C:\Program Files (x86)\Plex\Plex Media Server\PlexDlnaServer.exe Mar 18, 2013 18:29:52:767 [2528] DEBUG - Network change for advertiser. Mar 18, 2013 18:29:52:767 [2528] DEBUG - NetworkService: Setting up multicast listener on 0.0.0.0:32410 (outbound: 0) Mar 18, 2013 18:29:52:767 [2528] DEBUG - Network change for browser (polled=0), closing 0 browse sockets. Mar 18, 2013 18:29:52:767 [2528] DEBUG - NetworkService: Setting up multicast listener on 0.0.0.0:32413 (outbound: 0) Mar 18, 2013 18:29:52:767 [2528] DEBUG - NetworkService: Browsing on interface 127.0.0.1. Mar 18, 2013 18:29:52:767 [2528] DEBUG - NetworkService: Setting up multicast listener on 127.0.0.1:0 (outbound: 1) Mar 18, 2013 18:29:52:767 [2528] DEBUG - NetworkService: Browsing on interface 192.168.1.100. Mar 18, 2013 18:29:52:767 [2528] DEBUG - NetworkService: Setting up multicast listener on 192.168.1.100:0 (outbound: 1) Mar 18, 2013 18:29:52:767 [3656] DEBUG - Bonjour: MonitorTxtRecord - DNSServiceConstructFullName succeeded: MAPODOFU._plexmediasvr._tcp.local. Mar 18, 2013 18:29:52:767 [2528] DEBUG - Network change for browser (polled=1), closing 0 browse sockets. Mar 18, 2013 18:29:52:767 [2528] DEBUG - NetworkService: Browsing on interface 127.0.0.1. Mar 18, 2013 18:29:52:767 [2528] DEBUG - NetworkService: Setting up multicast listener on 127.0.0.1:0 (outbound: 1) Mar 18, 2013 18:29:52:767 [2528] DEBUG - NetworkService: Browsing on interface 192.168.1.100. Mar 18, 2013 18:29:52:767 [2528] DEBUG - NetworkService: Setting up multicast listener on 192.168.1.100:0 (outbound: 1) Mar 18, 2013 18:29:52:767 [0932] DEBUG - Request: GET /library/sections [192.168.1.65:64268] (5 live) Mar 18, 2013 18:29:52:767 [3200] DEBUG - Set up a thread pool for HTTP server with 2 threads. Mar 18, 2013 18:29:52:767 [3200] DEBUG - Running database fix-ups. Mar 18, 2013 18:29:52:767 [3656] DEBUG - Bonjour: DNSServiceQueryRecord succeeded, QueryRecordContext = 0x034F11D8 Mar 18, 2013 18:29:52:767 [3656] INFO - Bonjour: adding host - name = MAPODOFU, hostname - MAPODOFU.local., machineIdentifier = 57910a53873f40dbb5d840c429b206d18b8851ea Mar 18, 2013 18:29:52:767 [3656] DEBUG - Bonjour: DNSServiceResolve_Callback: removing reference 0x03ECC8B0, deleting ResolveContext instance 0x035680B0 Mar 18, 2013 18:29:52:767 [3656] DEBUG - Bonjour: DNSServiceQueryRecord_Callback succeeded, QueryRecordContext = 0x034F11D8 Mar 18, 2013 18:29:52:767 [3656] INFO - Bonjour: TXT record added for MAPODOFU._plexmediasvr._tcp.local. Mar 18, 2013 18:29:52:767 [5104] DEBUG - Request: GET /:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_ [127.0.0.1:58475] (5 live) Mar 18, 2013 18:29:52:783 [5104] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_ Mar 18, 2013 18:29:52:783 [5104] DEBUG - HTTP requesting to: http://127.0.0.1:58479/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_ Mar 18, 2013 18:29:52:783 [5760] DEBUG - Notifying the system bundle an update to server /system/notify/serverUpdated?host=MAPODOFU.local. Mar 18, 2013 18:29:52:783 [5760] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/notify/serverUpdated?host=MAPODOFU.local. Mar 18, 2013 18:29:52:783 [0932] DEBUG - It took 0.016000 sec to serialize a list with 5 elements. Mar 18, 2013 18:29:52:783 [5760] DEBUG - HTTP requesting to: http://127.0.0.1:58479/system/notify/serverUpdated?host=MAPODOFU.local. Mar 18, 2013 18:29:52:783 [5576] DEBUG - Request: GET / [127.0.0.1:58477] (5 live) Mar 18, 2013 18:29:52:783 [2528] DEBUG - NetworkServiceBrowser: SERVER arrived: 192.168.1.100 Mar 18, 2013 18:29:52:783 [2528] DEBUG - Notifying the system bundle an update to server /system/notify/serverUpdated?host=192.168.1.100 Mar 18, 2013 18:29:52:783 [2528] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/notify/serverUpdated?host=192.168.1.100 Mar 18, 2013 18:29:52:783 [5576] DEBUG - It took 0.000000 sec to serialize a list with 7 elements. Mar 18, 2013 18:29:52:783 [2528] DEBUG - HTTP requesting to: http://127.0.0.1:58479/system/notify/serverUpdated?host=192.168.1.100 Mar 18, 2013 18:29:52:783 [5224] DEBUG - Request: GET /servers [127.0.0.1:58478] (5 live) Mar 18, 2013 18:29:52:783 [5224] DEBUG - It took 0.000000 sec to serialize a list with 2 elements. Mar 18, 2013 18:29:52:783 [3164] DEBUG - Request: GET / [127.0.0.1:58476] (5 live) Mar 18, 2013 18:29:52:783 [3164] DEBUG - It took 0.000000 sec to serialize a list with 7 elements. Mar 18, 2013 18:29:52:783 [0932] DEBUG - Request: GET /channels/all [192.168.1.65:64271] (5 live) Mar 18, 2013 18:29:52:783 [0932] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:29:52:861 [0932] DEBUG - Request: GET / [127.0.0.1:58496] (5 live) Mar 18, 2013 18:29:52:876 [0932] DEBUG - It took 0.000000 sec to serialize a list with 7 elements. Mar 18, 2013 18:29:52:954 [5224] DEBUG - Request: GET /library/sections [192.168.1.100:58497] (5 live) Mar 18, 2013 18:29:52:954 [3164] DEBUG - Request: GET /servers [127.0.0.1:58498] (5 live) Mar 18, 2013 18:29:52:954 [0932] DEBUG - Request: GET /servers [127.0.0.1:58499] (5 live) Mar 18, 2013 18:29:52:970 [3164] DEBUG - It took 0.016000 sec to serialize a list with 2 elements. Mar 18, 2013 18:29:52:986 [0932] DEBUG - It took 0.000000 sec to serialize a list with 2 elements. Mar 18, 2013 18:29:53:048 [5576] DEBUG - Request: GET /library/sections [192.168.1.100:58501] (5 live) Mar 18, 2013 18:29:53:079 [3164] DEBUG - Request: GET /library/sections [192.168.1.100:58504] (4 live) Mar 18, 2013 18:29:53:126 [5224] DEBUG - It took 0.125000 sec to serialize a list with 5 elements. Mar 18, 2013 18:29:53:126 [5576] DEBUG - It took 0.031000 sec to serialize a list with 5 elements. Mar 18, 2013 18:29:53:157 [3164] DEBUG - It took 0.047000 sec to serialize a list with 5 elements. Mar 18, 2013 18:29:53:157 [0932] DEBUG - Request: GET /channels/all [192.168.1.100:58505] (5 live) Mar 18, 2013 18:29:53:157 [0932] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:29:53:188 [3164] DEBUG - Request: GET /channels/all [192.168.1.100:58506] (5 live) Mar 18, 2013 18:29:53:188 [3164] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:29:53:220 [0932] DEBUG - Request: GET /channels/all [192.168.1.100:58507] (5 live) Mar 18, 2013 18:29:53:220 [0932] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:29:53:251 [2528] DEBUG - [com.plexapp.system] HTTP reply status 200, with 0 bytes of content. Mar 18, 2013 18:29:53:251 [2528] DEBUG - NetworkServiceBrowser: PLAYER arrived: 192.168.1.111 Mar 18, 2013 18:29:53:251 [2528] DEBUG - NetworkServiceBrowser: SERVER arrived: 192.168.1.65 Mar 18, 2013 18:29:53:251 [2528] DEBUG - Notifying the system bundle an update to server /system/notify/serverUpdated?host=192.168.1.65 Mar 18, 2013 18:29:53:251 [2528] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/notify/serverUpdated?host=192.168.1.65 Mar 18, 2013 18:29:53:251 [2528] DEBUG - HTTP requesting to: http://127.0.0.1:58479/system/notify/serverUpdated?host=192.168.1.65 Mar 18, 2013 18:29:53:266 [5760] DEBUG - [com.plexapp.system] HTTP reply status 200, with 0 bytes of content. Mar 18, 2013 18:29:53:313 [5576] DEBUG - Request: GET /servers [127.0.0.1:58511] (5 live) Mar 18, 2013 18:29:53:313 [5576] DEBUG - It took 0.000000 sec to serialize a list with 2 elements. Mar 18, 2013 18:29:53:438 [0932] DEBUG - Request: GET /library/sections [192.168.1.100:58517] (5 live) Mar 18, 2013 18:29:53:469 [0932] DEBUG - It took 0.015000 sec to serialize a list with 5 elements. Mar 18, 2013 18:29:53:516 [5576] DEBUG - Request: GET /channels/all [192.168.1.100:58519] (5 live) Mar 18, 2013 18:29:53:516 [5576] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:29:53:547 [2528] DEBUG - [com.plexapp.system] HTTP reply status 200, with 0 bytes of content. Mar 18, 2013 18:29:53:641 [3656] DEBUG - Bonjour: DNSServiceBrowse_Callback: sdRef = 0x03EC0EF8, flags = 2, interfaceIndex = 15, code = 0 Mar 18, 2013 18:29:53:641 [3656] DEBUG - Bonjour: DNSServiceBrowse_Callback: serviceName = YGGDRASIL, regtype = _plexmediasvr._tcp., replyDomain = local. Mar 18, 2013 18:29:53:641 [3656] DEBUG - Bonjour: DNSServiceBrowse_Callback: calling DNSServiceResolve on YGGDRASIL Mar 18, 2013 18:29:53:656 [3656] DEBUG - Bonjour: DNSServiceResolve succeeded, adding reference 0x08046E88, new ResolveContext instance 0x28A7BB02 Mar 18, 2013 18:29:54:499 [5228] DEBUG - [com.plexapp.system] HTTP reply status 200, with 3220 bytes of content. Mar 18, 2013 18:29:54:499 [5228] DEBUG - The system knows about 13 agents. Mar 18, 2013 18:29:54:499 [1004] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Cine21.bundle. Mar 18, 2013 18:29:54:499 [3412] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Framework.bundle. Mar 18, 2013 18:29:54:499 [5228] DEBUG - Waiting for all 24 plug-ins to finish starting. Mar 18, 2013 18:29:54:499 [5260] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\HTbackdrops.bundle. Mar 18, 2013 18:29:54:499 [3412] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\IMDB.bundle. Mar 18, 2013 18:29:54:499 [1004] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.cine21] yet. Mar 18, 2013 18:29:54:499 [1004] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\LastFM.bundle. Mar 18, 2013 18:29:54:499 [5260] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.htbackdrops] yet. Mar 18, 2013 18:29:54:499 [5260] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\LocalMedia.bundle. Mar 18, 2013 18:29:54:499 [3412] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.imdb] yet. Mar 18, 2013 18:29:54:499 [3412] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Media-Flags.bundle. Mar 18, 2013 18:29:54:514 [1004] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.lastfm] yet. Mar 18, 2013 18:29:54:514 [1004] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\MoviePosterDB.bundle. Mar 18, 2013 18:29:54:514 [3412] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Netflix.bundle. Mar 18, 2013 18:29:54:514 [5260] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.localmedia] yet. Mar 18, 2013 18:29:54:514 [5260] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\OpenSubtitles.bundle. Mar 18, 2013 18:29:54:514 [1004] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.movieposterdb] yet. Mar 18, 2013 18:29:54:514 [1004] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Pandora.bundle. Mar 18, 2013 18:29:54:514 [3412] DEBUG - We're going to add C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Netflix.bundle\Contents/Site Configurations as a location for site configurations. Mar 18, 2013 18:29:54:514 [3412] DEBUG - Adding directory for site configurations: C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Netflix.bundle\Contents/Site Configurations Mar 18, 2013 18:29:54:514 [3412] DEBUG - The path changed: C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Netflix.bundle\Contents/Site Configurations. Mar 18, 2013 18:29:54:514 [3412] DEBUG - This corresponds to site configuration map: C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Netflix.bundle\Contents/Site Configurations (directory: 1) Mar 18, 2013 18:29:54:514 [3412] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.plugins.netflix] yet. Mar 18, 2013 18:29:54:514 [3412] DEBUG - * Added Netflix at /video/netflix Mar 18, 2013 18:29:54:514 [3412] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\PersonalMedia.bundle. Mar 18, 2013 18:29:54:514 [3412] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.none] yet. Mar 18, 2013 18:29:54:514 [3412] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\PlexThemeMusic.bundle. Mar 18, 2013 18:29:54:514 [3412] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.plexthememusic] yet. Mar 18, 2013 18:29:54:514 [3412] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Scanners.bundle. Mar 18, 2013 18:29:54:514 [3412] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Services.bundle. Mar 18, 2013 18:29:54:514 [3412] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\SiteConfigurations.bundle. Mar 18, 2013 18:29:54:514 [3412] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Spotify.bundle. Mar 18, 2013 18:29:54:514 [3412] DEBUG - Starting file watcher for com.plexapp.plugins.spotify Mar 18, 2013 18:29:54:514 [3412] DEBUG - Plugin::createProcess: Creating plugin process: "C:\Program Files (x86)\Plex\Plex Media Server\PlexScriptHost.exe" "C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Framework.bundle\Contents\Resources\Versions\2\Python/bootstrap.py" "C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Spotify.bundle" Mar 18, 2013 18:29:54:514 [3412] DEBUG - Spawned plug-in com.plexapp.plugins.spotify with PID 5304 Mar 18, 2013 18:29:54:514 [3412] DEBUG - [com.plexapp.plugins.spotify] Sent command: GET /:/prefixes Mar 18, 2013 18:29:54:530 [1004] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.plugins.pandora] yet. Mar 18, 2013 18:29:54:530 [1004] DEBUG - * Added Pandora at /music/pandora Mar 18, 2013 18:29:54:530 [1004] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\The-Movie-Database.bundle. Mar 18, 2013 18:29:54:530 [1004] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.themoviedb] yet. Mar 18, 2013 18:29:54:530 [1004] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\TheTVDB.bundle. Mar 18, 2013 18:29:54:530 [1004] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.thetvdb] yet. Mar 18, 2013 18:29:54:530 [1004] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\TVRage.bundle. Mar 18, 2013 18:29:54:530 [1004] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.tvrage] yet. Mar 18, 2013 18:29:54:530 [1004] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\WebClient.bundle. Mar 18, 2013 18:29:54:530 [1004] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\WebManager.bundle. Mar 18, 2013 18:29:54:530 [1004] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Wikipedia.bundle. Mar 18, 2013 18:29:54:530 [1004] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.wikipedia] yet. Mar 18, 2013 18:29:54:530 [1004] DEBUG - Starting plug-in C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\YouTube.bundle. Mar 18, 2013 18:29:54:530 [1004] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.plugins.youtube] yet. Mar 18, 2013 18:29:54:530 [1004] DEBUG - * Added YouTube at /video/youtube Mar 18, 2013 18:29:54:546 [5260] DEBUG - Perfect cache hit, we don't need to start [com.plexapp.agents.opensubtitles] yet. Mar 18, 2013 18:29:54:546 [5104] DEBUG - [com.plexapp.system] HTTP reply status 200, with 86152 bytes of content. Mar 18, 2013 18:29:54:639 [3656] DEBUG - Bonjour: DNSServiceResolve_Callback: sdResolveRef = 0x03ECC948, flags = 0, interfaceIndex = 15, errorCode = 0 Mar 18, 2013 18:29:54:639 [3656] DEBUG - Bonjour: DNSServiceResolve_Callback: fullname = YGGDRASIL._plexmediasvr._tcp.local., hosttarget = YGGDRASIL.local., tcpport = 36990, txtLen = 113 Mar 18, 2013 18:29:54:639 [3656] DEBUG - Bonjour: DNSServiceResolve_Callback: resolved TXT record for YGGDRASIL._plexmediasvr._tcp.local.: host = YGGDRASIL.local., machineIdentifier = 6e186c42359e78e9c87c7998009a151e91cc6c8b, version = 0.9.7.17-1f0b170 Mar 18, 2013 18:29:54:686 [3164] DEBUG - Request: GET /library/sections [192.168.1.65:64283] (5 live) Mar 18, 2013 18:29:54:686 [3164] DEBUG - It took 0.000000 sec to serialize a list with 5 elements. Mar 18, 2013 18:29:54:686 [3164] DEBUG - Request: GET /channels/all [192.168.1.65:64284] (5 live) Mar 18, 2013 18:29:54:686 [3164] DEBUG - It took 0.000000 sec to serialize a list with 3 elements. Mar 18, 2013 18:29:55:232 [4052] DEBUG - File C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Netflix.bundle\Contents/Site Configurations changed: 1362968900 => 0. Mar 18, 2013 18:29:55:232 [4052] DEBUG - The path changed: C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Netflix.bundle\Contents/Site Configurations. Mar 18, 2013 18:29:55:232 [4052] DEBUG - This corresponds to site configuration map: C:\Users\Administrator\AppData\Local\Plex Media Server\Plug-ins\Netflix.bundle\Contents/Site Configurations (directory: 1) Mar 18, 2013 18:29:55:575 [0932] DEBUG - Request: GET /system/messaging/clear_events/com.plexapp.plugins.spotify [127.0.0.1:58529] (5 live) Mar 18, 2013 18:29:55:575 [0932] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/messaging/clear_events/com.plexapp.plugins.spotify Mar 18, 2013 18:29:55:575 [0932] DEBUG - HTTP requesting to: http://127.0.0.1:58479/system/messaging/clear_events/com.plexapp.plugins.spotify Mar 18, 2013 18:29:55:653 [0932] DEBUG - [com.plexapp.system] HTTP reply status 200, with 0 bytes of content. Mar 18, 2013 18:29:55:762 [5104] DEBUG - Request: GET /:/plugins/com.plexapp.system/resourceHashes [127.0.0.1:58532] (5 live) Mar 18, 2013 18:29:55:762 [5104] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /:/plugins/com.plexapp.system/resourceHashes Mar 18, 2013 18:29:55:762 [5104] DEBUG - HTTP requesting to: http://127.0.0.1:58479/:/plugins/com.plexapp.system/resourceHashes Mar 18, 2013 18:29:55:840 [5104] DEBUG - [com.plexapp.system] HTTP reply status 200, with 25379 bytes of content. Mar 18, 2013 18:29:55:872 [5224] DEBUG - Request: GET / [127.0.0.1:58535] (5 live) Mar 18, 2013 18:29:55:872 [5224] DEBUG - It took 0.000000 sec to serialize a list with 9 elements. Mar 18, 2013 18:29:55:872 [5104] DEBUG - Request: GET /:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_ [127.0.0.1:58536] (5 live) Mar 18, 2013 18:29:55:872 [5104] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_ Mar 18, 2013 18:29:55:887 [5104] DEBUG - HTTP requesting to: http://127.0.0.1:58479/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_ Mar 18, 2013 18:29:55:950 [5104] DEBUG - [com.plexapp.system] HTTP reply status 200, with 86152 bytes of content. Mar 18, 2013 18:29:56:932 [3656] DEBUG - Bonjour: MonitorTxtRecord - DNSServiceConstructFullName succeeded: YGGDRASIL._plexmediasvr._tcp.local. Mar 18, 2013 18:29:56:932 [3656] DEBUG - Bonjour: DNSServiceQueryRecord succeeded, QueryRecordContext = 0x0803BED8 Mar 18, 2013 18:29:56:932 [3656] INFO - Bonjour: adding host - name = YGGDRASIL, hostname - YGGDRASIL.local., machineIdentifier = 6e186c42359e78e9c87c7998009a151e91cc6c8b Mar 18, 2013 18:29:56:932 [3656] DEBUG - Bonjour: DNSServiceResolve_Callback: removing reference 0x03ECC948, deleting ResolveContext instance 0x08046E88 Mar 18, 2013 18:29:56:932 [3656] DEBUG - Bonjour: DNSServiceQueryRecord_Callback succeeded, QueryRecordContext = 0x0803BED8 Mar 18, 2013 18:29:56:932 [3656] INFO - Bonjour: TXT record added for YGGDRASIL._plexmediasvr._tcp.local. Mar 18, 2013 18:29:56:932 [2888] DEBUG - Notifying the system bundle an update to server /system/notify/serverUpdated?host=YGGDRASIL.local. Mar 18, 2013 18:29:56:932 [2888] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/notify/serverUpdated?host=YGGDRASIL.local. Mar 18, 2013 18:29:56:932 [2888] DEBUG - HTTP requesting to: http://127.0.0.1:58479/system/notify/serverUpdated?host=YGGDRASIL.local. Mar 18, 2013 18:29:56:932 [3164] DEBUG - Request: GET /servers [127.0.0.1:58540] (5 live) Mar 18, 2013 18:29:56:932 [3164] DEBUG - It took 0.000000 sec to serialize a list with 2 elements. Mar 18, 2013 18:29:56:964 [0932] DEBUG - Request: GET /library/sections [192.168.1.100:58543] (5 live) Mar 18, 2013 18:29:56:964 [0932] DEBUG - It took 0.000000 sec to serialize a list with 5 elements. Mar 18, 2013 18:29:56:979 [0932] DEBUG - Request: GET /channels/all [192.168.1.100:58544] (5 live) Mar 18, 2013 18:29:56:979 [0932] DEBUG - It took 0.000000 sec to serialize a list with 3 elements. Mar 18, 2013 18:29:56:979 [2888] DEBUG - [com.plexapp.system] HTTP reply status 200, with 0 bytes of content. Mar 18, 2013 18:29:57:073 [5916] DEBUG - NAT: Initialized UPnP, result: SUCCESS Mar 18, 2013 18:29:57:073 [5916] DEBUG - NAT: Requested public address via UPnP (success=1) Mar 18, 2013 18:29:57:073 [5916] DEBUG - NAT: Obtained public address of 184.164.177.94 (failed: 0 myPlex: 0). Mar 18, 2013 18:29:57:073 [5916] DEBUG - NAT: Checking for change in address: old was and new is 184.164.177.94. Mar 18, 2013 18:29:57:073 [5916] INFO - NAT: Mapping changed 184.164.177.94:32400 -> 192.168.1.100:32400 Mar 18, 2013 18:29:57:088 [5916] DEBUG - It took 0.000000 sec to serialize a list with 6 elements. Mar 18, 2013 18:29:57:088 [5916] DEBUG - MyPlex: Sending Server Info to myPlex (user=entrox@stoleyour.com, ip=, port=32400) Mar 18, 2013 18:29:57:088 [5916] DEBUG - HTTP requesting to: https://my.plexapp.com/servers.xml?auth_token=uwYZxRhtAoC5oyYRpaih Mar 18, 2013 18:29:57:993 [5916] DEBUG - MyPlex: Published Mapping State <--- 201 Mar 18, 2013 18:29:57:993 [5916] DEBUG - MyPlex: Got response for 6e186c42359e78e9c87c7998009a151e91cc6c8b Mar 18, 2013 18:29:57:993 [5916] DEBUG - MyPlex: Registered IP: 184.164.177.94 Mar 18, 2013 18:29:57:993 [5916] DEBUG - MyPlex: Registered Port: 32400 Mar 18, 2013 18:29:57:993 [5916] DEBUG - NAT: Updating mapping complete in thread 03561E68. Mar 18, 2013 18:29:57:993 [5916] DEBUG - NAT: Deleting puncher. Mar 18, 2013 18:29:57:993 [5916] DEBUG - NAT: Deleting NATUPnPPuncher. Mar 18, 2013 18:29:57:993 [5916] DEBUG - NAT: Deleting NATPmPPuncher. Mar 18, 2013 18:29:57:993 [5916] DEBUG - NAT: We're going to next poll in 19.1 hours. Mar 18, 2013 18:29:58:227 [5104] DEBUG - Request: GET /library/sections/7/recentlyAddedGrandparents [50.18.148.15:56763] (5 live) Mar 18, 2013 18:29:58:227 [5104] DEBUG - We found auth token (uwYZxRhtAoC5oyYRpaih), enabling token-based authentication. Mar 18, 2013 18:29:58:227 [5104] DEBUG - Came in with the master token, authorization succeeded. Mar 18, 2013 18:29:58:555 [5104] DEBUG - It took 0.281000 sec to serialize a list with 25 elements. Mar 18, 2013 18:29:59:210 [5224] DEBUG - Request: GET /library/sections/5/recentlyAdded [50.18.148.15:56777] (5 live) Mar 18, 2013 18:29:59:210 [5224] DEBUG - We found auth token (uwYZxRhtAoC5oyYRpaih), enabling token-based authentication. Mar 18, 2013 18:29:59:210 [5224] DEBUG - Came in with the master token, authorization succeeded. Mar 18, 2013 18:29:59:226 [5224] DEBUG - It took 0.000000 sec to serialize a list with 13 elements. Mar 18, 2013 18:29:59:569 [5104] DEBUG - Request: GET /library/metadata/31086?checkFiles=1&skipRefresh=1 [192.168.1.5:50295] (6 live) Mar 18, 2013 18:29:59:569 [5224] DEBUG - Request: GET /:/websockets/notifications?X-Plex-Token=FCKqkE7yRmXePkCzhryw [192.168.1.5:50297] (6 live) Mar 18, 2013 18:29:59:569 [5104] DEBUG - * checkFiles => 1 Mar 18, 2013 18:29:59:569 [5224] DEBUG - * X-Plex-Token => FCKqkE7yRmXePkCzhryw Mar 18, 2013 18:29:59:569 [5104] DEBUG - * skipRefresh => 1 Mar 18, 2013 18:29:59:569 [5224] DEBUG - Creating a WebSocket for notification stream Mar 18, 2013 18:29:59:569 [5224] DEBUG - WebSocket: Performing handshake from origin http://192.168.1.100:32400 Mar 18, 2013 18:29:59:569 [5224] DEBUG - Beginning read from WebSocket Mar 18, 2013 18:29:59:584 [5104] DEBUG - It took 0.000000 sec to serialize a list with 1 elements. Mar 18, 2013 18:29:59:647 [3164] DEBUG - Request: GET /library/metadata/25982/children [192.168.1.5:50296] (6 live) Mar 18, 2013 18:29:59:662 [3164] DEBUG - It took 0.000000 sec to serialize a list with 20 elements. Mar 18, 2013 18:30:00:006 [5104] DEBUG - Request: GET /video/:/transcode/universal/start.m3u8?path=http%3A%2F%2F127.0.0.1%3A32400%2Flibrary%2Fmetadata%2F31086&session=bpib73lzgze&protocol=hls&offset=0&fastSeek=1&directPlay=0&directStream=1&videoQuality=75&videoResolution=1280x720&subtitleSize=100&audioBoost=100&X-Plex-Token=FCKqkE7yRmXePkCzhryw&X-Plex-Client-Identifier=bpib73lzgze&X-Plex-Product=Web+Client&X-Plex-Device=Windows&X-Plex-Platform=Firefox&X-Plex-Platform-Version=19&X-Plex-Version=0.9.9.11&X-Plex-Device-Name=Plex%2FWeb+(Firefox) [192.168.1.5:50298] (5 live) Mar 18, 2013 18:30:00:006 [5104] DEBUG - * path => http://127.0.0.1:32400/library/metadata/31086 Mar 18, 2013 18:30:00:006 [5104] DEBUG - * session => bpib73lzgze Mar 18, 2013 18:30:00:006 [5104] DEBUG - * protocol => hls Mar 18, 2013 18:30:00:006 [5104] DEBUG - * offset => 0 Mar 18, 2013 18:30:00:006 [5104] DEBUG - * fastSeek => 1 Mar 18, 2013 18:30:00:006 [5104] DEBUG - * directPlay => 0 Mar 18, 2013 18:30:00:006 [5104] DEBUG - * directStream => 1 Mar 18, 2013 18:30:00:006 [5104] DEBUG - * videoQuality => 75 Mar 18, 2013 18:30:00:006 [5104] DEBUG - * videoResolution => 1280x720 Mar 18, 2013 18:30:00:006 [5104] DEBUG - * subtitleSize => 100 Mar 18, 2013 18:30:00:006 [5104] DEBUG - * audioBoost => 100 Mar 18, 2013 18:30:00:006 [5104] DEBUG - * X-Plex-Token => FCKqkE7yRmXePkCzhryw Mar 18, 2013 18:30:00:006 [5104] DEBUG - * X-Plex-Client-Identifier => bpib73lzgze Mar 18, 2013 18:30:00:006 [5104] DEBUG - * X-Plex-Product => Web Client Mar 18, 2013 18:30:00:006 [5104] DEBUG - * X-Plex-Device => Windows Mar 18, 2013 18:30:00:006 [5104] DEBUG - * X-Plex-Platform => Firefox Mar 18, 2013 18:30:00:006 [5104] DEBUG - * X-Plex-Platform-Version => 19 Mar 18, 2013 18:30:00:006 [5104] DEBUG - * X-Plex-Version => 0.9.9.11 Mar 18, 2013 18:30:00:006 [5104] DEBUG - * X-Plex-Device-Name => Plex/Web (Firefox) Mar 18, 2013 18:30:00:006 [5104] DEBUG - Using profile Web Mar 18, 2013 18:30:00:006 [5104] DEBUG - Downloading document http://127.0.0.1:32400/library/metadata/31086 Mar 18, 2013 18:30:00:006 [5104] DEBUG - HTTP requesting to: http://127.0.0.1:32400/library/metadata/31086 Mar 18, 2013 18:30:00:006 [0932] DEBUG - Request: GET /library/metadata/31086 [127.0.0.1:58548] (5 live) Mar 18, 2013 18:30:00:021 [0932] DEBUG - It took 0.000000 sec to serialize a list with 1 elements. Mar 18, 2013 18:30:00:021 [5104] DEBUG - Caching document http://127.0.0.1:32400/library/metadata/31086 as 3c5712cd28029b0934187b0986953c80f67d3b45 Mar 18, 2013 18:30:00:021 [5104] DEBUG - Remuxing to hls/mpegts/h264/mp3 Mar 18, 2013 18:30:00:021 [5104] DEBUG - Found session GUID of bpib73lzgze in session start. Mar 18, 2013 18:30:00:021 [5104] DEBUG - Using session GUID bpib73lzgze for new transcode session. Mar 18, 2013 18:30:00:021 [5104] DEBUG - Cleaning directory for session bpib73lzgze (C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f) Mar 18, 2013 18:30:00:021 [5104] DEBUG - Saving session: bpib73lzgze Mar 18, 2013 18:30:00:068 [5224] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/index.m3u8 [192.168.1.5:50301] (6 live) Mar 18, 2013 18:30:00:068 [5224] DEBUG - Starting a transcode session bpib73lzgze at offset -1.0 (stopped=1) Mar 18, 2013 18:30:00:068 [5224] DEBUG - Job running: C:\Program Files (x86)\Plex\Plex Media Server\PlexNewTranscoder.exe -i "http://127.0.0.1:32400/library/parts/48316/file.mkv" -threads 0 -y -segment_format mpegts -f segment -loglevel quiet -progressurl http://127.0.0.1:32400/video/:/transcode/session/bpib73lzgze/progress -vcodec copy -bsf h264_mp4toannexb -flags -global_header -segment_time 10 -segment_start_number 0 -map 0:0 "-sn" -acodec libmp3lame -aq 2 -map 0:1 media-%05d.ts Mar 18, 2013 18:30:00:302 [5576] DEBUG - Request: GET /library/parts/48316/file.mkv [127.0.0.1:58549] (6 live) Mar 18, 2013 18:30:00:489 [0932] DEBUG - Request: GET /library/sections/10/recentlyAdded [50.18.148.15:56781] (6 live) Mar 18, 2013 18:30:00:489 [0932] DEBUG - We found auth token (uwYZxRhtAoC5oyYRpaih), enabling token-based authentication. Mar 18, 2013 18:30:00:489 [0932] DEBUG - Came in with the master token, authorization succeeded. Mar 18, 2013 18:30:00:505 [0932] DEBUG - It took 0.016000 sec to serialize a list with 8 elements. Mar 18, 2013 18:30:00:598 [5576] WARN - SLOW QUERY: It took 296.000000 ms to retrieve 1 items. Mar 18, 2013 18:30:00:598 [5576] DEBUG - Content-Length of Z:\Sports\Formula 1\Season 2012\Formula 1 - s2012e18 - Abu Dhabi Grand Prix - pt1.mkv is 4147196287. Mar 18, 2013 18:30:00:614 [0932] INFO - [Transcoder] Input #0, matroska,webm, from 'http://127.0.0.1:32400/library/parts/48316/file.mkv': Mar 18, 2013 18:30:00:630 [5576] INFO - [Transcoder] Stream #0:0: Video: h264 (High), yuv420p, 1280x720 [SAR 1:1 DAR 16:9], 25 fps, 25 tbr, 1k tbn, 50 tbc (default) Mar 18, 2013 18:30:00:630 [0932] INFO - [Transcoder] Stream #0:1: Audio: ac3, 48000 Hz, 5.1(side), fltp, 384 kb/s (default) Mar 18, 2013 18:30:00:630 [3164] DEBUG - [Transcoder] Average FPS ~ 25 fps, Frame rate ~ 25 fps. Mar 18, 2013 18:30:00:645 [3164] INFO - [Transcoder] Output #0, segment, to 'media-%05d.ts': Mar 18, 2013 18:30:00:645 [3164] INFO - [Transcoder] Stream #0:0: Video: h264, yuv420p, 1280x720 [SAR 1:1 DAR 16:9], q=2-31, 25 fps, 90k tbn, 25 tbc (default) Mar 18, 2013 18:30:00:645 [3164] INFO - [Transcoder] Stream #0:1: Audio: mp3, 48000 Hz, stereo, fltp (default) Mar 18, 2013 18:30:00:645 [3164] DEBUG - Request: PUT /video/:/transcode/session/bpib73lzgze/progress?width=1280&height=720 [127.0.0.1:58557] (7 live) Mar 18, 2013 18:30:00:645 [3164] DEBUG - * width => 1280 Mar 18, 2013 18:30:00:645 [3164] DEBUG - * height => 720 Mar 18, 2013 18:30:00:645 [3164] DEBUG - We want 7 segments ahead, last returned was -1 and max is -1. Mar 18, 2013 18:30:00:645 [3164] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:30:00:661 [5224] DEBUG - [FFMPEG] Duration: 7543 Mar 18, 2013 18:30:00:661 [5224] DEBUG - Read line, and done: 1 Mar 18, 2013 18:30:00:661 [5224] DEBUG - Building an M3U8 for 7543 total seconds. Mar 18, 2013 18:30:00:848 [5576] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00000.ts [192.168.1.5:50303] (7 live) Mar 18, 2013 18:30:00:848 [5576] DEBUG - Asked for segment 0 from session. Mar 18, 2013 18:30:00:879 [5104] DEBUG - Request: GET /library/sections/11/recentlyAddedGrandparents [50.18.148.15:56783] (7 live) Mar 18, 2013 18:30:00:879 [5104] DEBUG - We found auth token (uwYZxRhtAoC5oyYRpaih), enabling token-based authentication. Mar 18, 2013 18:30:00:879 [5104] DEBUG - Came in with the master token, authorization succeeded. Mar 18, 2013 18:30:00:879 [5104] DEBUG - It took 0.000000 sec to serialize a list with 3 elements. Mar 18, 2013 18:30:01:144 [5104] DEBUG - Request: GET /library/sections/1/recentlyAddedGrandparents [50.18.148.15:56787] (7 live) Mar 18, 2013 18:30:01:144 [5104] DEBUG - We found auth token (uwYZxRhtAoC5oyYRpaih), enabling token-based authentication. Mar 18, 2013 18:30:01:144 [5104] DEBUG - Came in with the master token, authorization succeeded. Mar 18, 2013 18:30:01:160 [5104] DEBUG - It took 0.000000 sec to serialize a list with 17 elements. Mar 18, 2013 18:30:01:394 [5576] DEBUG - Returning segment 0 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00000.ts Mar 18, 2013 18:30:01:394 [5576] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00000.ts is 6898660. Mar 18, 2013 18:30:01:472 [0932] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48316%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50305] (7 live) Mar 18, 2013 18:30:01:472 [0932] DEBUG - * time => NaN Mar 18, 2013 18:30:01:472 [0932] DEBUG - * duration => NaN Mar 18, 2013 18:30:01:472 [0932] DEBUG - * state => Mar 18, 2013 18:30:01:472 [0932] DEBUG - * key => /library/parts/48316/file.mkv Mar 18, 2013 18:30:01:472 [0932] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:30:01:472 [0932] INFO - Missing or invalid time parameter Mar 18, 2013 18:30:01:612 [3164] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00001.ts [192.168.1.5:50306] (7 live) Mar 18, 2013 18:30:01:612 [3164] DEBUG - Asked for segment 1 from session. Mar 18, 2013 18:30:02:049 [3164] DEBUG - Returning segment 1 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00001.ts Mar 18, 2013 18:30:02:049 [3164] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00001.ts is 6006224. Mar 18, 2013 18:30:02:658 [3164] DEBUG - Request: PUT /video/:/transcode/session/bpib73lzgze/progress?progress=0.4&size=-22&speed=16.1&remaining=466 [127.0.0.1:58558] (7 live) Mar 18, 2013 18:30:02:658 [3164] DEBUG - * progress => 0.4 Mar 18, 2013 18:30:02:658 [3164] DEBUG - * size => -22 Mar 18, 2013 18:30:02:658 [3164] DEBUG - * speed => 16.1 Mar 18, 2013 18:30:02:658 [3164] DEBUG - * remaining => 466 Mar 18, 2013 18:30:03:032 [3164] DEBUG - We want 7 segments ahead, last returned was 1 and max is 2. Mar 18, 2013 18:30:03:032 [3164] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:30:04:670 [5576] DEBUG - Request: PUT /video/:/transcode/session/bpib73lzgze/progress?progress=0.8&size=-22&speed=14.1&remaining=498 [127.0.0.1:58559] (7 live) Mar 18, 2013 18:30:04:670 [5576] DEBUG - * progress => 0.8 Mar 18, 2013 18:30:04:670 [5576] DEBUG - * size => -22 Mar 18, 2013 18:30:04:670 [5576] DEBUG - * speed => 14.1 Mar 18, 2013 18:30:04:670 [5576] DEBUG - * remaining => 498 Mar 18, 2013 18:30:05:107 [0932] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00745.ts [192.168.1.5:50312] (7 live) Mar 18, 2013 18:30:05:107 [0932] DEBUG - Asked for segment 745 from session. Mar 18, 2013 18:30:05:169 [5576] DEBUG - We want 7 segments ahead, last returned was 1 and max is 4. Mar 18, 2013 18:30:05:169 [5576] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:30:05:169 [0932] DEBUG - We're in a seek: asked for 745, min/max available was 0/4 Mar 18, 2013 18:30:05:169 [0932] DEBUG - Segment #745 WON. Mar 18, 2013 18:30:05:169 [0932] DEBUG - Stopping transcode session bpib73lzgze Mar 18, 2013 18:30:05:169 [0932] DEBUG - Killing job. Mar 18, 2013 18:30:05:169 [0932] DEBUG - Cleaning directory for session bpib73lzgze (C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f) Mar 18, 2013 18:30:05:419 [0932] DEBUG - Starting a transcode session bpib73lzgze at offset 7450.0 (stopped=1) Mar 18, 2013 18:30:05:419 [0932] DEBUG - Job running: C:\Program Files (x86)\Plex\Plex Media Server\PlexNewTranscoder.exe -ss 7450 -i "http://127.0.0.1:32400/library/parts/48316/file.mkv" -threads 0 -y -segment_format mpegts -f segment -loglevel quiet -progressurl http://127.0.0.1:32400/video/:/transcode/session/bpib73lzgze/progress -vcodec copy -bsf h264_mp4toannexb -flags -global_header -segment_time 10 -segment_start_number 745 -map 0:0 "-sn" -acodec libmp3lame -aq 2 -map 0:1 media-%05d.ts Mar 18, 2013 18:30:05:653 [5224] DEBUG - Request: GET /library/parts/48316/file.mkv [127.0.0.1:58560] (6 live) Mar 18, 2013 18:30:05:887 [5224] WARN - SLOW QUERY: It took 234.000000 ms to retrieve 1 items. Mar 18, 2013 18:30:05:902 [5224] DEBUG - Content-Length of Z:\Sports\Formula 1\Season 2012\Formula 1 - s2012e18 - Abu Dhabi Grand Prix - pt1.mkv is 4147196287. Mar 18, 2013 18:30:05:918 [5576] DEBUG - Request: GET /library/parts/48316/file.mkv [127.0.0.1:58561] (6 live) Mar 18, 2013 18:30:05:918 [5576] DEBUG - Request range: 4147173263 to 0 Mar 18, 2013 18:30:06:152 [5576] WARN - SLOW QUERY: It took 234.000000 ms to retrieve 1 items. Mar 18, 2013 18:30:06:152 [5576] DEBUG - Content-Length of Z:\Sports\Formula 1\Season 2012\Formula 1 - s2012e18 - Abu Dhabi Grand Prix - pt1.mkv is 4147196287. Mar 18, 2013 18:30:06:183 [3164] DEBUG - Request: GET /library/parts/48316/file.mkv [127.0.0.1:58562] (6 live) Mar 18, 2013 18:30:06:183 [3164] DEBUG - Request range: 55844 to 0 Mar 18, 2013 18:30:06:417 [3164] WARN - SLOW QUERY: It took 234.000000 ms to retrieve 1 items. Mar 18, 2013 18:30:06:417 [3164] DEBUG - Content-Length of Z:\Sports\Formula 1\Season 2012\Formula 1 - s2012e18 - Abu Dhabi Grand Prix - pt1.mkv is 4147196287. Mar 18, 2013 18:30:06:448 [3164] DEBUG - Request: GET /library/parts/48316/file.mkv [127.0.0.1:58563] (7 live) Mar 18, 2013 18:30:06:448 [3164] DEBUG - Request range: 4090476324 to 0 Mar 18, 2013 18:30:06:682 [3164] WARN - SLOW QUERY: It took 234.000000 ms to retrieve 1 items. Mar 18, 2013 18:30:06:682 [3164] DEBUG - Content-Length of Z:\Sports\Formula 1\Season 2012\Formula 1 - s2012e18 - Abu Dhabi Grand Prix - pt1.mkv is 4147196287. Mar 18, 2013 18:30:06:745 [5224] INFO - [Transcoder] Input #0, matroska,webm, from 'http://127.0.0.1:32400/library/parts/48316/file.mkv': Mar 18, 2013 18:30:06:745 [3164] INFO - [Transcoder] Stream #0:0: Video: h264 (High), yuv420p, 1280x720 [SAR 1:1 DAR 16:9], 25 fps, 25 tbr, 1k tbn, 50 tbc (default) Mar 18, 2013 18:30:06:745 [5224] INFO - [Transcoder] Stream #0:1: Audio: ac3, 48000 Hz, 5.1(side), fltp, 384 kb/s (default) Mar 18, 2013 18:30:06:760 [3164] DEBUG - [Transcoder] Average FPS ~ 25 fps, Frame rate ~ 25 fps. Mar 18, 2013 18:30:06:760 [5224] INFO - [Transcoder] Output #0, segment, to 'media-%05d.ts': Mar 18, 2013 18:30:06:760 [5224] INFO - [Transcoder] Stream #0:0: Video: h264, yuv420p, 1280x720 [SAR 1:1 DAR 16:9], q=2-31, 25 fps, 90k tbn, 25 tbc (default) Mar 18, 2013 18:30:06:760 [5224] INFO - [Transcoder] Stream #0:1: Audio: mp3, 48000 Hz, stereo, fltp (default) Mar 18, 2013 18:30:06:760 [5224] DEBUG - Request: PUT /video/:/transcode/session/bpib73lzgze/progress?width=1280&height=720 [127.0.0.1:58571] (7 live) Mar 18, 2013 18:30:06:760 [5224] DEBUG - * width => 1280 Mar 18, 2013 18:30:06:760 [5224] DEBUG - * height => 720 Mar 18, 2013 18:30:06:776 [5224] DEBUG - We want 7 segments ahead, last returned was 1 and max is -1. Mar 18, 2013 18:30:06:776 [5224] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:30:06:792 [0932] DEBUG - [FFMPEG] Duration: 7543 Mar 18, 2013 18:30:06:792 [0932] DEBUG - Read line, and done: 1 Mar 18, 2013 18:30:07:993 [0932] DEBUG - Returning segment 745 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00745.ts Mar 18, 2013 18:30:07:993 [0932] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00745.ts is 14049804. Mar 18, 2013 18:30:08:164 [5224] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48316%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50315] (7 live) Mar 18, 2013 18:30:08:164 [5224] DEBUG - * time => NaN Mar 18, 2013 18:30:08:164 [5224] DEBUG - * duration => NaN Mar 18, 2013 18:30:08:164 [5224] DEBUG - * state => Mar 18, 2013 18:30:08:164 [5224] DEBUG - * key => /library/parts/48316/file.mkv Mar 18, 2013 18:30:08:164 [5224] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:30:08:164 [5224] INFO - Missing or invalid time parameter Mar 18, 2013 18:30:08:788 [3164] DEBUG - Request: PUT /video/:/transcode/session/bpib73lzgze/progress?progress=0.3&size=-22&speed=11.7&remaining=640 [127.0.0.1:58572] (7 live) Mar 18, 2013 18:30:08:788 [3164] DEBUG - * progress => 0.3 Mar 18, 2013 18:30:08:788 [3164] DEBUG - * size => -22 Mar 18, 2013 18:30:08:788 [3164] DEBUG - * speed => 11.7 Mar 18, 2013 18:30:08:788 [3164] DEBUG - * remaining => 640 Mar 18, 2013 18:30:09:272 [3164] DEBUG - We want 7 segments ahead, last returned was 745 and max is 746. Mar 18, 2013 18:30:09:272 [3164] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:30:10:926 [5576] DEBUG - Request: PUT /video/:/transcode/session/bpib73lzgze/progress?progress=0.5&size=-22&speed=8.1&remaining=785 [127.0.0.1:58574] (7 live) Mar 18, 2013 18:30:10:926 [5576] DEBUG - * progress => 0.5 Mar 18, 2013 18:30:10:926 [5576] DEBUG - * size => -22 Mar 18, 2013 18:30:10:926 [5576] DEBUG - * speed => 8.1 Mar 18, 2013 18:30:10:926 [5576] DEBUG - * remaining => 785 Mar 18, 2013 18:30:11:238 [5576] DEBUG - We want 7 segments ahead, last returned was 745 and max is 748. Mar 18, 2013 18:30:11:238 [5576] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:30:11:550 [5224] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48316%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50320] (6 live) Mar 18, 2013 18:30:11:550 [5224] DEBUG - * time => NaN Mar 18, 2013 18:30:11:550 [5224] DEBUG - * duration => NaN Mar 18, 2013 18:30:11:550 [5224] DEBUG - * state => Mar 18, 2013 18:30:11:550 [5224] DEBUG - * key => /library/parts/48316/file.mkv Mar 18, 2013 18:30:11:550 [5224] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:30:11:550 [5224] INFO - Missing or invalid time parameter Mar 18, 2013 18:30:12:938 [5224] DEBUG - Request: PUT /video/:/transcode/session/bpib73lzgze/progress?progress=0.9&size=-22&speed=12.2&remaining=770 [127.0.0.1:58575] (6 live) Mar 18, 2013 18:30:12:938 [5224] DEBUG - * progress => 0.9 Mar 18, 2013 18:30:12:938 [5224] DEBUG - * size => -22 Mar 18, 2013 18:30:12:938 [5224] DEBUG - * speed => 12.2 Mar 18, 2013 18:30:12:938 [5224] DEBUG - * remaining => 770 Mar 18, 2013 18:30:12:938 [5224] DEBUG - We want 7 segments ahead, last returned was 745 and max is 750. Mar 18, 2013 18:30:12:938 [5224] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:30:14:498 [5224] DEBUG - Request: PUT /video/:/transcode/session/bpib73lzgze/progress?progress=1.2&size=-22&speed=13.7&remaining=577 [127.0.0.1:58576] (5 live) Mar 18, 2013 18:30:14:498 [5224] DEBUG - * progress => 1.2 Mar 18, 2013 18:30:14:498 [5224] DEBUG - * size => -22 Mar 18, 2013 18:30:14:498 [5224] DEBUG - * speed => 13.7 Mar 18, 2013 18:30:14:498 [5224] DEBUG - * remaining => 577 Mar 18, 2013 18:30:15:309 [5224] DEBUG - We want 7 segments ahead, last returned was 745 and max is 754. Mar 18, 2013 18:30:15:309 [5224] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:30:15:309 [0932] DEBUG - [Transcoder] Throttle - Going into sloth mode. Mar 18, 2013 18:30:16:308 [5576] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00746.ts [192.168.1.5:50331] (5 live) Mar 18, 2013 18:30:16:308 [5576] DEBUG - Asked for segment 746 from session. Mar 18, 2013 18:30:16:308 [5576] DEBUG - Returning segment 746 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00746.ts Mar 18, 2013 18:30:16:308 [5576] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00746.ts is 6746380. Mar 18, 2013 18:30:21:471 [5576] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48316%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50354] (4 live) Mar 18, 2013 18:30:21:471 [5576] DEBUG - * time => NaN Mar 18, 2013 18:30:21:471 [5576] DEBUG - * duration => NaN Mar 18, 2013 18:30:21:471 [5576] DEBUG - * state => Mar 18, 2013 18:30:21:471 [5576] DEBUG - * key => /library/parts/48316/file.mkv Mar 18, 2013 18:30:21:471 [5576] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:30:21:471 [5576] INFO - Missing or invalid time parameter Mar 18, 2013 18:30:24:529 [3412] ERROR - GetLineFromPipeWithTimeout timed out Mar 18, 2013 18:30:24:529 [3412] ERROR - Timeout reading status line from plug-in pipe [com.plexapp.plugins.spotify], we're killing it (got: ''). Mar 18, 2013 18:30:24:529 [3412] DEBUG - Stopping [com.plexapp.plugins.spotify]. Mar 18, 2013 18:30:24:529 [3412] DEBUG - [com.plexapp.plugins.spotify] Killing. Mar 18, 2013 18:30:24:529 [3412] ERROR - Error received reading configuration for com.plexapp.plugins.spotify Mar 18, 2013 18:30:24:529 [3412] DEBUG - Stopping [com.plexapp.plugins.spotify]. Mar 18, 2013 18:30:24:607 [5228] DEBUG - Done waiting for all plug-ins to start. Mar 18, 2013 18:30:24:607 [5228] DEBUG - Bonjour: updating PMS service record Mar 18, 2013 18:30:24:607 [5228] INFO - Bonjour: machineIdentifier = 6e186c42359e78e9c87c7998009a151e91cc6c8b, version = 0.9.7.17-1f0b170, playersModified = 1363645824.0 Mar 18, 2013 18:30:24:607 [5640] DEBUG - HTTP requesting to: https://my.plexapp.com/servers/6e186c42359e78e9c87c7998009a151e91cc6c8b/sync_lists?auth_token=uwYZxRhtAoC5oyYRpaih Mar 18, 2013 18:30:24:607 [5228] DEBUG - Bonjour: DNSServiceUpdateRecord succeeded Mar 18, 2013 18:30:24:607 [3656] DEBUG - Bonjour: DNSServiceQueryRecord_Callback succeeded, QueryRecordContext = 0x0803BED8 Mar 18, 2013 18:30:24:607 [3656] INFO - Bonjour: TXT record removed for YGGDRASIL._plexmediasvr._tcp.local. Mar 18, 2013 18:30:24:607 [3656] DEBUG - Bonjour: DNSServiceQueryRecord_Callback succeeded, QueryRecordContext = 0x0803BED8 Mar 18, 2013 18:30:24:607 [3656] INFO - Bonjour: TXT record added for YGGDRASIL._plexmediasvr._tcp.local. Mar 18, 2013 18:30:24:607 [1400] DEBUG - Notifying the system bundle an update to server /system/notify/serverUpdated?host=YGGDRASIL.local. Mar 18, 2013 18:30:24:607 [1400] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/notify/serverUpdated?host=YGGDRASIL.local. Mar 18, 2013 18:30:24:607 [1400] DEBUG - HTTP requesting to: http://127.0.0.1:58479/system/notify/serverUpdated?host=YGGDRASIL.local. Mar 18, 2013 18:30:24:607 [0932] DEBUG - Request: GET /servers [127.0.0.1:58582] (4 live) Mar 18, 2013 18:30:24:607 [0932] DEBUG - It took 0.000000 sec to serialize a list with 2 elements. Mar 18, 2013 18:30:24:622 [5224] DEBUG - Request: GET /library/sections [192.168.1.65:64290] (4 live) Mar 18, 2013 18:30:24:622 [5224] DEBUG - It took 0.000000 sec to serialize a list with 5 elements. Mar 18, 2013 18:30:24:638 [5224] DEBUG - Request: GET /channels/all [192.168.1.65:64291] (4 live) Mar 18, 2013 18:30:24:638 [5224] DEBUG - It took 0.000000 sec to serialize a list with 3 elements. Mar 18, 2013 18:30:24:638 [0932] DEBUG - Request: GET /library/sections [192.168.1.100:58585] (4 live) Mar 18, 2013 18:30:24:638 [0932] DEBUG - It took 0.000000 sec to serialize a list with 5 elements. Mar 18, 2013 18:30:24:654 [0932] DEBUG - Request: GET /channels/all [192.168.1.100:58586] (4 live) Mar 18, 2013 18:30:24:654 [0932] DEBUG - It took 0.000000 sec to serialize a list with 3 elements. Mar 18, 2013 18:30:24:654 [1400] DEBUG - [com.plexapp.system] HTTP reply status 200, with 0 bytes of content. Mar 18, 2013 18:30:25:184 [5640] DEBUG - Sync: downloaded 0 sync lists, analyzing now... Mar 18, 2013 18:30:25:184 [5640] INFO - Sync: analyzed 0 sync list(s) with 0 sync items(s) Mar 18, 2013 18:30:26:307 [0932] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00747.ts [192.168.1.5:50384] (4 live) Mar 18, 2013 18:30:26:307 [0932] DEBUG - Asked for segment 747 from session. Mar 18, 2013 18:30:26:307 [0932] DEBUG - Returning segment 747 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00747.ts Mar 18, 2013 18:30:26:307 [0932] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00747.ts is 7204724. Mar 18, 2013 18:30:31:471 [5576] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48316%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50416] (4 live) Mar 18, 2013 18:30:31:471 [5576] DEBUG - * time => NaN Mar 18, 2013 18:30:31:471 [5576] DEBUG - * duration => NaN Mar 18, 2013 18:30:31:471 [5576] DEBUG - * state => Mar 18, 2013 18:30:31:471 [5576] DEBUG - * key => /library/parts/48316/file.mkv Mar 18, 2013 18:30:31:471 [5576] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:30:31:471 [5576] INFO - Missing or invalid time parameter Mar 18, 2013 18:30:36:213 [0932] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00748.ts [192.168.1.5:50455] (3 live) Mar 18, 2013 18:30:36:213 [0932] DEBUG - Asked for segment 748 from session. Mar 18, 2013 18:30:36:213 [0932] DEBUG - Returning segment 748 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00748.ts Mar 18, 2013 18:30:36:213 [0932] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00748.ts is 4263652. Mar 18, 2013 18:30:41:471 [0932] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48316%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50471] (3 live) Mar 18, 2013 18:30:41:471 [0932] DEBUG - * time => NaN Mar 18, 2013 18:30:41:471 [0932] DEBUG - * duration => NaN Mar 18, 2013 18:30:41:471 [0932] DEBUG - * state => Mar 18, 2013 18:30:41:471 [0932] DEBUG - * key => /library/parts/48316/file.mkv Mar 18, 2013 18:30:41:471 [0932] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:30:41:471 [0932] INFO - Missing or invalid time parameter Mar 18, 2013 18:30:46:307 [2668] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00749.ts [192.168.1.5:50472] (3 live) Mar 18, 2013 18:30:46:307 [2668] DEBUG - Asked for segment 749 from session. Mar 18, 2013 18:30:46:307 [2668] DEBUG - Returning segment 749 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00749.ts Mar 18, 2013 18:30:46:307 [2668] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00749.ts is 4769748. Mar 18, 2013 18:30:51:486 [0932] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48316%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50475] (3 live) Mar 18, 2013 18:30:51:486 [0932] DEBUG - * time => NaN Mar 18, 2013 18:30:51:486 [0932] DEBUG - * duration => NaN Mar 18, 2013 18:30:51:486 [0932] DEBUG - * state => Mar 18, 2013 18:30:51:486 [0932] DEBUG - * key => /library/parts/48316/file.mkv Mar 18, 2013 18:30:51:486 [0932] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:30:51:486 [0932] INFO - Missing or invalid time parameter Mar 18, 2013 18:30:56:306 [0932] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00750.ts [192.168.1.5:50477] (3 live) Mar 18, 2013 18:30:56:306 [0932] DEBUG - Asked for segment 750 from session. Mar 18, 2013 18:30:56:306 [0932] DEBUG - Returning segment 750 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00750.ts Mar 18, 2013 18:30:56:306 [0932] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00750.ts is 3875244. Mar 18, 2013 18:31:01:485 [4480] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48316%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50479] (3 live) Mar 18, 2013 18:31:01:485 [4480] DEBUG - * time => NaN Mar 18, 2013 18:31:01:485 [4480] DEBUG - * duration => NaN Mar 18, 2013 18:31:01:485 [4480] DEBUG - * state => Mar 18, 2013 18:31:01:485 [4480] DEBUG - * key => /library/parts/48316/file.mkv Mar 18, 2013 18:31:01:485 [4480] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:31:01:485 [4480] INFO - Missing or invalid time parameter Mar 18, 2013 18:31:06:306 [0932] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00751.ts [192.168.1.5:50480] (3 live) Mar 18, 2013 18:31:06:306 [0932] DEBUG - Asked for segment 751 from session. Mar 18, 2013 18:31:06:306 [0932] DEBUG - Returning segment 751 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00751.ts Mar 18, 2013 18:31:06:306 [0932] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00751.ts is 9167444. Mar 18, 2013 18:31:11:469 [0932] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48316%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50484] (3 live) Mar 18, 2013 18:31:11:469 [0932] DEBUG - * time => NaN Mar 18, 2013 18:31:11:469 [0932] DEBUG - * duration => NaN Mar 18, 2013 18:31:11:469 [0932] DEBUG - * state => Mar 18, 2013 18:31:11:485 [0932] DEBUG - * key => /library/parts/48316/file.mkv Mar 18, 2013 18:31:11:485 [0932] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:31:11:485 [0932] INFO - Missing or invalid time parameter Mar 18, 2013 18:31:21:485 [2108] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48316%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50489] (3 live) Mar 18, 2013 18:31:21:485 [2108] DEBUG - * time => NaN Mar 18, 2013 18:31:21:485 [2108] DEBUG - * duration => NaN Mar 18, 2013 18:31:21:485 [2108] DEBUG - * state => Mar 18, 2013 18:31:21:485 [2108] DEBUG - * key => /library/parts/48316/file.mkv Mar 18, 2013 18:31:21:485 [2108] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:31:21:485 [2108] INFO - Missing or invalid time parameter Mar 18, 2013 18:31:23:310 [3648] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00752.ts [192.168.1.5:50490] (3 live) Mar 18, 2013 18:31:23:310 [3648] DEBUG - Asked for segment 752 from session. Mar 18, 2013 18:31:23:310 [3648] DEBUG - Returning segment 752 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00752.ts Mar 18, 2013 18:31:23:310 [3648] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00752.ts is 5318708. Mar 18, 2013 18:31:31:484 [2108] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48316%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50493] (3 live) Mar 18, 2013 18:31:31:484 [2108] DEBUG - * time => NaN Mar 18, 2013 18:31:31:484 [2108] DEBUG - * duration => NaN Mar 18, 2013 18:31:31:484 [2108] DEBUG - * state => Mar 18, 2013 18:31:31:484 [2108] DEBUG - * key => /library/parts/48316/file.mkv Mar 18, 2013 18:31:31:484 [2108] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:31:31:484 [2108] INFO - Missing or invalid time parameter Mar 18, 2013 18:31:33:309 [3648] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00753.ts [192.168.1.5:50494] (3 live) Mar 18, 2013 18:31:33:309 [3648] DEBUG - Asked for segment 753 from session. Mar 18, 2013 18:31:33:309 [3648] DEBUG - Returning segment 753 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00753.ts Mar 18, 2013 18:31:33:309 [3648] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00753.ts is 2979236. Mar 18, 2013 18:31:38:052 [3648] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00754.ts [192.168.1.5:50495] (3 live) Mar 18, 2013 18:31:38:052 [3648] DEBUG - Asked for segment 754 from session. Mar 18, 2013 18:31:38:052 [3648] DEBUG - Returning segment 754 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00754.ts Mar 18, 2013 18:31:38:052 [3648] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00754.ts is 242896. Mar 18, 2013 18:31:41:484 [4892] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48316%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50497] (3 live) Mar 18, 2013 18:31:41:484 [4892] DEBUG - * time => NaN Mar 18, 2013 18:31:41:484 [4892] DEBUG - * duration => NaN Mar 18, 2013 18:31:41:484 [4892] DEBUG - * state => Mar 18, 2013 18:31:41:484 [4892] DEBUG - * key => /library/parts/48316/file.mkv Mar 18, 2013 18:31:41:484 [4892] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:31:41:484 [4892] INFO - Missing or invalid time parameter Mar 18, 2013 18:31:50:766 [0832] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48316%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50501] (3 live) Mar 18, 2013 18:31:50:766 [0832] DEBUG - * time => NaN Mar 18, 2013 18:31:50:766 [0832] DEBUG - * duration => NaN Mar 18, 2013 18:31:50:766 [0832] DEBUG - * state => Mar 18, 2013 18:31:50:766 [0832] DEBUG - * key => /library/parts/48316/file.mkv Mar 18, 2013 18:31:50:766 [0832] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:31:50:766 [0832] INFO - Missing or invalid time parameter Mar 18, 2013 18:31:51:015 [4892] DEBUG - Request: GET /video/:/transcode/universal/start.m3u8?path=http%3A%2F%2F127.0.0.1%3A32400%2Flibrary%2Fmetadata%2F31086&session=bpib73lzgze&protocol=hls&offset=0&fastSeek=1&directPlay=0&directStream=1&videoQuality=75&videoResolution=1280x720&subtitleSize=100&audioBoost=100&X-Plex-Token=FCKqkE7yRmXePkCzhryw&X-Plex-Client-Identifier=bpib73lzgze&X-Plex-Product=Web+Client&X-Plex-Device=Windows&X-Plex-Platform=Firefox&X-Plex-Platform-Version=19&X-Plex-Version=0.9.9.11&X-Plex-Device-Name=Plex%2FWeb+(Firefox) [192.168.1.5:50503] (3 live) Mar 18, 2013 18:31:51:015 [4892] DEBUG - * path => http://127.0.0.1:32400/library/metadata/31086 Mar 18, 2013 18:31:51:015 [4892] DEBUG - * session => bpib73lzgze Mar 18, 2013 18:31:51:015 [4892] DEBUG - * protocol => hls Mar 18, 2013 18:31:51:015 [4892] DEBUG - * offset => 0 Mar 18, 2013 18:31:51:015 [4892] DEBUG - * fastSeek => 1 Mar 18, 2013 18:31:51:015 [4892] DEBUG - * directPlay => 0 Mar 18, 2013 18:31:51:015 [4892] DEBUG - * directStream => 1 Mar 18, 2013 18:31:51:015 [4892] DEBUG - * videoQuality => 75 Mar 18, 2013 18:31:51:015 [4892] DEBUG - * videoResolution => 1280x720 Mar 18, 2013 18:31:51:015 [4892] DEBUG - * subtitleSize => 100 Mar 18, 2013 18:31:51:015 [4892] DEBUG - * audioBoost => 100 Mar 18, 2013 18:31:51:015 [4892] DEBUG - * X-Plex-Token => FCKqkE7yRmXePkCzhryw Mar 18, 2013 18:31:51:015 [4892] DEBUG - * X-Plex-Client-Identifier => bpib73lzgze Mar 18, 2013 18:31:51:015 [4892] DEBUG - * X-Plex-Product => Web Client Mar 18, 2013 18:31:51:015 [4892] DEBUG - * X-Plex-Device => Windows Mar 18, 2013 18:31:51:015 [4892] DEBUG - * X-Plex-Platform => Firefox Mar 18, 2013 18:31:51:015 [4892] DEBUG - * X-Plex-Platform-Version => 19 Mar 18, 2013 18:31:51:015 [4892] DEBUG - * X-Plex-Version => 0.9.9.11 Mar 18, 2013 18:31:51:015 [4892] DEBUG - * X-Plex-Device-Name => Plex/Web (Firefox) Mar 18, 2013 18:31:51:015 [4892] DEBUG - Using profile Web Mar 18, 2013 18:31:51:015 [4892] DEBUG - Downloading document http://127.0.0.1:32400/library/metadata/31086 Mar 18, 2013 18:31:51:015 [4892] DEBUG - Cache hit for document http://127.0.0.1:32400/library/metadata/31086 Mar 18, 2013 18:31:51:015 [4892] DEBUG - HTTP requesting to: http://127.0.0.1:32400/library/metadata/31086 Mar 18, 2013 18:31:51:015 [5356] DEBUG - Request: GET /library/metadata/31086 [127.0.0.1:58592] (4 live) Mar 18, 2013 18:31:51:031 [5356] DEBUG - It took 0.000000 sec to serialize a list with 1 elements. Mar 18, 2013 18:31:51:031 [4892] DEBUG - Caching document http://127.0.0.1:32400/library/metadata/31086 as 3c5712cd28029b0934187b0986953c80f67d3b45 Mar 18, 2013 18:31:51:031 [4892] DEBUG - Remuxing to hls/mpegts/h264/mp3 Mar 18, 2013 18:31:51:031 [4892] DEBUG - Found session GUID of bpib73lzgze in session start. Mar 18, 2013 18:31:51:031 [4892] DEBUG - Using session GUID bpib73lzgze for new transcode session. Mar 18, 2013 18:31:51:031 [4892] DEBUG - Using existing transcode session. Mar 18, 2013 18:31:51:093 [0832] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/index.m3u8 [192.168.1.5:50504] (4 live) Mar 18, 2013 18:31:51:093 [0832] DEBUG - Building an M3U8 for 7543 total seconds. Mar 18, 2013 18:31:51:249 [0832] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00000.ts [192.168.1.5:50505] (4 live) Mar 18, 2013 18:31:51:249 [0832] DEBUG - Asked for segment 0 from session. Mar 18, 2013 18:31:51:265 [0832] DEBUG - We're in a seek: asked for 0, min/max available was 745/754 Mar 18, 2013 18:31:51:265 [0832] DEBUG - Segment #0 WON. Mar 18, 2013 18:31:51:265 [0832] DEBUG - Stopping transcode session bpib73lzgze Mar 18, 2013 18:31:51:265 [0832] DEBUG - Killing job. Mar 18, 2013 18:31:51:265 [0832] DEBUG - Cleaning directory for session bpib73lzgze (C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f) Mar 18, 2013 18:31:51:281 [0832] DEBUG - Starting a transcode session bpib73lzgze at offset 0.0 (stopped=1) Mar 18, 2013 18:31:51:281 [0832] DEBUG - Job running: C:\Program Files (x86)\Plex\Plex Media Server\PlexNewTranscoder.exe -i "http://127.0.0.1:32400/library/parts/48316/file.mkv" -threads 0 -y -segment_format mpegts -f segment -loglevel quiet -progressurl http://127.0.0.1:32400/video/:/transcode/session/bpib73lzgze/progress -vcodec copy -bsf h264_mp4toannexb -flags -global_header -segment_time 10 -segment_start_number 0 -map 0:0 "-sn" -acodec libmp3lame -aq 2 -map 0:1 media-%05d.ts Mar 18, 2013 18:31:51:515 [5356] DEBUG - Request: GET /library/parts/48316/file.mkv [127.0.0.1:58593] (4 live) Mar 18, 2013 18:31:51:749 [5356] WARN - SLOW QUERY: It took 234.000000 ms to retrieve 1 items. Mar 18, 2013 18:31:51:749 [5356] DEBUG - Content-Length of Z:\Sports\Formula 1\Season 2012\Formula 1 - s2012e18 - Abu Dhabi Grand Prix - pt1.mkv is 4147196287. Mar 18, 2013 18:31:51:780 [5356] INFO - [Transcoder] Input #0, matroska,webm, from 'http://127.0.0.1:32400/library/parts/48316/file.mkv': Mar 18, 2013 18:31:51:780 [4892] INFO - [Transcoder] Stream #0:0: Video: h264 (High), yuv420p, 1280x720 [SAR 1:1 DAR 16:9], 25 fps, 25 tbr, 1k tbn, 50 tbc (default) Mar 18, 2013 18:31:51:780 [5356] INFO - [Transcoder] Stream #0:1: Audio: ac3, 48000 Hz, 5.1(side), fltp, 384 kb/s (default) Mar 18, 2013 18:31:51:795 [5356] DEBUG - [Transcoder] Average FPS ~ 25 fps, Frame rate ~ 25 fps. Mar 18, 2013 18:31:51:795 [5356] INFO - [Transcoder] Output #0, segment, to 'media-%05d.ts': Mar 18, 2013 18:31:51:795 [4892] INFO - [Transcoder] Stream #0:0: Video: h264, yuv420p, 1280x720 [SAR 1:1 DAR 16:9], q=2-31, 25 fps, 90k tbn, 25 tbc (default) Mar 18, 2013 18:31:51:795 [4892] INFO - [Transcoder] Stream #0:1: Audio: mp3, 48000 Hz, stereo, fltp (default) Mar 18, 2013 18:31:51:795 [5356] DEBUG - Request: PUT /video/:/transcode/session/bpib73lzgze/progress?width=1280&height=720 [127.0.0.1:58601] (5 live) Mar 18, 2013 18:31:51:795 [5356] DEBUG - * width => 1280 Mar 18, 2013 18:31:51:795 [5356] DEBUG - * height => 720 Mar 18, 2013 18:31:51:795 [5356] DEBUG - We want 7 segments ahead, last returned was 754 and max is -1. Mar 18, 2013 18:31:51:795 [5356] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:31:51:811 [0832] DEBUG - [FFMPEG] Duration: 7543 Mar 18, 2013 18:31:51:811 [0832] DEBUG - Read line, and done: 1 Mar 18, 2013 18:31:52:373 [5356] DEBUG - Request: GET /servers [127.0.0.1:58602] (5 live) Mar 18, 2013 18:31:52:373 [5356] DEBUG - It took 0.000000 sec to serialize a list with 2 elements. Mar 18, 2013 18:31:52:373 [5356] DEBUG - Request: GET /library/sections [192.168.1.100:58603] (5 live) Mar 18, 2013 18:31:52:373 [5356] DEBUG - It took 0.000000 sec to serialize a list with 5 elements. Mar 18, 2013 18:31:52:388 [4892] DEBUG - Request: GET /channels/all [192.168.1.100:58604] (5 live) Mar 18, 2013 18:31:52:388 [4892] DEBUG - It took 0.000000 sec to serialize a list with 3 elements. Mar 18, 2013 18:31:52:809 [0832] DEBUG - Returning segment 0 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00000.ts Mar 18, 2013 18:31:52:809 [0832] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00000.ts is 6898660. Mar 18, 2013 18:31:52:934 [5356] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48317%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50507] (5 live) Mar 18, 2013 18:31:52:934 [5356] DEBUG - * time => NaN Mar 18, 2013 18:31:52:950 [5356] DEBUG - * duration => NaN Mar 18, 2013 18:31:52:950 [5356] DEBUG - * state => Mar 18, 2013 18:31:52:950 [5356] DEBUG - * key => /library/parts/48317/file.mkv Mar 18, 2013 18:31:52:950 [5356] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:31:52:950 [5356] INFO - Missing or invalid time parameter Mar 18, 2013 18:31:53:075 [0832] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00001.ts [192.168.1.5:50509] (5 live) Mar 18, 2013 18:31:53:075 [0832] DEBUG - Asked for segment 1 from session. Mar 18, 2013 18:31:53:293 [0832] DEBUG - Returning segment 1 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00001.ts Mar 18, 2013 18:31:53:293 [0832] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00001.ts is 6006224. Mar 18, 2013 18:31:53:808 [4892] DEBUG - Request: PUT /video/:/transcode/session/bpib73lzgze/progress?progress=0.4&size=-22&speed=15.0&remaining=501 [127.0.0.1:58607] (5 live) Mar 18, 2013 18:31:53:808 [4892] DEBUG - * progress => 0.4 Mar 18, 2013 18:31:53:808 [4892] DEBUG - * size => -22 Mar 18, 2013 18:31:53:808 [4892] DEBUG - * speed => 15.0 Mar 18, 2013 18:31:53:808 [4892] DEBUG - * remaining => 501 Mar 18, 2013 18:31:53:808 [4892] DEBUG - We want 7 segments ahead, last returned was 1 and max is 1. Mar 18, 2013 18:31:53:808 [4892] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:31:55:820 [5356] DEBUG - Request: PUT /video/:/transcode/session/bpib73lzgze/progress?progress=0.7&size=-22&speed=10.4&remaining=609 [127.0.0.1:58608] (5 live) Mar 18, 2013 18:31:55:820 [5356] DEBUG - * progress => 0.7 Mar 18, 2013 18:31:55:820 [5356] DEBUG - * size => -22 Mar 18, 2013 18:31:55:820 [5356] DEBUG - * speed => 10.4 Mar 18, 2013 18:31:55:820 [5356] DEBUG - * remaining => 609 Mar 18, 2013 18:31:55:820 [5356] DEBUG - We want 7 segments ahead, last returned was 1 and max is 4. Mar 18, 2013 18:31:55:820 [5356] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:32:02:123 [5356] DEBUG - Request: GET /video/:/transcode/universal/session/bpib73lzgze/base/00002.ts [192.168.1.5:50510] (5 live) Mar 18, 2013 18:32:02:123 [5356] DEBUG - Asked for segment 2 from session. Mar 18, 2013 18:32:02:123 [5356] DEBUG - Returning segment 2 from session: C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00002.ts Mar 18, 2013 18:32:02:123 [5356] DEBUG - Content-Length of C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f\media-00002.ts is 5264000. Mar 18, 2013 18:32:02:622 [5356] DEBUG - Request: PUT /video/:/transcode/session/bpib73lzgze/progress?progress=0.9&size=-22&speed=2.4&remaining=1916 [127.0.0.1:58610] (5 live) Mar 18, 2013 18:32:02:622 [5356] DEBUG - * progress => 0.9 Mar 18, 2013 18:32:02:622 [5356] DEBUG - * size => -22 Mar 18, 2013 18:32:02:622 [5356] DEBUG - * speed => 2.4 Mar 18, 2013 18:32:02:622 [5356] DEBUG - * remaining => 1916 Mar 18, 2013 18:32:02:622 [5356] DEBUG - We want 7 segments ahead, last returned was 2 and max is 5. Mar 18, 2013 18:32:02:622 [5356] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:32:04:634 [5004] DEBUG - Request: PUT /video/:/transcode/session/bpib73lzgze/progress?progress=1.3&size=-22&speed=17.1&remaining=1775 [127.0.0.1:58611] (4 live) Mar 18, 2013 18:32:04:634 [5004] DEBUG - * progress => 1.3 Mar 18, 2013 18:32:04:634 [5004] DEBUG - * size => -22 Mar 18, 2013 18:32:04:634 [5004] DEBUG - * speed => 17.1 Mar 18, 2013 18:32:04:634 [5004] DEBUG - * remaining => 1775 Mar 18, 2013 18:32:05:243 [4496] DEBUG - Request: GET /:/timeline?time=NaN&duration=NaN&state=&key=%2Flibrary%2Fparts%2F48317%2Ffile.mkv&ratingKey=31086 [192.168.1.5:50513] (5 live) Mar 18, 2013 18:32:05:243 [4496] DEBUG - * time => NaN Mar 18, 2013 18:32:05:243 [4496] DEBUG - * duration => NaN Mar 18, 2013 18:32:05:243 [4496] DEBUG - * state => Mar 18, 2013 18:32:05:243 [4496] DEBUG - * key => /library/parts/48317/file.mkv Mar 18, 2013 18:32:05:243 [4496] DEBUG - * ratingKey => 31086 Mar 18, 2013 18:32:05:243 [4496] INFO - Missing or invalid time parameter Mar 18, 2013 18:32:05:352 [5004] DEBUG - We want 7 segments ahead, last returned was 2 and max is 9. Mar 18, 2013 18:32:05:352 [5004] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:32:06:491 [5356] DEBUG - Request: GET /library/metadata/25982?checkFiles=1&skipRefresh=1 [192.168.1.5:50515] (5 live) Mar 18, 2013 18:32:06:491 [5356] DEBUG - * checkFiles => 1 Mar 18, 2013 18:32:06:491 [5356] DEBUG - * skipRefresh => 1 Mar 18, 2013 18:32:06:506 [5356] DEBUG - It took 0.000000 sec to serialize a list with 1 elements. Mar 18, 2013 18:32:06:787 [5356] DEBUG - Request: GET /library/metadata/25982/children [192.168.1.5:50516] (6 live) Mar 18, 2013 18:32:06:787 [4496] DEBUG - Request: GET /video/:/transcode/segmented/stop?session=bpib73lzgze [192.168.1.5:50517] (5 live) Mar 18, 2013 18:32:06:787 [4496] DEBUG - * session => bpib73lzgze Mar 18, 2013 18:32:06:787 [0276] DEBUG - Stopping transcode session bpib73lzgze Mar 18, 2013 18:32:06:787 [0276] DEBUG - Killing job. Mar 18, 2013 18:32:06:818 [5356] DEBUG - It took 0.000000 sec to serialize a list with 20 elements. Mar 18, 2013 18:32:07:021 [0276] DEBUG - Cleaning directory for session bpib73lzgze (C:\Users\ADMINI~1\AppData\Local\Temp\2\plex-transcode-bpib73lzgze-9344ebc4-2030-4d7f-b735-be5a783b632f) Mar 18, 2013 18:32:07:037 [0276] DEBUG - Whacked session, 0 remaining. Mar 18, 2013 18:32:07:037 [0276] DEBUG - It took 0.000000 sec to serialize a list with 0 elements. Mar 18, 2013 18:32:10:172 [3196] DEBUG - Ordered to stop server. Mar 18, 2013 18:32:10:172 [4852] DEBUG - Stopping server... Mar 18, 2013 18:32:10:172 [3720] DEBUG - Sync: cancelCurrentTranscode Mar 18, 2013 18:32:10:172 [4852] DEBUG - Server stopped. Mar 18, 2013 18:32:10:172 [4852] DEBUG - NetworkService: Stopping advertisement. Mar 18, 2013 18:32:10:172 [4852] DEBUG - Killing plug-ins. Mar 18, 2013 18:32:10:172 [4852] DEBUG - [com.plexapp.system] Killing. Mar 18, 2013 18:32:10:172 [4852] DEBUG - Waiting for DLNA server to exit. Mar 18, 2013 18:32:10:874 [3912] DEBUG - DLNA Server exited. Mar 18, 2013 18:32:10:874 [4852] DEBUG - WebKit: Stream closed. Mar 18, 2013 18:32:10:874 [4852] DEBUG - WK_BrowseToURL about:blank