2018-12-16 18:56:02,471 (7f4168b25700) :  INFO (core:349) - Starting framework core - Version: 2.6.3, Build: ecd6004 (Tue Oct 30 17:17:43 UTC 2018)
2018-12-16 18:56:02,472 (7f4168b25700) :  DEBUG (core:361) - Using the elevated policy
2018-12-16 18:56:02,472 (7f4168b25700) :  DEBUG (core:450) - Starting runtime component.
2018-12-16 18:56:02,476 (7f4168b25700) :  DEBUG (core:450) - Starting caching component.
2018-12-16 18:56:02,477 (7f4168b25700) :  DEBUG (core:450) - Starting data component.
2018-12-16 18:56:02,477 (7f4168b25700) :  DEBUG (core:450) - Starting networking component.
2018-12-16 18:56:02,485 (7f4168b25700) :  DEBUG (networking:284) - Loaded HTTP cookies
2018-12-16 18:56:02,516 (7f4168b25700) :  DEBUG (networking:452) - Setting the default network timeout to 20.0
2018-12-16 18:56:02,518 (7f4168b25700) :  DEBUG (core:450) - Starting localization component.
2018-12-16 18:56:02,519 (7f4168b25700) :  INFO (localization:409) - Setting the default locale to en-us
2018-12-16 18:56:02,519 (7f4168b25700) :  DEBUG (core:450) - Starting messaging component.
2018-12-16 18:56:02,521 (7f4168b25700) :  DEBUG (core:450) - Starting debugging component.
2018-12-16 18:56:02,521 (7f4168b25700) :  DEBUG (core:450) - Starting services component.
2018-12-16 18:56:02,522 (7f415ab7d700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/system/messaging/clear_events/com.plexapp.agents.thetvdb'
2018-12-16 18:56:02,523 (7f4168b25700) :  DEBUG (core:450) - Starting myplex component.
2018-12-16 18:56:02,526 (7f4168b25700) :  DEBUG (core:450) - Starting notifications component.
2018-12-16 18:56:02,884 (7f4168b25700) :  DEBUG (accessor:68) - Creating a new model access point for provider com.plexapp.agents.thetvdb in namespace 'metadata'
2018-12-16 18:56:02,911 (7f4168b25700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/resourceHashes'
2018-12-16 18:56:03,024 (7f415ab7d700) :  DEBUG (services:265) - Plug-in is not daemonized - loading services from system
2018-12-16 18:56:03,024 (7f4168b25700) :  DEBUG (runtime:1117) - Created a thread named 'load_all_services'
2018-12-16 18:56:03,027 (7f415ab7d700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_'
2018-12-16 18:56:03,028 (7f4168b25700) :  DEBUG (runtime:1117) - Created a thread named 'get_server_info'
2018-12-16 18:56:03,030 (7f4168b25700) :  DEBUG (core:150) - Finished starting framework core
2018-12-16 18:56:03,031 (7f4168b25700) :  DEBUG (core:560) - Loading plug-in code
2018-12-16 18:56:03,043 (7f415a5a1700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400'
2018-12-16 18:56:03,053 (7f415a5a1700) :  DEBUG (core:538) - Machine identifier is 01b1defbda073ad84e7514920c4ee70d5ead7488
2018-12-16 18:56:03,054 (7f415a5a1700) :  DEBUG (core:539) - Server version is 1.13.9.5456-ecd600442
2018-12-16 18:56:03,537 (7f415ab7d700) :  DEBUG (services:362) - Loaded services
2018-12-16 18:56:03,586 (7f415a88f700) :  DEBUG (services:438) - No shared code to load
2018-12-16 18:56:04,379 (7f4168b25700) :  DEBUG (core:566) - Finished loading plug-in code
2018-12-16 18:56:04,380 (7f4168b25700) :  DEBUG (agentkit:1115) - Creating new agent class called TVDBAgent
2018-12-16 18:56:04,383 (7f4168b25700) :  DEBUG (agentkit:933) - Updating agent information: [{'media_types': ['TV_Show'], 'accepts_from': None, 'fallback_agent': None, 'contributes_to': None, 'languages': ['en', 'fr', 'zh', 'sv', 'no', 'da', 'fi', 'nl', 'de', 'it', 'es', 'pl', 'hu', 'el', 'tr', 'ru', 'he', 'ja', 'pt', 'cs', 'ko', 'sl', 'hr'], 'persist_stored_files': True, 'version': 0, 'primary_provider': True, 'prefs': True, 'name': 'TheTVDB'}]
2018-12-16 18:56:04,385 (7f4168b25700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X0FnZW50U2VydmljZTpVcGRhdGVJbmZv/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQo1CmRpY3QKbGlzdApkaWN0Cmxpc3QKbGlzdAoyCnMyNgpjb20ucGxleGFwcC5hZ2VudHMudGhldHZkYnMxMAppZGVudGlmaWVycjEKczEwCmFnZW50X2luZm8xCnIyCjEwCnIzCnMxMQptZWRpYV90eXBlc25zMTIKYWNjZXB0c19mcm9tbnMxNApmYWxsYmFja19hZ2VudG5zMTQKY29udHJpYnV0ZXNfdG9yNApzOQpsYW5ndWFnZXNiMXMyMApwZXJzaXN0X3N0b3JlZF9maWxlc2kwCnM3CnZlcnNpb25iMXMxNgpwcmltYXJ5X3Byb3ZpZGVyYjFzNQpwcmVmc3M3ClRoZVRWREJzNApuYW1lMQpzNwpUVl9TaG93MjMKczIKZW5zMgpmcnMyCnpoczIKc3ZzMgpub3MyCmRhczIKZmlzMgpubHMyCmRlczIKaXRzMgplc3MyCnBsczIKaHVzMgplbHMyCnRyczIKcnVzMgpoZXMyCmphczIKcHRzMgpjc3MyCmtvczIKc2xzMgpocnIwCg__'
2018-12-16 18:56:04,462 (7f4168b25700) :  INFO (core:611) - Started plug-in
2018-12-16 18:56:04,463 (7f4168b25700) :  DEBUG (socketinterface:160) - Starting socket server
2018-12-16 18:56:04,465 (7f4168b25700) :  DEBUG (runtime:1117) - Created a thread named 'start'
2018-12-16 18:56:04,465 (7f4168b25700) :  INFO (socketinterface:184) - Socket server started on port 57485
2018-12-16 18:56:04,466 (7f4168b25700) :  INFO (pipeinterface:25) - Entering run loop
2018-12-16 18:56:04,466 (7f4168b25700) :  DEBUG (runtime:717) - Handling request GET /:/prefixes
2018-12-16 18:56:04,470 (7f4168b25700) :  DEBUG (runtime:814) - Found route matching /:/prefixes
2018-12-16 18:56:04,472 (7f4168b25700) :  DEBUG (runtime:924) - Response: [200] MediaContainer, 151 bytes
2018-12-16 18:56:04,495 (7f415ab7d700) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.thetvdb/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCmVuczQKbGFuZ2IwczYKbWFudWFsYjFzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M3ClRWX1Nob3dzMTAKbWVkaWFfdHlwZTkKczE2CjY0MDcyOTBlZWMyYTQ3OGJzMTcKb3BlblN1YnRpdGxlc0hhc2hzMgoxMHM3CmVwaXNvZGVzMQoxczgKZXBpc29kaWNzMTgKVGhlIFByb3RlY3RvciAyMDE4czQKc2hvd3MxCjFzNgpzZWFzb25zMTIzCiUyRnZvbHVtZTElMkZ0diUyMHNlcmllcyUyRlRoZSUyMFByb3RlY3RvciUyMDIwMTglMkZTZWFzb24lMjAxJTJGVGhlJTIwUHJvdGVjdG9yJTIwMjAxOCUyMC0lMjAxeDEwJTIwLSUyMEVwaXNvZGUlMjAxMCUyRW1rdnM4CmZpbGVuYW1lczQwCmEwNTU5NDVmZmY1Njg3MTFlYWM1ZjIxZTFhZWE5ODZmNDM4OWZlZjRzOApwbGV4SGFzaHMyCi0xczgKZHVyYXRpb25zNwoxODczNDUzczIKaWRyMAo_
2018-12-16 18:56:04,497 (7f415ab7d700) :  DEBUG (runtime:49) - Received packed state data (556 bytes)
2018-12-16 18:56:04,526 (7f415ab7d700) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.thetvdb/messaging/function/X0FnZW50S2l0OlNlYXJjaA__/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoyCmRpY3QKZGljdAo2CnMyCmVuczQKbGFuZ2IwczYKbWFudWFsYjFzNwpwcmltYXJ5aTAKczcKdmVyc2lvbnIxCnM2Cmt3YXJnc3M3ClRWX1Nob3dzMTAKbWVkaWFfdHlwZTkKczE2CjY0MDcyOTBlZWMyYTQ3OGJzMTcKb3BlblN1YnRpdGxlc0hhc2hzMgoxMHM3CmVwaXNvZGVzMQoxczgKZXBpc29kaWNzMTgKVGhlIFByb3RlY3RvciAyMDE4czQKc2hvd3MxCjFzNgpzZWFzb25zMTIzCiUyRnZvbHVtZTElMkZ0diUyMHNlcmllcyUyRlRoZSUyMFByb3RlY3RvciUyMDIwMTglMkZTZWFzb24lMjAxJTJGVGhlJTIwUHJvdGVjdG9yJTIwMjAxOCUyMC0lMjAxeDEwJTIwLSUyMEVwaXNvZGUlMjAxMCUyRW1rdnM4CmZpbGVuYW1lczQwCmEwNTU5NDVmZmY1Njg3MTFlYWM1ZjIxZTFhZWE5ODZmNDM4OWZlZjRzOApwbGV4SGFzaHMyCi0xczgKZHVyYXRpb25zNwoxODczNDUzczIKaWRyMAo_
2018-12-16 18:56:04,527 (7f415ab7d700) :  INFO (agentkit:957) - Searching for matches for {'openSubtitlesHash': '6407290eec2a478b', 'episode': '10', 'episodic': '1', 'show': 'The Protector 2018', 'season': '1', 'filename': '%2Fvolume1%2Ftv%20series%2FThe%20Protector%202018%2FSeason%201%2FThe%20Protector%202018%20-%201x10%20-%20Episode%2010%2Emkv', 'plexHash': 'a055945fff568711eac5f21e1aea986f4389fef4', 'duration': '-1', 'id': '1873453'}
2018-12-16 18:56:04,544 (7f415ab7d700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/1873453/tree'
2018-12-16 18:56:04,692 (7f415ab7d700) :  DEBUG (networking:161) - Fetching 'https://meta.plex.tv/tv/guid/3f/3fe59aae2148f26e154a3d03f4248451460c51ef.xml' from the HTTP cache
2018-12-16 18:56:04,761 (7f415ab7d700) :  DEBUG (networking:166) - Requesting 'https://meta.plex.tv/tv/names/en/7c/7cf7ee65284ea681431133881523c10a2b9f1687.xml'
2018-12-16 18:56:05,170 (7f415ab7d700) :  DEBUG (networking:166) - Requesting 'https://meta.plex.tv/tv/names/en/66/66efd9eefecf45dd64eff8e5cb2d13e005041925.xml'
2018-12-16 18:56:05,321 (7f415ab7d700) :  DEBUG (networking:166) - Requesting 'https://tvdb2.plex.tv/login'
2018-12-16 18:56:05,606 (7f415ab7d700) :  DEBUG (networking:161) - Fetching 'https://tvdb2.plex.tv/series/248929?lang=en' from the HTTP cache
2018-12-16 18:56:05,623 (7f415ab7d700) :  INFO (__init__:360) - Adding (based on word matches) id: 248929, name: The Protector, year: 2011, lang: en, score: 85
2018-12-16 18:56:05,625 (7f415ab7d700) :  INFO (__init__:461) - Top GUID+name result: MetadataSearchResult(lang='en', thumb=None, score=85, year='2011', id='248929', name='The Protector')
2018-12-16 18:56:05,626 (7f415ab7d700) :  INFO (__init__:369) - Searching for exact match with: The+Protector+2018 (lang: en)
2018-12-16 18:56:05,628 (7f415ab7d700) :  DEBUG (networking:166) - Requesting 'https://tvdb2.plex.tv/search/series?name=The+Protector+2018'
2018-12-16 18:56:06,149 (7f415ab7d700) :  INFO (__init__:491) - ---- UMP RESULTS MAP ----
2018-12-16 18:56:06,186 (7f415ab7d700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/services/ump/matches?type=2&title=The%20Protector%202018&year=&lang=en&manual=0'
2018-12-16 18:56:06,860 (7f415ab7d700) :  INFO (__init__:411) - UMP: MetadataSearchResult(lang='en', thumb='https://image.tmdb.org/t/p/w154/p4H5pwgcU4sZmgizMCEpYuW39sq.jpg', score=98, year=2018, id='347838', name='The Protector')
2018-12-16 18:56:06,861 (7f415ab7d700) :  INFO (__init__:516) - Final result: MetadataSearchResult(lang='en', thumb='https://image.tmdb.org/t/p/w154/p4H5pwgcU4sZmgizMCEpYuW39sq.jpg', score=98, year=2018, id='347838', name='The Protector')
2018-12-16 18:56:06,862 (7f415ab7d700) :  INFO (__init__:516) - Final result: MetadataSearchResult(lang='en', thumb=None, score=86, year='2011', id='248929', name='The Protector')
2018-12-16 18:56:06,865 (7f415ab7d700) :  DEBUG (runtime:88) - Sending packed state data (583 bytes)
2018-12-16 18:56:06,866 (7f415ab7d700) :  DEBUG (runtime:924) - Response: [200] str, 1040 bytes
2018-12-16 18:56:07,037 (7f415ab7d700) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.thetvdb/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKZW5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNwoxODczNDUzczQKZGJpZGkwCnM3CnZlcnNpb25uczEwCnBhcmVudEdVSURuczgKcGFyZW50SURzNwpUVl9TaG93czEwCm1lZGlhX3R5cGVzNDMKY29tLnBsZXhhcHAuYWdlbnRzLnRoZXR2ZGI6Ly8zNDc4Mzg%40bGFuZz1lbnM0Cmd1aWRzNgozNDc4MzhzMgppZHIwCg__
2018-12-16 18:56:07,039 (7f415ab7d700) :  DEBUG (runtime:49) - Received packed state data (556 bytes)
2018-12-16 18:56:07,042 (7f415ab7d700) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.thetvdb/messaging/function/X0FnZW50S2l0OlVwZGF0ZU1ldGFkYXRh/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMTAKczIKZW5zNApsYW5nYjFzNQpmb3JjZWIwczgKcGVyaW9kaWNzNwoxODczNDUzczQKZGJpZGkwCnM3CnZlcnNpb25uczEwCnBhcmVudEdVSURuczgKcGFyZW50SURzNwpUVl9TaG93czEwCm1lZGlhX3R5cGVzNDMKY29tLnBsZXhhcHAuYWdlbnRzLnRoZXR2ZGI6Ly8zNDc4Mzg@bGFuZz1lbnM0Cmd1aWRzNgozNDc4MzhzMgppZHIwCg__
2018-12-16 18:56:07,044 (7f415ab7d700) :  DEBUG (model:32) - Loading model with GUID com.plexapp.agents.thetvdb://347838?lang=en
2018-12-16 18:56:07,085 (7f415ab7d700) :  DEBUG (model:234) - Deserializing from /volume1/Plex/Library/Application Support/Plex Media Server/Metadata/TV Shows/a/4003c846267470d213ac0488002f22d30f2a2bf.bundle/Contents/com.plexapp.agents.thetvdb/Info.xml
2018-12-16 18:56:07,613 (7f415ab7d700) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/metadata/1873453/tree'
2018-12-16 18:56:07,635 (7f415ab7d700) :  INFO (__init__:785) - def update()
2018-12-16 18:56:07,683 (7f415ab7d700) :  DEBUG (networking:161) - Fetching 'https://tvdb2.plex.tv/series/347838?lang=en' from the HTTP cache
2018-12-16 18:56:07,731 (7f415ab7d700) :  DEBUG (networking:161) - Fetching 'http://127.0.0.1:32400/services/tmdb?uri=%2Ffind%2F347838%3Fexternal_source%3Dtvdb_id' from the HTTP cache
2018-12-16 18:56:07,779 (7f415ab7d700) :  DEBUG (networking:161) - Fetching 'http://127.0.0.1:32400/services/tmdb?uri=%2Ftv%2F79026%2Frecommendations' from the HTTP cache
2018-12-16 18:56:07,815 (7f415ab7d700) :  DEBUG (networking:161) - Fetching 'https://tvdb2.plex.tv/series/347838/actors' from the HTTP cache
2018-12-16 18:56:07,837 (7f415ab7d700) :  DEBUG (preferences:258) - Loaded preferences from DefaultPrefs.json
2018-12-16 18:56:07,862 (7f415ab7d700) :  DEBUG (preferences:178) - Loaded the user preferences for com.plexapp.agents.thetvdb
2018-12-16 18:56:07,888 (7f415ab7d700) :  DEBUG (networking:166) - Requesting 'https://meta.plex.tv/tv_e/347838/protector/-1'
2018-12-16 18:56:08,174 (7f415ab7d700) :  ERROR (networking:219) - Error opening URL 'https://meta.plex.tv/tv_e/347838/protector/-1'
2018-12-16 18:56:08,221 (7f415ab7d700) :  DEBUG (networking:166) - Requesting 'https://tvdb2.plex.tv/series/347838/episodes?page=1'
2018-12-16 18:56:08,598 (7f415ab7d700) :  INFO (__init__:902) - Show ordering is: aired
2018-12-16 18:56:08,600 (7f415ab7d700) :  INFO (__init__:930) - No media for season 1 episode 1 - skipping population of episode data
2018-12-16 18:56:08,601 (7f415ab7d700) :  INFO (__init__:930) - No media for season 1 episode 2 - skipping population of episode data
2018-12-16 18:56:08,602 (7f415ab7d700) :  INFO (__init__:930) - No media for season 1 episode 3 - skipping population of episode data
2018-12-16 18:56:08,604 (7f415ab7d700) :  INFO (__init__:930) - No media for season 1 episode 4 - skipping population of episode data
2018-12-16 18:56:08,605 (7f415ab7d700) :  INFO (__init__:930) - No media for season 1 episode 5 - skipping population of episode data
2018-12-16 18:56:08,606 (7f415ab7d700) :  INFO (__init__:930) - No media for season 1 episode 6 - skipping population of episode data
2018-12-16 18:56:08,607 (7f415ab7d700) :  INFO (__init__:930) - No media for season 1 episode 7 - skipping population of episode data
2018-12-16 18:56:08,608 (7f415ab7d700) :  INFO (__init__:930) - No media for season 1 episode 8 - skipping population of episode data
2018-12-16 18:56:08,610 (7f415ab7d700) :  INFO (__init__:930) - No media for season 1 episode 9 - skipping population of episode data
2018-12-16 18:56:08,611 (7f415ab7d700) :  DEBUG (threadkit:234) - Starting a parallel task set named UpdateEpisodes with 1 tasks
2018-12-16 18:56:08,656 (7f415a5a1700) :  DEBUG (networking:161) - Fetching 'https://tvdb2.plex.tv/episodes/6903710?lang=en' from the HTTP cache
2018-12-16 18:56:08,676 (7f415a5a1700) :  INFO (__init__:1025) - Season Extra XML is empty - therefore, no episode XML
2018-12-16 18:56:08,678 (7f415ab7d700) :  DEBUG (threadkit:244) - Parallel task set UpdateEpisodes ended
2018-12-16 18:56:08,732 (7f415ab7d700) :  DEBUG (networking:161) - Fetching 'https://tvdb2.plex.tv/series/347838/images?lang=en' from the HTTP cache
2018-12-16 18:56:08,771 (7f415ab7d700) :  DEBUG (networking:161) - Fetching 'https://tvdb2.plex.tv/series/347838/images/query?keyType=fanart&lang=en' from the HTTP cache
2018-12-16 18:56:08,797 (7f415ab7d700) :  DEBUG (networking:161) - Fetching 'https://tvdb2.plex.tv/series/347838/images/query?keyType=poster&lang=en' from the HTTP cache
2018-12-16 18:56:08,831 (7f415ab7d700) :  DEBUG (networking:161) - Fetching 'https://tvdb2.plex.tv/series/347838/images/query?keyType=series&lang=en' from the HTTP cache
2018-12-16 18:56:08,847 (7f415ab7d700) :  DEBUG (threadkit:234) - Starting a parallel task set named DownloadImages with 7 tasks
2018-12-16 18:56:08,851 (7f415ab7d700) :  DEBUG (threadkit:244) - Parallel task set DownloadImages ended
2018-12-16 18:56:08,852 (7f415ab7d700) :  INFO (__init__:1118) - Series Extra XML is empty - therefore, no season XML
2018-12-16 18:56:09,029 (7f415ab7d700) :  DEBUG (model:229) - Serializing to /volume1/Plex/Library/Application Support/Plex Media Server/Metadata/TV Shows/a/4003c846267470d213ac0488002f22d30f2a2bf.bundle/Contents/com.plexapp.agents.thetvdb/Info.xml
2018-12-16 18:56:09,033 (7f415ab7d700) :  DEBUG (runtime:88) - Sending packed state data (583 bytes)
2018-12-16 18:56:09,034 (7f415ab7d700) :  DEBUG (runtime:924) - Response: [200] str, 16 bytes
