2017-06-08 12:19:59,430 (7f7330c85740) :  INFO (core:349) - Starting framework core - Version: 2.6.3, Build: 995f1de (Wed Apr 12 21:33:54 UTC 2017)
2017-06-08 12:19:59,430 (7f7330c85740) :  DEBUG (core:361) - Using the elevated policy
2017-06-08 12:19:59,430 (7f7330c85740) :  DEBUG (core:450) - Starting runtime component.
2017-06-08 12:19:59,443 (7f7330c85740) :  DEBUG (core:450) - Starting caching component.
2017-06-08 12:19:59,443 (7f7330c85740) :  DEBUG (core:450) - Starting data component.
2017-06-08 12:19:59,443 (7f7330c85740) :  DEBUG (core:450) - Starting networking component.
2017-06-08 12:19:59,445 (7f7330c85740) :  DEBUG (networking:284) - Loaded HTTP cookies
2017-06-08 12:19:59,447 (7f7330c85740) :  DEBUG (networking:452) - Setting the default network timeout to 20.0
2017-06-08 12:19:59,448 (7f7330c85740) :  DEBUG (core:450) - Starting localization component.
2017-06-08 12:19:59,448 (7f7330c85740) :  INFO (localization:409) - Setting the default locale to en-us
2017-06-08 12:19:59,448 (7f7330c85740) :  DEBUG (core:450) - Starting messaging component.
2017-06-08 12:19:59,450 (7f7330c85740) :  DEBUG (core:450) - Starting debugging component.
2017-06-08 12:19:59,450 (7f7330c85740) :  DEBUG (core:450) - Starting services component.
2017-06-08 12:19:59,451 (7f7330c85740) :  DEBUG (core:450) - Starting myplex component.
2017-06-08 12:19:59,451 (7f7330c85740) :  DEBUG (core:450) - Starting notifications component.
2017-06-08 12:19:59,458 (7f730a7fc700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/system/messaging/clear_events/com.plexapp.agents.lyricfind'
2017-06-08 12:19:59,639 (7f7330c85740) :  DEBUG (accessor:68) - Creating a new model access point for provider com.plexapp.agents.lyricfind in namespace 'metadata'
2017-06-08 12:19:59,646 (7f7330c85740) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/resourceHashes'
2017-06-08 12:19:59,668 (7f730a7fc700) :  DEBUG (services:265) - Plug-in is not daemonized - loading services from system
2017-06-08 12:19:59,668 (7f7330c85740) :  DEBUG (runtime:1117) - Created a thread named 'load_all_services'
2017-06-08 12:19:59,669 (7f730a7fc700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_'
2017-06-08 12:19:59,674 (7f7330c85740) :  DEBUG (runtime:1117) - Created a thread named 'get_server_info'
2017-06-08 12:19:59,674 (7f7330c85740) :  DEBUG (core:150) - Finished starting framework core
2017-06-08 12:19:59,674 (7f7330c85740) :  DEBUG (core:560) - Loading plug-in code
2017-06-08 12:19:59,675 (7f73097fa700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400'
2017-06-08 12:19:59,693 (7f73097fa700) :  DEBUG (core:538) - Machine identifier is 9137ee3c856455d82ce048f60bd6e5b64d0ae2ab
2017-06-08 12:19:59,694 (7f73097fa700) :  DEBUG (core:539) - Server version is 1.5.5.3634-995f1dead
2017-06-08 12:19:59,715 (7f7330c85740) :  DEBUG (core:566) - Finished loading plug-in code
2017-06-08 12:19:59,715 (7f7330c85740) :  DEBUG (agentkit:1115) - Creating new agent class called LyricFindAlbumAgent
2017-06-08 12:19:59,716 (7f7330c85740) :  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'}]
2017-06-08 12:19:59,716 (7f7330c85740) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X0FnZW50U2VydmljZTpVcGRhdGVJbmZv/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQo2CmRpY3QKbGlzdApkaWN0Cmxpc3QKbGlzdApsaXN0CjIKczI4CmNvbS5wbGV4YXBwLmFnZW50cy5seXJpY2ZpbmRzMTAKaWRlbnRpZmllcnIxCnMxMAphZ2VudF9pbmZvMQpyMgoxMApyMwpzMTEKbWVkaWFfdHlwZXNuczEyCmFjY2VwdHNfZnJvbW5zMTQKZmFsbGJhY2tfYWdlbnRyNApzMTQKY29udHJpYnV0ZXNfdG9yNQpzOQpsYW5ndWFnZXNiMXMyMApwZXJzaXN0X3N0b3JlZF9maWxlc2kwCnM3CnZlcnNpb25iMHMxNgpwcmltYXJ5X3Byb3ZpZGVyYjBzNQpwcmVmc3M5Ckx5cmljRmluZHM0Cm5hbWUxCnM1CkFsYnVtMwpzMjgKY29tLnBsZXhhcHAuYWdlbnRzLnBsZXhtdXNpY3MyOQpjb20ucGxleGFwcC5hZ2VudHMubG9jYWxtZWRpYXMyNQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtMQpzMgp4bnIwCg__'
2017-06-08 12:19:59,768 (7f7330c85740) :  INFO (core:611) - Started plug-in
2017-06-08 12:19:59,769 (7f7330c85740) :  DEBUG (socketinterface:160) - Starting socket server
2017-06-08 12:19:59,770 (7f7330c85740) :  DEBUG (runtime:1117) - Created a thread named 'start'
2017-06-08 12:19:59,770 (7f7330c85740) :  INFO (socketinterface:184) - Socket server started on port 44571
2017-06-08 12:19:59,770 (7f7330c85740) :  INFO (pipeinterface:25) - Entering run loop
2017-06-08 12:19:59,770 (7f7330c85740) :  DEBUG (runtime:717) - Handling request GET /:/prefixes
2017-06-08 12:19:59,772 (7f7330c85740) :  DEBUG (runtime:814) - Found route matching /:/prefixes
2017-06-08 12:19:59,773 (7f7330c85740) :  DEBUG (runtime:924) - Response: [200] MediaContainer, 153 bytes
2017-06-08 12:19:59,786 (7f7308ff9700) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCmVuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM0Cjg1NDdzOApwYXJlbnRJRHM2MQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtOi8vTXIuJTIwU2NydWZmL05pbmphJTIwVHVuYT9sYW5nPWVuczQKZ3VpZGIxczUKZm9yY2VzMjUKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbXMxMwpwcmltYXJ5X2FnZW50czQKODU0OHMyCmlkcjAK
2017-06-08 12:19:59,799 (7f72ebfff700) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCmVuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM0Cjg1NTBzOApwYXJlbnRJRHM3OQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtOi8vUmljaGFyZCUyMFN0b2x0em1hbi9GaW5lJTIwTXVzaWMlMjBWb2wuJTIwMT9sYW5nPWVuczQKZ3VpZGIxczUKZm9yY2VzMjUKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbXMxMwpwcmltYXJ5X2FnZW50czQKODU1MXMyCmlkcjAK
2017-06-08 12:19:59,803 (7f72eb7fe700) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCmVuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM0Cjg1NTNzOApwYXJlbnRJRHM1Nwpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtOi8vQm9iJTIwQWNyaS9Cb2IlMjBBY3JpP2xhbmc9ZW5zNApndWlkYjFzNQpmb3JjZXMyNQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtczEzCnByaW1hcnlfYWdlbnRzNAo4NTU0czIKaWRyMAo_
2017-06-08 12:19:59,811 (7f7308ff9700) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCmVuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM0Cjg1NDdzOApwYXJlbnRJRHM2MQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtOi8vTXIuJTIwU2NydWZmL05pbmphJTIwVHVuYT9sYW5nPWVuczQKZ3VpZGIxczUKZm9yY2VzMjUKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbXMxMwpwcmltYXJ5X2FnZW50czQKODU0OHMyCmlkcjAK
2017-06-08 12:19:59,812 (7f7308ff9700) :  INFO (agentkit:957) - Searching for matches for {'id': '8548', 'guid': 'com.plexapp.agents.lastfm://Mr.%20Scruff/Ninja%20Tuna?lang=en', 'force': True, 'primary_agent': 'com.plexapp.agents.lastfm', 'parentID': '8547'}
2017-06-08 12:19:59,812 (7f72ebfff700) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCmVuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM0Cjg1NTBzOApwYXJlbnRJRHM3OQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtOi8vUmljaGFyZCUyMFN0b2x0em1hbi9GaW5lJTIwTXVzaWMlMjBWb2wuJTIwMT9sYW5nPWVuczQKZ3VpZGIxczUKZm9yY2VzMjUKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbXMxMwpwcmltYXJ5X2FnZW50czQKODU1MXMyCmlkcjAK
2017-06-08 12:19:59,813 (7f72eb7fe700) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCmVuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM0Cjg1NTNzOApwYXJlbnRJRHM1Nwpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtOi8vQm9iJTIwQWNyaS9Cb2IlMjBBY3JpP2xhbmc9ZW5zNApndWlkYjFzNQpmb3JjZXMyNQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtczEzCnByaW1hcnlfYWdlbnRzNAo4NTU0czIKaWRyMAo_
2017-06-08 12:19:59,819 (7f72eb7fe700) :  INFO (agentkit:957) - Searching for matches for {'id': '8554', 'guid': 'com.plexapp.agents.lastfm://Bob%20Acri/Bob%20Acri?lang=en', 'force': True, 'primary_agent': 'com.plexapp.agents.lastfm', 'parentID': '8553'}
2017-06-08 12:19:59,818 (7f72ebfff700) :  INFO (agentkit:957) - Searching for matches for {'id': '8551', 'guid': 'com.plexapp.agents.lastfm://Richard%20Stoltzman/Fine%20Music%20Vol.%201?lang=en', 'force': True, 'primary_agent': 'com.plexapp.agents.lastfm', 'parentID': '8550'}
2017-06-08 12:19:59,817 (7f7308ff9700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/8548/tree'
2017-06-08 12:19:59,830 (7f72ebfff700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/8551/tree'
2017-06-08 12:19:59,830 (7f72eb7fe700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/8554/tree'
2017-06-08 12:19:59,844 (7f72ebfff700) :  DEBUG (accessor:68) - Creating a new read-only model access point for provider com.plexapp.agents.lastfm in namespace 'metadata'
2017-06-08 12:19:59,852 (7f72ebfff700) :  DEBUG (model:32) - Loading model with GUID com.plexapp.agents.lastfm://Richard%20Stoltzman/Fine%20Music%20Vol.%201?lang=en
2017-06-08 12:19:59,857 (7f72ebfff700) :  DEBUG (model:234) - Deserializing from /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/Albums/c/7ffcdd55e63d45fb6674f43fa694a25ef056139.bundle/Contents/com.plexapp.agents.lastfm/Info.xml
2017-06-08 12:19:59,861 (7f72ebfff700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/8550/tree'
2017-06-08 12:19:59,867 (7f7308ff9700) :  DEBUG (model:32) - Loading model with GUID com.plexapp.agents.lastfm://Mr.%20Scruff/Ninja%20Tuna?lang=en
2017-06-08 12:19:59,868 (7f7308ff9700) :  DEBUG (model:234) - Deserializing from /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/Albums/8/00c69022c61c2b4ce02b9e9d3a176202901f85c.bundle/Contents/com.plexapp.agents.lastfm/Info.xml
2017-06-08 12:19:59,870 (7f72eb7fe700) :  DEBUG (model:32) - Loading model with GUID com.plexapp.agents.lastfm://Bob%20Acri/Bob%20Acri?lang=en
2017-06-08 12:19:59,871 (7f72eb7fe700) :  DEBUG (model:234) - Deserializing from /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/Albums/0/cb2f0aa6861f1d5eb8e6892b40a511d2edce40a.bundle/Contents/com.plexapp.agents.lastfm/Info.xml
2017-06-08 12:19:59,876 (7f7308ff9700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/8547/tree'
2017-06-08 12:19:59,884 (7f72eb7fe700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/8553/tree'
2017-06-08 12:19:59,898 (7f730a7fc700) :  DEBUG (services:362) - Loaded services
2017-06-08 12:19:59,912 (7f72eb7fe700) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2017-06-08 12:19:59,914 (7f7309ffb700) :  DEBUG (services:438) - No shared code to load
2017-06-08 12:19:59,915 (7f72ebfff700) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2017-06-08 12:19:59,918 (7f72ebfff700) :  DEBUG (runtime:924) - Response: [200] str, 300 bytes
2017-06-08 12:19:59,916 (7f7308ff9700) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2017-06-08 12:19:59,921 (7f7308ff9700) :  DEBUG (runtime:924) - Response: [200] str, 300 bytes
2017-06-08 12:19:59,915 (7f72eb7fe700) :  DEBUG (runtime:924) - Response: [200] str, 300 bytes
2017-06-08 12:19:59,932 (7f72eb7fe700) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKZW5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNAo4NTUxczQKZGJpZGkwCnM3CnZlcnNpb25zNTUKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbTovL1JpY2hhcmQlMjBTdG9sdHptYW4%40bGFuZz1lbnMxMApwYXJlbnRHVUlEczQKODU1MHM4CnBhcmVudElEczUKQWxidW1zMTAKbWVkaWFfdHlwZXM3OQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtOi8vUmljaGFyZCUyMFN0b2x0em1hbi9GaW5lJTIwTXVzaWMlMjBWb2wuJTIwMT9sYW5nPWVuczQKZ3VpZHM0Cm51bGxzMgppZHIwCg__
2017-06-08 12:19:59,933 (7f72eb7fe700) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKZW5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNAo4NTUxczQKZGJpZGkwCnM3CnZlcnNpb25zNTUKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbTovL1JpY2hhcmQlMjBTdG9sdHptYW4@bGFuZz1lbnMxMApwYXJlbnRHVUlEczQKODU1MHM4CnBhcmVudElEczUKQWxidW1zMTAKbWVkaWFfdHlwZXM3OQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtOi8vUmljaGFyZCUyMFN0b2x0em1hbi9GaW5lJTIwTXVzaWMlMjBWb2wuJTIwMT9sYW5nPWVuczQKZ3VpZHM0Cm51bGxzMgppZHIwCg__
2017-06-08 12:19:59,934 (7f72eb7fe700) :  DEBUG (model:32) - Loading model with GUID com.plexapp.agents.lastfm://Richard%20Stoltzman/Fine%20Music%20Vol.%201?lang=en
2017-06-08 12:19:59,934 (7f72eb7fe700) :  ERROR (model:205) - Cannot read model from /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/Albums/c/7ffcdd55e63d45fb6674f43fa694a25ef056139.bundle/Contents/com.plexapp.agents.lyricfind
2017-06-08 12:19:59,935 (7f72eb7fe700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/8551/tree'
2017-06-08 12:19:59,937 (7f7308ff9700) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKZW5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNAo4NTQ4czQKZGJpZGkwCnM3CnZlcnNpb25zNDgKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbTovL01yLiUyMFNjcnVmZj9sYW5nPWVuczEwCnBhcmVudEdVSURzNAo4NTQ3czgKcGFyZW50SURzNQpBbGJ1bXMxMAptZWRpYV90eXBlczYxCmNvbS5wbGV4YXBwLmFnZW50cy5sYXN0Zm06Ly9Nci4lMjBTY3J1ZmYvTmluamElMjBUdW5hP2xhbmc9ZW5zNApndWlkczQKbnVsbHMyCmlkcjAK
2017-06-08 12:19:59,939 (7f7308ff9700) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKZW5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNAo4NTQ4czQKZGJpZGkwCnM3CnZlcnNpb25zNDgKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbTovL01yLiUyMFNjcnVmZj9sYW5nPWVuczEwCnBhcmVudEdVSURzNAo4NTQ3czgKcGFyZW50SURzNQpBbGJ1bXMxMAptZWRpYV90eXBlczYxCmNvbS5wbGV4YXBwLmFnZW50cy5sYXN0Zm06Ly9Nci4lMjBTY3J1ZmYvTmluamElMjBUdW5hP2xhbmc9ZW5zNApndWlkczQKbnVsbHMyCmlkcjAK
2017-06-08 12:19:59,939 (7f7308ff9700) :  DEBUG (model:32) - Loading model with GUID com.plexapp.agents.lastfm://Mr.%20Scruff/Ninja%20Tuna?lang=en
2017-06-08 12:19:59,940 (7f7308ff9700) :  ERROR (model:205) - Cannot read model from /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/Albums/8/00c69022c61c2b4ce02b9e9d3a176202901f85c.bundle/Contents/com.plexapp.agents.lyricfind
2017-06-08 12:19:59,940 (7f7308ff9700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/8548/tree'
2017-06-08 12:19:59,944 (7f72eb7fe700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=Richard%20Stoltzman&album=Fine%20Music%2C%20Vol.%201'
2017-06-08 12:19:59,946 (7f72ebfff700) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKZW5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNAo4NTU0czQKZGJpZGkwCnM3CnZlcnNpb25zNDYKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbTovL0JvYiUyMEFjcmk%40bGFuZz1lbnMxMApwYXJlbnRHVUlEczQKODU1M3M4CnBhcmVudElEczUKQWxidW1zMTAKbWVkaWFfdHlwZXM1Nwpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtOi8vQm9iJTIwQWNyaS9Cb2IlMjBBY3JpP2xhbmc9ZW5zNApndWlkczQKbnVsbHMyCmlkcjAK
2017-06-08 12:19:59,947 (7f72ebfff700) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKZW5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNAo4NTU0czQKZGJpZGkwCnM3CnZlcnNpb25zNDYKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbTovL0JvYiUyMEFjcmk@bGFuZz1lbnMxMApwYXJlbnRHVUlEczQKODU1M3M4CnBhcmVudElEczUKQWxidW1zMTAKbWVkaWFfdHlwZXM1Nwpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtOi8vQm9iJTIwQWNyaS9Cb2IlMjBBY3JpP2xhbmc9ZW5zNApndWlkczQKbnVsbHMyCmlkcjAK
2017-06-08 12:19:59,948 (7f72ebfff700) :  DEBUG (model:32) - Loading model with GUID com.plexapp.agents.lastfm://Bob%20Acri/Bob%20Acri?lang=en
2017-06-08 12:19:59,948 (7f72ebfff700) :  ERROR (model:205) - Cannot read model from /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/Albums/0/cb2f0aa6861f1d5eb8e6892b40a511d2edce40a.bundle/Contents/com.plexapp.agents.lyricfind
2017-06-08 12:19:59,949 (7f72ebfff700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/8554/tree'
2017-06-08 12:19:59,952 (7f7308ff9700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=Mr.%20Scruff&album=Ninja%20Tuna'
2017-06-08 12:19:59,960 (7f72ebfff700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=Bob%20Acri&album=Bob%20Acri'
2017-06-08 12:20:00,362 (7f72ebfff700) :  DEBUG (threadkit:234) - Starting a parallel task set named MatchLyrics with 1 tasks
2017-06-08 12:20:00,365 (7f7309ffb700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=Bob%20Acri&track=Sleep%20Away'
2017-06-08 12:20:00,603 (7f72ebfff700) :  DEBUG (threadkit:244) - Parallel task set MatchLyrics ended
2017-06-08 12:20:00,605 (7f72ebfff700) :  DEBUG (model:229) - Serializing to /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/Albums/0/cb2f0aa6861f1d5eb8e6892b40a511d2edce40a.bundle/Contents/com.plexapp.agents.lyricfind/Info.xml
2017-06-08 12:20:00,606 (7f72ebfff700) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2017-06-08 12:20:00,606 (7f72ebfff700) :  DEBUG (runtime:924) - Response: [200] str, 16 bytes
2017-06-08 12:20:00,772 (7f7308ff9700) :  DEBUG (threadkit:234) - Starting a parallel task set named MatchLyrics with 1 tasks
2017-06-08 12:20:00,772 (7f7309ffb700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=Mr.%20Scruff&track=Kalimba'
2017-06-08 12:20:00,785 (7f72eb7fe700) :  DEBUG (threadkit:234) - Starting a parallel task set named MatchLyrics with 1 tasks
2017-06-08 12:20:00,786 (7f72e8ff9700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=Richard%20Stoltzman&track=Maid%20with%20the%20Flaxen%20Hair'
2017-06-08 12:20:01,014 (7f7308ff9700) :  DEBUG (threadkit:244) - Parallel task set MatchLyrics ended
2017-06-08 12:20:01,016 (7f7308ff9700) :  DEBUG (model:229) - Serializing to /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/Albums/8/00c69022c61c2b4ce02b9e9d3a176202901f85c.bundle/Contents/com.plexapp.agents.lyricfind/Info.xml
2017-06-08 12:20:01,017 (7f7308ff9700) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2017-06-08 12:20:01,018 (7f7308ff9700) :  DEBUG (runtime:924) - Response: [200] str, 16 bytes
2017-06-08 12:20:01,027 (7f72eb7fe700) :  DEBUG (threadkit:244) - Parallel task set MatchLyrics ended
2017-06-08 12:20:01,030 (7f72eb7fe700) :  DEBUG (model:229) - Serializing to /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/Albums/c/7ffcdd55e63d45fb6674f43fa694a25ef056139.bundle/Contents/com.plexapp.agents.lyricfind/Info.xml
2017-06-08 12:20:01,031 (7f72eb7fe700) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2017-06-08 12:20:01,032 (7f72eb7fe700) :  DEBUG (runtime:924) - Response: [200] str, 16 bytes
2017-06-08 12:29:52,977 (7f72ea7fc700) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCmVuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM0CjQ1NjNzOApwYXJlbnRJRHM2OQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtOi8vSkolMjBHcmV5JTIwJTI2JTIwTW9mcm8vTG9jaGxvb3NhP2xhbmc9ZW5zNApndWlkYjFzNQpmb3JjZXMyNQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtczEzCnByaW1hcnlfYWdlbnRzNAo0NjAxczIKaWRyMAo_
2017-06-08 12:29:52,978 (7f72ea7fc700) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2017-06-08 12:29:52,980 (7f72ea7fc700) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCmVuczQKbGFuZ2IwczYKbWFudWFsYjBzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M1CkFsYnVtczEwCm1lZGlhX3R5cGU1CnM0CjQ1NjNzOApwYXJlbnRJRHM2OQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtOi8vSkolMjBHcmV5JTIwJTI2JTIwTW9mcm8vTG9jaGxvb3NhP2xhbmc9ZW5zNApndWlkYjFzNQpmb3JjZXMyNQpjb20ucGxleGFwcC5hZ2VudHMubGFzdGZtczEzCnByaW1hcnlfYWdlbnRzNAo0NjAxczIKaWRyMAo_
2017-06-08 12:29:52,980 (7f72ea7fc700) :  INFO (agentkit:957) - Searching for matches for {'id': '4601', 'guid': 'com.plexapp.agents.lastfm://JJ%20Grey%20%26%20Mofro/Lochloosa?lang=en', 'force': True, 'primary_agent': 'com.plexapp.agents.lastfm', 'parentID': '4563'}
2017-06-08 12:29:52,982 (7f72ea7fc700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/4601/tree'
2017-06-08 12:29:52,991 (7f72ea7fc700) :  DEBUG (model:32) - Loading model with GUID com.plexapp.agents.lastfm://JJ%20Grey%20%26%20Mofro/Lochloosa?lang=en
2017-06-08 12:29:52,991 (7f72ea7fc700) :  DEBUG (model:234) - Deserializing from /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/Albums/7/c428c1d90dab31ac87efab90429f2b278968cbf.bundle/Contents/com.plexapp.agents.lastfm/Info.xml
2017-06-08 12:29:52,996 (7f72ea7fc700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/4563/tree'
2017-06-08 12:29:53,011 (7f72ea7fc700) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2017-06-08 12:29:53,012 (7f72ea7fc700) :  DEBUG (runtime:924) - Response: [200] str, 300 bytes
2017-06-08 12:29:53,022 (7f72ea7fc700) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKZW5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNAo0NjAxczQKZGJpZGkwCnM3CnZlcnNpb25zNTkKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbTovL0pKJTIwR3JleSUyMCUyNiUyME1vZnJvP2xhbmc9ZW5zMTAKcGFyZW50R1VJRHM0CjQ1NjNzOApwYXJlbnRJRHM1CkFsYnVtczEwCm1lZGlhX3R5cGVzNjkKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbTovL0pKJTIwR3JleSUyMCUyNiUyME1vZnJvL0xvY2hsb29zYT9sYW5nPWVuczQKZ3VpZHM0Cm51bGxzMgppZHIwCg__
2017-06-08 12:29:53,024 (7f72ea7fc700) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2017-06-08 12:29:53,025 (7f72ea7fc700) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.lyricfind/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKZW5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNAo0NjAxczQKZGJpZGkwCnM3CnZlcnNpb25zNTkKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbTovL0pKJTIwR3JleSUyMCUyNiUyME1vZnJvP2xhbmc9ZW5zMTAKcGFyZW50R1VJRHM0CjQ1NjNzOApwYXJlbnRJRHM1CkFsYnVtczEwCm1lZGlhX3R5cGVzNjkKY29tLnBsZXhhcHAuYWdlbnRzLmxhc3RmbTovL0pKJTIwR3JleSUyMCUyNiUyME1vZnJvL0xvY2hsb29zYT9sYW5nPWVuczQKZ3VpZHM0Cm51bGxzMgppZHIwCg__
2017-06-08 12:29:53,026 (7f72ea7fc700) :  DEBUG (model:32) - Loading model with GUID com.plexapp.agents.lastfm://JJ%20Grey%20%26%20Mofro/Lochloosa?lang=en
2017-06-08 12:29:53,027 (7f72ea7fc700) :  DEBUG (model:234) - Deserializing from /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/Albums/7/c428c1d90dab31ac87efab90429f2b278968cbf.bundle/Contents/com.plexapp.agents.lyricfind/Info.xml
2017-06-08 12:29:53,029 (7f72ea7fc700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/4601/tree'
2017-06-08 12:29:53,039 (7f72ea7fc700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=JJ%20Grey%20%26%20Mofro&album=Lochloosa'
2017-06-08 12:29:53,833 (7f72ea7fc700) :  DEBUG (threadkit:234) - Starting a parallel task set named MatchLyrics with 3 tasks
2017-06-08 12:29:53,835 (7f72e97fa700) :  INFO (__init__:32) - Adding Lyric Lochloosa to track Lochloosa
2017-06-08 12:29:53,838 (7f72e97fa700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=JJ%20Grey%20%26%20Mofro&track=Fireflies'
2017-06-08 12:29:53,840 (7f72e8ff9700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/lyricfind/search?reqtype=default&searchtype=track&limit=100&output=json&artist=JJ%20Grey%20%26%20Mofro&track=Everybody%27s'
2017-06-08 12:29:54,569 (7f72ea7fc700) :  DEBUG (threadkit:244) - Parallel task set MatchLyrics ended
2017-06-08 12:29:54,573 (7f72ea7fc700) :  DEBUG (model:229) - Serializing to /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Metadata/Albums/7/c428c1d90dab31ac87efab90429f2b278968cbf.bundle/Contents/com.plexapp.agents.lyricfind/Info.xml
2017-06-08 12:29:54,574 (7f72ea7fc700) :  DEBUG (runtime:88) - Sending packed state data (109 bytes)
2017-06-08 12:29:54,575 (7f72ea7fc700) :  DEBUG (runtime:924) - Response: [200] str, 16 bytes
