BMT not updating metadata on large numbers of shows

[fresnoboy]

Folks, I am trying to find out what is broken with my BMT metadata processing. I used to run sage on windows, but moved to linux a few months ago and running v9 quite successfully.

I have been trying to find issues with why plex doesn't have metadata on a bunch of shows, and so have been digging into what's going on with BMT on my sage server.

Look at the log files, I get a bunch of items like this in them when I try and update shows without fanart or in depth metadata. There seems to be a lot of errors like these:

2017-01-22 16:59:25,263 [Thread-48] WARN phoenix.log - AutomaticMetadataVisitor(): lookup failed with an error for DecoratedItem: [SageMediaFile [sageId=55022504, sageObject=A[55022504,16952971,"NBC Bay Area News at 5",10600@0122.17:00,30,T]]]
MetadataException [query=SearchQuery [type=TV, fields={QUERY: NBC Bay Area News at 5,YEAR: 2010,CLEAN_TITLE: NBC Bay Area News at 5,EPISODE_DATE: 2011-07-27,RAW_TITLE: NBC Bay Area News at 5,}, hints=Hints [hints={import_tv_as_recording: false,update_fanart: true,scan_missing_metadata: true,refresh: false,scan_subfolders: true,update_metadata: true,}]], ]
at sagex.phoenix.metadata.MetadataManager.search(MetadataManager.java:315)
at sagex.phoenix.metadata.MetadataManager.automaticUpdate(MetadataManager.java:506)
at sagex.phoenix.metadata.MetadataManager.automaticUpdate(MetadataManager.java:477)
at sagex.phoenix.metadata.AutomaticMetadataVisitor.visit(AutomaticMetadataVisitor.java:30)
at sagex.phoenix.vfs.DecoratedMediaFile.accept(DecoratedMediaFile.java:49)
at sagex.phoenix.vfs.DecoratedMediaFolder.accept(DecoratedMediaFolder.java:70)
at sagex.phoenix.metadata.PhoenixMetadataSupport$1.run(PhoenixMetadataSupport.java:123)
at sagex.phoenix.progress.ProgressTrackerManager$1.run(ProgressTrackerManager.java:48)
2017-01-22 16:59:25,264 [Thread-48] INFO sagex.phoenix.metadata.MetadataManager - search(): tvdb; SearchQuery [type=TV, fields={YEAR: 2015,CLEAN_TITLE: NBC Nightly News With Lester Holt,EPISODE_DATE: 2017-01-22,RAW_TITLE: NBC Nightly News With Lester Holt,}, hints=Hints [hints={import_tv_as_recording: false,update_fanart: true,scan_missing_metadata: true,refresh: false,scan_subfolders: true,update_metadata: true,}]]
2017-01-22 16:59:25,264 [Thread-48] INFO sagex.phoenix.metadata.MetadataManager - Searching: NBC Nightly News With Lester Holt using TVDBMetadataProvider[MetadataProviderInfo [id=tvdb, fanartId=null, mediaTypes=[TV], name=thetvdb.com]]
2017-01-22 16:59:25,264 [Thread-48] INFO sagex.phoenix.metadata.provider.tvdb.TVDBSearchParser - TVDB Search: http://www.thetvdb.com/api/GetSeries...th+Lester+Holt
2017-01-22 16:59:25,321 [Thread-48] INFO sagex.phoenix.metadata.MetadataManager - No good matches for NBC Nightly News With Lester Holt will try other providers if available.
2017-01-22 16:59:25,321 [Thread-48] WARN phoenix.log - ERROR; /Future Airings (12 hours)/NBC Nightly News With Lester Holt; NBC Nightly News With Lester Holt; 55022491; Metadata lookup failed for NBC Nightly News With Lester Holt
MetadataException [query=SearchQuery [type=TV, fields={QUERY: NBC Nightly News With Lester Holt,YEAR: 2015,CLEAN_TITLE: NBC Nightly News With Lester Holt,EPISODE_DATE: 2017-01-22,RAW_TITLE: NBC Nightly News With Lester Holt,}, hints=Hints [hints={import_tv_as_recording: false,update_fanart: true,scan_missing_metadata: true,refresh: false,scan_subfolders: true,update_metadata: true,}]], ]
at sagex.phoenix.metadata.MetadataManager.getMetdata(MetadataManager.java:410)
at sagex.phoenix.metadata.MetadataManager.automaticUpdate(MetadataManager.java:506)
at sagex.phoenix.metadata.MetadataManager.automaticUpdate(MetadataManager.java:477)
at sagex.phoenix.metadata.AutomaticMetadataVisitor.visit(AutomaticMetadataVisitor.java:30)
at sagex.phoenix.vfs.DecoratedMediaFile.accept(DecoratedMediaFile.java:49)
at sagex.phoenix.vfs.DecoratedMediaFolder.accept(DecoratedMediaFolder.java:70)
at sagex.phoenix.metadata.PhoenixMetadataSupport$1.run(PhoenixMetadataSupport.java:123)
at sagex.phoenix.progress.ProgressTrackerManager$1.run(ProgressTrackerManager.java:48)
2017-01-22 16:59:25,321 [Thread-48] WARN phoenix.log - AutomaticMetadataVisitor(): lookup failed with an error for DecoratedItem: [SageMediaFile [sageId=55022491, sageObject=A[55022491,55022474,"NBC Nightly News With Lester Holt",10600@0122.17:30,30,T]]]
MetadataException [query=SearchQuery [type=TV, fields={QUERY: NBC Nightly News With Lester Holt,YEAR: 2015,CLEAN_TITLE: NBC Nightly News With Lester Holt,EPISODE_DATE: 2017-01-22,RAW_TITLE: NBC Nightly News With Lester Holt,}, hints=Hints [hints={import_tv_as_recording: false,update_fanart: true,scan_missing_metadata: true,refresh: false,scan_subfolders: true,update_metadata: true,}]], ]
at sagex.phoenix.metadata.MetadataManager.getMetdata(MetadataManager.java:410)
at sagex.phoenix.metadata.MetadataManager.automaticUpdate(MetadataManager.java:506)
at sagex.phoenix.metadata.MetadataManager.automaticUpdate(MetadataManager.java:477)
at sagex.phoenix.metadata.AutomaticMetadataVisitor.visit(AutomaticMetadataVisitor.java:30)
at sagex.phoenix.vfs.DecoratedMediaFile.accept(DecoratedMediaFile.java:49)
at sagex.phoenix.vfs.DecoratedMediaFolder.accept(DecoratedMediaFolder.java:70)
at sagex.phoenix.metadata.PhoenixMetadataSupport$1.run(PhoenixMetadataSupport.java:123)
at sagex.phoenix.progress.ProgressTrackerManager$1.run(ProgressTrackerManager.java:48)
2017-01-22 16:59:25,321 [Thread-48] WARN sagex.phoenix.metadata.persistence.TVSeriesUtil - Unable to create a SeriesInfoID for null:null
2017-01-22 16:59:25,322 [Thread-48] INFO sagex.phoenix.metadata.MetadataManager - search(): tvdb; SearchQuery [type=TV, fields={YEAR: 2010,CLEAN_TITLE: NBC Bay Area News at 6,EPISODE_DATE: 2011-07-27,RAW_TITLE: NBC Bay Area News at 6,}, hints=Hints [hints={import_tv_as_recording: false,update_fanart: true,scan_missing_metadata: true,refresh: false,scan_subfolders: true,update_metadata: true,}]]
2017-01-22 16:59:25,322 [Thread-48] INFO sagex.phoenix.metadata.MetadataManager - Searching: NBC Bay Area News at 6 using TVDBMetadataProvider[MetadataProviderInfo [id=tvdb, fanartId=null, mediaTypes=[TV], name=thetvdb.com]]
2017-01-22 16:59:25,322 [Thread-48] INFO sagex.phoenix.metadata.provider.tvdb.TVDBSearchParser - TVDB Search: http://www.thetvdb.com/api/GetSeries...Area+News+at+6
2017-01-22 16:59:25,387 [Thread-48] WARN sagex.phoenix.metadata.provider.tvdb.TVDBSearchParser - Could not find any results for: CachedUrl: http://www.thetvdb.com/api/GetSeries...rea+News+at+6; UrlId: 620b5aa8b59bacf02cf0c286d1a6dbe0; CachedFile: ./userdata/Phoenix/cache/url/620b5aa8b59bacf02cf0c286d1a6dbe0.properties
2017-01-22 16:59:25,387 [Thread-48] INFO sagex.phoenix.metadata.MetadataManager - No good matches for NBC Bay Area News at 6 will try other providers if available.
2017-01-22 16:59:25,387 [Thread-48] WARN phoenix.log - ERROR; /Future Airings (12 hours)/NBC Bay Area News at 6; NBC Bay Area News at 6; 55022505; Search Failed for SearchQuery [type=TV, fields={QUERY: NBC Bay Area News at 6,YEAR: 2010,CLEAN_TITLE: NBC Bay Area News at 6,EPISODE_DATE: 2011-07-27,RAW_TITLE: NBC Bay Area News at 6,}, hints=Hints [hints={import_tv_as_recording: false,update_fanart: true,scan_missing_metadata: true,refresh: false,scan_subfolders: true,update_metadata: true,}]]
MetadataException [query=SearchQuery [type=TV, fields={QUERY: NBC Bay Area News at 6,YEAR: 2010,CLEAN_TITLE: NBC Bay Area News at 6,EPISODE_DATE: 2011-07-27,RAW_TITLE: NBC Bay Area News at 6,}, hints=Hints [hints={import_tv_as_recording: false,update_fanart: true,scan_missing_metadata: true,refresh: false,scan_subfolders: true,update_metadata: true,}]], ]
at sagex.phoenix.metadata.MetadataManager.search(MetadataManager.java:315)
at sagex.phoenix.metadata.MetadataManager.automaticUpdate(MetadataManager.java:506)
at sagex.phoenix.metadata.MetadataManager.automaticUpdate(MetadataManager.java:477)
at sagex.phoenix.metadata.AutomaticMetadataVisitor.visit(AutomaticMetadataVisitor.java:30)
at sagex.phoenix.vfs.DecoratedMediaFile.accept(DecoratedMediaFile.java:49)
at sagex.phoenix.vfs.DecoratedMediaFolder.accept(DecoratedMediaFolder.java:70)
at sagex.phoenix.metadata.PhoenixMetadataSupport$1.run(PhoenixMetadataSupport.java:123)
at sagex.phoenix.progress.ProgressTrackerManager$1.run(ProgressTrackerManager.java:48)
2017-01-22 16:59:25,387 [Thread-48] WARN phoenix.log - AutomaticMetadataVisitor(): lookup failed with an error for DecoratedItem: [SageMediaFile [sageId=55022505, sageObject=A[55022505,16952973,"NBC Bay Area News at 6",10600@0122.18:00,30,T]]]
MetadataException [query=SearchQuery [type=TV, fields={QUERY: NBC Bay Area News at 6,YEAR: 2010,CLEAN_TITLE: NBC Bay Area News at 6,EPISODE_DATE: 2011-07-27,RAW_TITLE: NBC Bay Area News at 6,}, hints=Hints [hints={import_tv_as_recording: false,update_fanart: true,scan_missing_metadata: true,refresh: false,scan_subfolders: true,update_metadata: true,}]], ]
at sagex.phoenix.metadata.MetadataManager.search(MetadataManager.java:315)
at sagex.phoenix.metadata.MetadataManager.automaticUpdate(MetadataManager.java:506)
at sagex.phoenix.metadata.MetadataManager.automaticUpdate(MetadataManager.java:477)
at sagex.phoenix.metadata.AutomaticMetadataVisitor.visit(AutomaticMetadataVisitor.java:30)
at sagex.phoenix.vfs.DecoratedMediaFile.accept(DecoratedMediaFile.java:49)
at sagex.phoenix.vfs.DecoratedMediaFolder.accept(DecoratedMediaFolder.java:70)
at sagex.phoenix.metadata.PhoenixMetadataSupport$1.run(PhoenixMetadataSupport.java:123)
at sagex.phoenix.progress.ProgressTrackerManager$1.run(ProgressTrackerManager.java:48)

Do folks have any idea as to what might be going on?

There are other complaints about fanart missing, but the I suspect that would get fixed if it could download the fanart properly.

Should I remove the plugin and try and reinstall it?

Thx
Mike

[stuckless]

These are all "NBC Bay Area News at 6", which I'm guessing won't actually have metadata from TVDB.

For other shows, you might have to train BMT... ie, do a manual search, save, then use the "add matcher" button and create a mapping for that show. Then if you rescan, it'll start to find/apply fanart/metadata for those other episodes.