2019-02-16 09:29:38,184 (279c) :  INFO (core:349) - Starting framework core - Version: 2.6.3, Build: cc260c4 (Fri Dec 14 11:21:01 UTC 2018)
2019-02-16 09:29:38,184 (279c) :  DEBUG (core:361) - Using the elevated policy
2019-02-16 09:29:38,184 (279c) :  DEBUG (core:450) - Starting runtime component.
2019-02-16 09:29:38,187 (279c) :  DEBUG (core:450) - Starting caching component.
2019-02-16 09:29:38,187 (279c) :  DEBUG (core:450) - Starting data component.
2019-02-16 09:29:38,187 (279c) :  DEBUG (core:450) - Starting networking component.
2019-02-16 09:29:38,188 (279c) :  DEBUG (networking:284) - Loaded HTTP cookies
2019-02-16 09:29:38,188 (279c) :  DEBUG (networking:452) - Setting the default network timeout to 20.0
2019-02-16 09:29:38,190 (279c) :  DEBUG (core:450) - Starting localization component.
2019-02-16 09:29:38,190 (279c) :  INFO (localization:409) - Setting the default locale to en-us
2019-02-16 09:29:38,190 (279c) :  DEBUG (core:450) - Starting messaging component.
2019-02-16 09:29:38,190 (279c) :  DEBUG (core:450) - Starting debugging component.
2019-02-16 09:29:38,190 (279c) :  DEBUG (core:450) - Starting services component.
2019-02-16 09:29:38,190 (279c) :  DEBUG (core:450) - Starting myplex component.
2019-02-16 09:29:38,190 (16e4) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/system/messaging/clear_events/com.plexapp.agents.lyricfind'
2019-02-16 09:29:38,191 (279c) :  DEBUG (core:450) - Starting notifications component.
2019-02-16 09:29:38,295 (279c) :  DEBUG (accessor:68) - Creating a new model access point for provider com.plexapp.agents.lyricfind in namespace 'metadata'
2019-02-16 09:29:38,299 (279c) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/resourceHashes'
2019-02-16 09:29:38,325 (279c) :  DEBUG (runtime:1117) - Created a thread named 'load_all_services'
2019-02-16 09:29:38,325 (24f8) :  DEBUG (services:265) - Plug-in is not daemonized - loading services from system
2019-02-16 09:29:38,326 (279c) :  DEBUG (runtime:1117) - Created a thread named 'get_server_info'
2019-02-16 09:29:38,328 (279c) :  DEBUG (core:150) - Finished starting framework core
2019-02-16 09:29:38,328 (279c) :  DEBUG (core:560) - Loading plug-in code
2019-02-16 09:29:38,328 (24f8) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_'
2019-02-16 09:29:38,328 (1ea8) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400'
2019-02-16 09:29:38,334 (1ea8) :  DEBUG (core:538) - Machine identifier is 4fc6fcbb720dfeaf43f7e287a162df51bc136a6e
2019-02-16 09:29:38,334 (1ea8) :  DEBUG (core:539) - Server version is 1.14.1.5488-cc260c476
2019-02-16 09:29:38,361 (279c) :  DEBUG (core:566) - Finished loading plug-in code
2019-02-16 09:29:38,362 (279c) :  DEBUG (agentkit:1115) - Creating new agent class called LyricFindAlbumAgent
2019-02-16 09:29:38,364 (279c) :  DEBUG (agentkit:933) - Updating agent information: [{'media_types': ['Album'], 'accepts_from': None, 'fallback_agent': None, 'contributes_to': ['com.plexapp.agents.plexmusic', 'com.plexapp.agents.localmedia', 'com.plexapp.agents.lastfm'], 'languages': ['xn'], 'persist_stored_files': True, 'version': 0, 'primary_provider': False, 'prefs': False, 'name': 'LyricFind'}]
2019-02-16 09:29:38,365 (279c) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X0FnZW50U2VydmljZTpVcGRhdGVJbmZv/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQo2CmRpY3QKbGlzdApkaWN0Cmxpc3QKbGlzdApsaXN0CjIKczI4CmNvbS5wbGV4YXBwLmFnZW50cy5seXJpY2ZpbmRzMTAKaWRlbnRpZmllcnIxCnMxMAphZ2VudF9pbmZvMQpyMgoxMApyMwpzMTEKbWVkaWFfdHlwZXNuczEyCmFjY2VwdHNfZnJvbW5zMTQKZmFsbGJhY2tfYWdlbnRyNApzMTQKY29udHJpYnV0ZXNfdG9yNQpzOQpsYW5ndWFnZXNiMXMyMApwZXJzaXN0X3N0b3JlZF9maWxlc2kwCnM3CnZlcnNpb25iMHMxNgpwcmltYXJ5X3Byb3ZpZGVyYjBzNQpwcmVmc3M5Ckx5cmljRmluZHM0Cm5hbWUxCnM1CkFsYnVtMwpzMjgKY29tLnBsZXhhcHAuYWdlbnRzLnBsZXhtdXNpY3MyOQpjb20ucGxleGFwcC5hZ2VudHMubG9jYWxtZWRpYXMyNQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtMQpzMgp4bnIwCg__'
2019-02-16 09:29:38,384 (279c) :  INFO (core:611) - Started plug-in
2019-02-16 09:29:38,384 (279c) :  DEBUG (socketinterface:160) - Starting socket server
2019-02-16 09:29:38,387 (279c) :  DEBUG (runtime:1117) - Created a thread named 'start'
2019-02-16 09:29:38,388 (279c) :  INFO (socketinterface:184) - Socket server started on port 55545
2019-02-16 09:29:38,388 (279c) :  INFO (pipeinterface:25) - Entering run loop
2019-02-16 09:29:38,388 (279c) :  DEBUG (runtime:717) - Handling request GET /:/prefixes
2019-02-16 09:29:38,391 (279c) :  DEBUG (runtime:814) - Found route matching /:/prefixes
2019-02-16 09:29:38,392 (279c) :  DEBUG (runtime:924) - Response: [200] MediaContainer, 153 bytes
2019-02-16 09:29:38,414 (2138) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCnhuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM1CjE2ODgzczgKcGFyZW50SURzMTMKbG9jYWw6Ly8xNjg4OHM0Cmd1aWRiMXM1CmZvcmNlczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhczEzCnByaW1hcnlfYWdlbnRzNQoxNjg4OHMyCmlkcjAK
2019-02-16 09:29:38,414 (2138) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2019-02-16 09:29:38,450 (2138) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCnhuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM1CjE2ODgzczgKcGFyZW50SURzMTMKbG9jYWw6Ly8xNjg4OHM0Cmd1aWRiMXM1CmZvcmNlczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhczEzCnByaW1hcnlfYWdlbnRzNQoxNjg4OHMyCmlkcjAK
2019-02-16 09:29:38,451 (2138) :  INFO (agentkit:957) - Searching for matches for {'id': '16888', 'guid': 'local://16888', 'force': True, 'primary_agent': 'com.plexapp.agents.localmedia', 'parentID': '16883'}
2019-02-16 09:29:38,453 (2138) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16888/tree'
2019-02-16 09:29:38,456 (24f8) :  DEBUG (services:362) - Loaded services
2019-02-16 09:29:38,460 (1430) :  DEBUG (services:438) - No shared code to load
2019-02-16 09:29:38,460 (2138) :  DEBUG (accessor:68) - Creating a new read-only model access point for provider com.plexapp.agents.localmedia in namespace 'metadata'
2019-02-16 09:29:38,463 (2138) :  DEBUG (model:32) - Loading model with GUID local://16888
2019-02-16 09:29:38,464 (2138) :  DEBUG (model:234) - Deserializing from C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\6\13b5533418f5a7a388c0afcea7c9297a969dab5.bundle\Contents\com.plexapp.agents.localmedia\Info.xml
2019-02-16 09:29:38,470 (2138) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16883/tree'
2019-02-16 09:29:38,502 (2138) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2019-02-16 09:29:38,502 (2138) :  DEBUG (runtime:924) - Response: [200] str, 300 bytes
2019-02-16 09:29:38,509 (1e08) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKeG5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNQoxNjg4OHM0CmRiaWRpMApzNwp2ZXJzaW9uczEzCmxvY2FsOi8vMTY4ODNzMTAKcGFyZW50R1VJRHM1CjE2ODgzczgKcGFyZW50SURzNQpBbGJ1bXMxMAptZWRpYV90eXBlczEzCmxvY2FsOi8vMTY4ODhzNApndWlkczQKbnVsbHMyCmlkcjAK
2019-02-16 09:29:38,509 (1e08) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2019-02-16 09:29:38,510 (1e08) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKeG5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNQoxNjg4OHM0CmRiaWRpMApzNwp2ZXJzaW9uczEzCmxvY2FsOi8vMTY4ODNzMTAKcGFyZW50R1VJRHM1CjE2ODgzczgKcGFyZW50SURzNQpBbGJ1bXMxMAptZWRpYV90eXBlczEzCmxvY2FsOi8vMTY4ODhzNApndWlkczQKbnVsbHMyCmlkcjAK
2019-02-16 09:29:38,510 (1e08) :  DEBUG (model:32) - Loading model with GUID local://16888
2019-02-16 09:29:38,512 (1e08) :  DEBUG (model:234) - Deserializing from C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\6\13b5533418f5a7a388c0afcea7c9297a969dab5.bundle\Contents\com.plexapp.agents.lyricfind\Info.xml
2019-02-16 09:29:38,513 (1e08) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16888/tree'
2019-02-16 09:29:38,519 (1e08) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=Leonard%20Cohen&album=I%27m%20Your%20Man'
2019-02-16 09:29:39,125 (1e08) :  DEBUG (threadkit:234) - Starting a parallel task set named MatchLyrics with 1 tasks
2019-02-16 09:29:39,128 (24c0) :  INFO (logkit:16) - Adding Lyric Ain't No Cure for Love to track Ain't No Cure for Love
2019-02-16 09:29:39,131 (1e08) :  DEBUG (threadkit:244) - Parallel task set MatchLyrics ended
2019-02-16 09:29:39,164 (1e08) :  DEBUG (model:229) - Serializing to C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\6\13b5533418f5a7a388c0afcea7c9297a969dab5.bundle\Contents\com.plexapp.agents.lyricfind\Info.xml
2019-02-16 09:29:39,170 (1e08) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2019-02-16 09:29:39,171 (1e08) :  DEBUG (runtime:924) - Response: [200] str, 16 bytes
2019-02-16 09:52:06,890 (1be8) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCnhuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM1CjE2ODgzczgKcGFyZW50SURzMTMKbG9jYWw6Ly8xNjkwOHM0Cmd1aWRiMXM1CmZvcmNlczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhczEzCnByaW1hcnlfYWdlbnRzNQoxNjkwOHMyCmlkcjAK
2019-02-16 09:52:06,891 (1be8) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2019-02-16 09:52:06,891 (1be8) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCnhuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM1CjE2ODgzczgKcGFyZW50SURzMTMKbG9jYWw6Ly8xNjkwOHM0Cmd1aWRiMXM1CmZvcmNlczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhczEzCnByaW1hcnlfYWdlbnRzNQoxNjkwOHMyCmlkcjAK
2019-02-16 09:52:06,891 (1be8) :  INFO (agentkit:957) - Searching for matches for {'id': '16908', 'guid': 'local://16908', 'force': True, 'primary_agent': 'com.plexapp.agents.localmedia', 'parentID': '16883'}
2019-02-16 09:52:06,892 (1be8) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16908/tree'
2019-02-16 09:52:06,898 (1be8) :  DEBUG (model:32) - Loading model with GUID local://16908
2019-02-16 09:52:06,900 (1be8) :  DEBUG (model:234) - Deserializing from C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\d\4272cc07c37be43bf5488e20faba4ca1bc4d8b0.bundle\Contents\com.plexapp.agents.localmedia\Info.xml
2019-02-16 09:52:06,901 (1be8) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16883/tree'
2019-02-16 09:52:06,930 (1be8) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2019-02-16 09:52:06,931 (1be8) :  DEBUG (runtime:924) - Response: [200] str, 300 bytes
2019-02-16 09:52:06,947 (1ed8) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKeG5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNQoxNjkwOHM0CmRiaWRpMApzNwp2ZXJzaW9uczEzCmxvY2FsOi8vMTY4ODNzMTAKcGFyZW50R1VJRHM1CjE2ODgzczgKcGFyZW50SURzNQpBbGJ1bXMxMAptZWRpYV90eXBlczEzCmxvY2FsOi8vMTY5MDhzNApndWlkczQKbnVsbHMyCmlkcjAK
2019-02-16 09:52:06,948 (1ed8) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2019-02-16 09:52:06,950 (1ed8) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKeG5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNQoxNjkwOHM0CmRiaWRpMApzNwp2ZXJzaW9uczEzCmxvY2FsOi8vMTY4ODNzMTAKcGFyZW50R1VJRHM1CjE2ODgzczgKcGFyZW50SURzNQpBbGJ1bXMxMAptZWRpYV90eXBlczEzCmxvY2FsOi8vMTY5MDhzNApndWlkczQKbnVsbHMyCmlkcjAK
2019-02-16 09:52:06,950 (1ed8) :  DEBUG (model:32) - Loading model with GUID local://16908
2019-02-16 09:52:06,950 (1ed8) :  DEBUG (model:234) - Deserializing from C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\d\4272cc07c37be43bf5488e20faba4ca1bc4d8b0.bundle\Contents\com.plexapp.agents.lyricfind\Info.xml
2019-02-16 09:52:06,953 (1ed8) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16908/tree'
2019-02-16 09:52:06,960 (1ed8) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=Leonard%20Cohen&album=Various%20Positions'
2019-02-16 09:52:07,596 (1ed8) :  DEBUG (threadkit:234) - Starting a parallel task set named MatchLyrics with 3 tasks
2019-02-16 09:52:07,601 (188c) :  INFO (logkit:16) - Adding Lyric The Law to track The Law
2019-02-16 09:52:07,608 (8cc) :  INFO (logkit:16) - Adding Lyric If It Be Your Will to track If It Be Your Will
2019-02-16 09:52:07,609 (18c0) :  INFO (logkit:16) - Adding Lyric Coming Back to You to track Coming Back to You
2019-02-16 09:52:07,611 (1ed8) :  DEBUG (threadkit:244) - Parallel task set MatchLyrics ended
2019-02-16 09:52:07,676 (1ed8) :  DEBUG (model:229) - Serializing to C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\d\4272cc07c37be43bf5488e20faba4ca1bc4d8b0.bundle\Contents\com.plexapp.agents.lyricfind\Info.xml
2019-02-16 09:52:07,680 (1ed8) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2019-02-16 09:52:07,680 (1ed8) :  DEBUG (runtime:924) - Response: [200] str, 16 bytes
2019-02-16 09:54:10,390 (1ef8) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCnhuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM1CjE2ODgzczgKcGFyZW50SURzMTMKbG9jYWw6Ly8xNjg5NXM0Cmd1aWRiMXM1CmZvcmNlczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhczEzCnByaW1hcnlfYWdlbnRzNQoxNjg5NXMyCmlkcjAK
2019-02-16 09:54:10,391 (1ef8) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2019-02-16 09:54:10,391 (1ef8) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCnhuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM1CjE2ODgzczgKcGFyZW50SURzMTMKbG9jYWw6Ly8xNjg5NXM0Cmd1aWRiMXM1CmZvcmNlczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhczEzCnByaW1hcnlfYWdlbnRzNQoxNjg5NXMyCmlkcjAK
2019-02-16 09:54:10,391 (1ef8) :  INFO (agentkit:957) - Searching for matches for {'id': '16895', 'guid': 'local://16895', 'force': True, 'primary_agent': 'com.plexapp.agents.localmedia', 'parentID': '16883'}
2019-02-16 09:54:10,392 (1ef8) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16895/tree'
2019-02-16 09:54:10,401 (1ef8) :  DEBUG (model:32) - Loading model with GUID local://16895
2019-02-16 09:54:10,401 (1ef8) :  DEBUG (model:234) - Deserializing from C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\1\8a9c1c20d03024cd52d3c20f49565e27f6b32e5.bundle\Contents\com.plexapp.agents.localmedia\Info.xml
2019-02-16 09:54:10,401 (1ef8) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16883/tree'
2019-02-16 09:54:10,433 (1ef8) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2019-02-16 09:54:10,434 (1ef8) :  DEBUG (runtime:924) - Response: [200] str, 300 bytes
2019-02-16 09:54:10,450 (2464) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKeG5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNQoxNjg5NXM0CmRiaWRpMApzNwp2ZXJzaW9uczEzCmxvY2FsOi8vMTY4ODNzMTAKcGFyZW50R1VJRHM1CjE2ODgzczgKcGFyZW50SURzNQpBbGJ1bXMxMAptZWRpYV90eXBlczEzCmxvY2FsOi8vMTY4OTVzNApndWlkczQKbnVsbHMyCmlkcjAK
2019-02-16 09:54:10,450 (2464) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2019-02-16 09:54:10,451 (2464) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKeG5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNQoxNjg5NXM0CmRiaWRpMApzNwp2ZXJzaW9uczEzCmxvY2FsOi8vMTY4ODNzMTAKcGFyZW50R1VJRHM1CjE2ODgzczgKcGFyZW50SURzNQpBbGJ1bXMxMAptZWRpYV90eXBlczEzCmxvY2FsOi8vMTY4OTVzNApndWlkczQKbnVsbHMyCmlkcjAK
2019-02-16 09:54:10,451 (2464) :  DEBUG (model:32) - Loading model with GUID local://16895
2019-02-16 09:54:10,453 (2464) :  DEBUG (model:234) - Deserializing from C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\1\8a9c1c20d03024cd52d3c20f49565e27f6b32e5.bundle\Contents\com.plexapp.agents.lyricfind\Info.xml
2019-02-16 09:54:10,457 (2464) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16895/tree'
2019-02-16 09:54:10,466 (2464) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=Leonard%20Cohen&album=Songs%20of%20Love%20and%20Hate'
2019-02-16 09:54:10,990 (2464) :  DEBUG (threadkit:234) - Starting a parallel task set named MatchLyrics with 7 tasks
2019-02-16 09:54:10,993 (1890) :  INFO (logkit:16) - Adding Lyric Avalanche to track Avalanche
2019-02-16 09:54:10,996 (2188) :  INFO (logkit:16) - Adding Lyric Last Year's Man to track Last Year's Man
2019-02-16 09:54:11,005 (1250) :  INFO (logkit:16) - Adding Lyric Dress Rehearsal Rag to track Dress Rehearsal Rag
2019-02-16 09:54:11,010 (838) :  INFO (logkit:16) - Adding Lyric Diamonds in the Mine to track Diamonds In The Mine
2019-02-16 09:54:11,023 (1890) :  INFO (logkit:16) - Adding Lyric Love Calls You by Your Name to track Love Calls You By Your Name
2019-02-16 09:54:11,025 (2188) :  INFO (logkit:16) - Adding Lyric Famous Blue Raincoat to track Famous Blue Raincoat
2019-02-16 09:54:11,036 (1250) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=Leonard%20Cohen&track=Sing%20Another%20Song%2C%20Boys'
2019-02-16 09:54:11,642 (2464) :  DEBUG (threadkit:244) - Parallel task set MatchLyrics ended
2019-02-16 09:54:11,734 (2464) :  DEBUG (model:229) - Serializing to C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\1\8a9c1c20d03024cd52d3c20f49565e27f6b32e5.bundle\Contents\com.plexapp.agents.lyricfind\Info.xml
2019-02-16 09:54:11,739 (2464) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2019-02-16 09:54:11,739 (2464) :  DEBUG (runtime:924) - Response: [200] str, 16 bytes
2019-02-16 09:55:50,941 (16c8) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCnhuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM1CjE2ODgzczgKcGFyZW50SURzMTMKbG9jYWw6Ly8xNjkyMHM0Cmd1aWRiMXM1CmZvcmNlczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhczEzCnByaW1hcnlfYWdlbnRzNQoxNjkyMHMyCmlkcjAK
2019-02-16 09:55:50,943 (16c8) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2019-02-16 09:55:50,944 (16c8) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCnhuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM1CjE2ODgzczgKcGFyZW50SURzMTMKbG9jYWw6Ly8xNjkyMHM0Cmd1aWRiMXM1CmZvcmNlczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhczEzCnByaW1hcnlfYWdlbnRzNQoxNjkyMHMyCmlkcjAK
2019-02-16 09:55:50,944 (16c8) :  INFO (agentkit:957) - Searching for matches for {'id': '16920', 'guid': 'local://16920', 'force': True, 'primary_agent': 'com.plexapp.agents.localmedia', 'parentID': '16883'}
2019-02-16 09:55:50,948 (16c8) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16920/tree'
2019-02-16 09:55:50,957 (16c8) :  DEBUG (model:32) - Loading model with GUID local://16920
2019-02-16 09:55:50,957 (16c8) :  DEBUG (model:234) - Deserializing from C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\7\736d919f956eab9e0b38199f6c9633987779827.bundle\Contents\com.plexapp.agents.localmedia\Info.xml
2019-02-16 09:55:50,960 (16c8) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16883/tree'
2019-02-16 09:55:50,990 (16c8) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2019-02-16 09:55:50,990 (16c8) :  DEBUG (runtime:924) - Response: [200] str, 300 bytes
2019-02-16 09:55:51,006 (17bc) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKeG5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNQoxNjkyMHM0CmRiaWRpMApzNwp2ZXJzaW9uczEzCmxvY2FsOi8vMTY4ODNzMTAKcGFyZW50R1VJRHM1CjE2ODgzczgKcGFyZW50SURzNQpBbGJ1bXMxMAptZWRpYV90eXBlczEzCmxvY2FsOi8vMTY5MjBzNApndWlkczQKbnVsbHMyCmlkcjAK
2019-02-16 09:55:51,007 (17bc) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2019-02-16 09:55:51,009 (17bc) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKeG5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNQoxNjkyMHM0CmRiaWRpMApzNwp2ZXJzaW9uczEzCmxvY2FsOi8vMTY4ODNzMTAKcGFyZW50R1VJRHM1CjE2ODgzczgKcGFyZW50SURzNQpBbGJ1bXMxMAptZWRpYV90eXBlczEzCmxvY2FsOi8vMTY5MjBzNApndWlkczQKbnVsbHMyCmlkcjAK
2019-02-16 09:55:51,009 (17bc) :  DEBUG (model:32) - Loading model with GUID local://16920
2019-02-16 09:55:51,009 (17bc) :  ERROR (model:205) - Cannot read model from C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\7\736d919f956eab9e0b38199f6c9633987779827.bundle\Contents\com.plexapp.agents.lyricfind
2019-02-16 09:55:51,009 (17bc) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16920/tree'
2019-02-16 09:55:51,023 (17bc) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=Leonard%20Cohen&album=Songs%20of%20Leonard%20Cohen'
2019-02-16 09:55:51,707 (17bc) :  DEBUG (threadkit:234) - Starting a parallel task set named MatchLyrics with 10 tasks
2019-02-16 09:55:51,710 (1a80) :  INFO (logkit:16) - Adding Lyric Suzanne to track Suzanne
2019-02-16 09:55:51,716 (48c) :  INFO (logkit:16) - Adding Lyric The Stranger Song to track The Stranger Song
2019-02-16 09:55:51,723 (2040) :  INFO (logkit:16) - Adding Lyric Master Song to track Master Song
2019-02-16 09:55:51,724 (1a80) :  INFO (logkit:16) - Adding Lyric Sisters of Mercy to track Sisters Of Mercy
2019-02-16 09:55:51,726 (168c) :  INFO (logkit:16) - Adding Lyric Winter Lady to track Winter Lady
2019-02-16 09:55:51,742 (48c) :  INFO (logkit:16) - Adding Lyric So Long, Marianne to track So Long, Marianne
2019-02-16 09:55:51,743 (168c) :  INFO (logkit:16) - Adding Lyric Teachers to track Teachers
2019-02-16 09:55:51,752 (2040) :  INFO (logkit:16) - Adding Lyric Hey, That's No Way to Say Goodbye to track Hey, That's No Way To Say Goodbye
2019-02-16 09:55:51,756 (1a80) :  INFO (logkit:16) - Adding Lyric Stories of the Street to track Stories Of The Street
2019-02-16 09:55:51,763 (48c) :  INFO (logkit:16) - Adding Lyric One of Us Cannot Be Wrong to track One Of Us Cannot Be Wrong
2019-02-16 09:55:51,763 (17bc) :  DEBUG (threadkit:244) - Parallel task set MatchLyrics ended
2019-02-16 09:55:51,885 (17bc) :  DEBUG (model:229) - Serializing to C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\7\736d919f956eab9e0b38199f6c9633987779827.bundle\Contents\com.plexapp.agents.lyricfind\Info.xml
2019-02-16 09:55:51,888 (17bc) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2019-02-16 09:55:51,888 (17bc) :  DEBUG (runtime:924) - Response: [200] str, 16 bytes
2019-02-16 09:57:41,094 (1168) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCnhuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM1CjE2ODgzczgKcGFyZW50SURzMTMKbG9jYWw6Ly8xNjkyNnM0Cmd1aWRiMXM1CmZvcmNlczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhczEzCnByaW1hcnlfYWdlbnRzNQoxNjkyNnMyCmlkcjAK
2019-02-16 09:57:41,095 (1168) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2019-02-16 09:57:41,095 (1168) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCnhuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM1CjE2ODgzczgKcGFyZW50SURzMTMKbG9jYWw6Ly8xNjkyNnM0Cmd1aWRiMXM1CmZvcmNlczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhczEzCnByaW1hcnlfYWdlbnRzNQoxNjkyNnMyCmlkcjAK
2019-02-16 09:57:41,095 (1168) :  INFO (agentkit:957) - Searching for matches for {'id': '16926', 'guid': 'local://16926', 'force': True, 'primary_agent': 'com.plexapp.agents.localmedia', 'parentID': '16883'}
2019-02-16 09:57:41,096 (1168) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16926/tree'
2019-02-16 09:57:41,105 (1168) :  DEBUG (model:32) - Loading model with GUID local://16926
2019-02-16 09:57:41,107 (1168) :  DEBUG (model:234) - Deserializing from C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\1\1579c2721c89dde5eb0fb58688588fafc652e48.bundle\Contents\com.plexapp.agents.localmedia\Info.xml
2019-02-16 09:57:41,108 (1168) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16883/tree'
2019-02-16 09:57:41,141 (1168) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2019-02-16 09:57:41,141 (1168) :  DEBUG (runtime:924) - Response: [200] str, 300 bytes
2019-02-16 09:57:41,157 (1f80) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKeG5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNQoxNjkyNnM0CmRiaWRpMApzNwp2ZXJzaW9uczEzCmxvY2FsOi8vMTY4ODNzMTAKcGFyZW50R1VJRHM1CjE2ODgzczgKcGFyZW50SURzNQpBbGJ1bXMxMAptZWRpYV90eXBlczEzCmxvY2FsOi8vMTY5MjZzNApndWlkczQKbnVsbHMyCmlkcjAK
2019-02-16 09:57:41,158 (1f80) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2019-02-16 09:57:41,160 (1f80) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKeG5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNQoxNjkyNnM0CmRiaWRpMApzNwp2ZXJzaW9uczEzCmxvY2FsOi8vMTY4ODNzMTAKcGFyZW50R1VJRHM1CjE2ODgzczgKcGFyZW50SURzNQpBbGJ1bXMxMAptZWRpYV90eXBlczEzCmxvY2FsOi8vMTY5MjZzNApndWlkczQKbnVsbHMyCmlkcjAK
2019-02-16 09:57:41,160 (1f80) :  DEBUG (model:32) - Loading model with GUID local://16926
2019-02-16 09:57:41,161 (1f80) :  DEBUG (model:234) - Deserializing from C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\1\1579c2721c89dde5eb0fb58688588fafc652e48.bundle\Contents\com.plexapp.agents.lyricfind\Info.xml
2019-02-16 09:57:41,167 (1f80) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/16926/tree'
2019-02-16 09:57:41,177 (1f80) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=Leonard%20Cohen&album=You%20Want%20It%20Darker'
2019-02-16 09:57:41,280 (1f80) :  DEBUG (threadkit:234) - Starting a parallel task set named MatchLyrics with 9 tasks
2019-02-16 09:57:41,293 (11e8) :  INFO (logkit:16) - Adding Lyric Treaty to track Treaty
2019-02-16 09:57:41,302 (f08) :  INFO (logkit:16) - Adding Lyric On the Level to track On the Level
2019-02-16 09:57:41,306 (1f54) :  INFO (logkit:16) - Adding Lyric Leaving the Table to track Leaving the Table
2019-02-16 09:57:41,315 (f08) :  INFO (logkit:16) - Adding Lyric Traveling Light to track Traveling Light
2019-02-16 09:57:41,315 (1b94) :  INFO (logkit:16) - Adding Lyric You Want It Darker to track You Want It Darker
2019-02-16 09:57:41,319 (f08) :  INFO (logkit:16) - Adding Lyric Steer Your Way to track Steer Your Way
2019-02-16 09:57:41,321 (1f54) :  INFO (logkit:16) - Adding Lyric It Seemed the Better Way to track It Seemed the Better Way
2019-02-16 09:57:41,322 (11e8) :  INFO (logkit:16) - Adding Lyric If I Didn't Have Your Love to track If I Didn't Have Your Love
2019-02-16 09:57:41,328 (1b94) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=Leonard%20Cohen&track=String%20Reprise%20/%20Treaty'
2019-02-16 09:57:41,411 (1f80) :  DEBUG (threadkit:244) - Parallel task set MatchLyrics ended
2019-02-16 09:57:41,520 (1f80) :  DEBUG (model:229) - Serializing to C:\Users\Stephen\AppData\Local\Plex Media Server\Metadata\Albums\1\1579c2721c89dde5eb0fb58688588fafc652e48.bundle\Contents\com.plexapp.agents.lyricfind\Info.xml
2019-02-16 09:57:41,523 (1f80) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2019-02-16 09:57:41,523 (1f80) :  DEBUG (runtime:924) - Response: [200] str, 16 bytes
