Suddently can't scrape TV fanart

[texneus]

Yet another "this could go many places" problem. I think this is a Phoenix scraper issue but the Phoenix forum appears to be for the UI, so I put it here since I'm using Gemstone.

For TV shows recorded roughly since late last week, I noticed I am no longer getting fan art for them. Movies do not seem to be an issue, just TV shows. Trying to update affected TV shows with CMT and BMT appears to go OK (in the sense that these complete with no error being displayed), but still no fanart gets downloaded. I verified fanart is present on TVDB for the shows in question, and no doubt about it...it's available.

Well, somehow tonight I pushed the wrong button in BMT and managed to wipe out all my TV fan art and I absolutely cannot get any of it back. Individual shows in Gemstone with CMT, nada. Refresh all metadata and fanart on a group of files in BMT...nada. Search by show in BMT...nada. It goes through the motions, but downloads nothing. Rebooted the server, no change.

I dug through the SageTV server directories and found a Phoenix log file full of lines like these for each show it tries to update (this happens to be for the TV show "Aerial America"). Of note:

1. Exception "Failed to process the actors for series...". Now this show probably legitimately doesn't have any actors, perhaps an unrelated issue. I don't see this on every show.

2. Skipping Fanart since fanart provider is empty (???) Did a setting get changed somewhere? On BMT when an individual episode is selected to update it finds it on TVDB, and I pick it. I'm not sure where else it thinks it should look. On the BMT status page it says "true" under Fanart Enabled. All TV shows seem to have this error along with the final "404" line.

2017-09-18 23:25:50,529 [765787511@qtp-1770872100-2] INFO  sagex.phoenix.metadata.MetadataManager - search(): tvdb; SearchQuery [type=TV, fields={QUERY: Aerial America,EPISODE_DATE: 2017-06-04 00:00,EPISODE: 1,EPISODE_TITLE: New York City 24,SEASON: 8,}, hints=Hints [hints={import_tv_as_recording: false,update_fanart: true,scan_subfolders: true,scan_missing_metadata: true,update_metadata: true,}]]
2017-09-18 23:25:50,531 [765787511@qtp-1770872100-2] INFO  sagex.phoenix.metadata.MetadataManager - Searching: Aerial America using TVDBMetadataProvider[MetadataProviderInfo [id=tvdb, fanartId=null, mediaTypes=[TV], name=thetvdb.com]]
2017-09-18 23:25:52,999 [765787511@qtp-1770872100-2] INFO  sagex.phoenix.metadata.MetadataManager - Fetching Metadata for MediaSearchResult [extraArgs={EPISODE_TITLE: New York City 24,EPISODE_DATE: 2017-06-04 00:00,EPISODE: 1,SEASON: 8,}, id=248718, imdbId=null, metadata=null, providerId=tvdb, score=1.0, title=Aerial America, type=TV, url=http://thetvdb.com/banners/graphical/248718-g2.jpg, year=2009]
2017-09-18 23:25:53,008 [765787511@qtp-1770872100-2] INFO  sagex.phoenix.metadata.provider.tvdb.TVDBSeriesParser - TVDB Series: 248718
2017-09-18 23:25:56,880 [765787511@qtp-1770872100-2] WARN  sagex.phoenix.metadata.provider.tvdb.TVDBSeriesParser - Failed to process the Actors for series: 248718
java.lang.NullPointerException
        at com.omertron.thetvdbapi.tools.DOMHelper.getEventDocFromUrl(DOMHelper.java:122)
        at com.omertron.thetvdbapi.tools.TvdbParser.getActors(TvdbParser.java:107)
        at com.omertron.thetvdbapi.TheTVDBApi.getActors(TheTVDBApi.java:333)
        at sagex.phoenix.metadata.provider.tvdb.TVDBSeriesParser.addActors(TVDBSeriesParser.java:77)
        at sagex.phoenix.metadata.provider.tvdb.TVDBSeriesParser.getSeriesInfo(TVDBSeriesParser.java:67)
        at sagex.phoenix.metadata.provider.tvdb.TVDBMetadataProvider.getSeriesInfo(TVDBMetadataProvider.java:123)
        at sagex.phoenix.metadata.provider.tvdb.TVDBItemParser.addSeriesInfo(TVDBItemParser.java:92)
        at sagex.phoenix.metadata.provider.tvdb.TVDBItemParser.getMetadata(TVDBItemParser.java:60)
        at sagex.phoenix.metadata.provider.tvdb.TVDBMetadataProvider.getMetaData(TVDBMetadataProvider.java:54)
        at sagex.phoenix.metadata.MetadataManager.getMetdata(MetadataManager.java:391)
        at org.jdna.bmt.web.server.BrowsingServicesImpl.getMetadata(BrowsingServicesImpl.java:485)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at com.google.gwt.user.server.rpc.RPC.invokeAndEncodeResponse(RPC.java:587)
        at com.google.gwt.user.server.rpc.RemoteServiceServlet.processCall(RemoteServiceServlet.java:333)
        at com.google.gwt.user.server.rpc.RemoteServiceServlet.processCall(RemoteServiceServlet.java:303)
        at com.google.gwt.user.server.rpc.RemoteServiceServlet.processPost(RemoteServiceServlet.java:373)
        at com.google.gwt.user.server.rpc.AbstractRemoteServiceServlet.doPost(AbstractRemoteServiceServlet.java:62)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
        at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:502)
        at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:389)
        at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
        at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
        at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
        at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:417)
        at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
        at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
        at org.mortbay.jetty.handler.rewrite.RewriteHandler.handle(RewriteHandler.java:230)
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
        at org.mortbay.jetty.Server.handle(Server.java:326)
        at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:534)
        at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:879)
        at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:747)
        at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218)
        at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
        at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
        at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:520)
2017-09-18 23:25:56,925 [765787511@qtp-1770872100-2] INFO  sagex.phoenix.metadata.MetadataManager - Skipping Fanart since Fanart Provider is empty
2017-09-18 23:25:57,237 [765787511@qtp-1770872100-2] WARN  sagex.phoenix.fanart.AdvancedFanartMediaRequestHandler - Fanart Failed: 404; Fanart not found

[texneus]

Desperately seeking clues here. 24 hours later and still no TV fanart. Gemstone just doesn't look "polished" without it. Still see the same errors in the log as well...

[jusjoken]

Can you post your settings from BMT configure under metadata as that may help narrow this down.

The full phoenix and or bmt logs may assist as well

k

[texneus]

I appreciate you looking into this. Some more data -

Last night in BMT I deleted all .properties files from the "TV Shows (All)" view. I also deleted (by hand, because I didn't see another way) all the fanart folders in the TV fanart folders. At that point I chose "Update Metadata..." ensuring "Scan all Subfolders", "Update Metadata", and "Update Fanart" were checked.

Properties files were re-created, so it appears getting/writing metadata isn't a problem. The fanart folders were recreated (Show title with background/banner/poster subfolders), but all folders are empty save a lone "images" file. I then manually downloaded banner/poster/background fanart for one recording (a random Dr. Who episode) from BMT, feeding it URLs from TVDB. That was successful. They also saved in the fanart directory where expected and appeared in the SageTV client. However, tonight I find that the poster I downloaded is gone .

I realized tonight that there is one thing I hadn't tried yet and that was to reboot the router. Done, and no change.

So as requested attached is the page I think you are looking for in BMT and complete Phoenix log files. Tonight I noticed there were two, so you get both. I can't seem to find a BMT log. There is a "bmtweb.log" along side the Phoenix logs, but it's 0 bytes. If you can tell me where the BMT log you need is, I'll get it to you ASAP.

Thank you!!!

[jusjoken]

I have not had time to dig through the logs yet but check your JARs folder and make sure you only have 1 thetvdbapi jar and it should be 1.8

Also, a sagetv log file from the server may assist.

k

[texneus]

Only 1 thetvdbapi.jar and it is version 1.8 (thetvdbapi-1.8.jar is the exact filename).

So here is something else I noticed tonight. Fanart seems to be working in the guide and for future recordings, although I suspect this may be obtained through a different method?

I will need to work out a way to get you the SageTV logs. Even zipped, the most recent file alone exceeds allowable attachment size...

[jusjoken]

Originally Posted by texneus

Only 1 thetvdbapi.jar and it is version 1.8 (thetvdbapi-1.8.jar is the exact filename).

So here is something else I noticed tonight. Fanart seems to be working in the guide and for future recordings, although I suspect this may be obtained through a different method?

I will need to work out a way to get you the SageTV logs. Even zipped, the most recent file alone exceeds allowable attachment size...

Ideally you would restart sage, recreate the issue and then upload that file so its easier to determine an issue.

k

[texneus]

AH, apologies. I was thinking you wanted the whole kit and caboodle so you could see all the failed attempts. Attached are the logs following a restart of the SageTV server followed by these actions:

Waited approx a 5 minutes to ensure the server was fully booted
Logged into BMT web.
Choosing Browse | TV shows (all)
Click "Load More Items" until all TV shows are displayed
Click "Refresh Fanart"
Waited for the refresh to finish.

The zip file contains phoenix.log, phoenix-metadata.log, and sagetv_0.log

[texneus]

I just discovered something that might be useful. I looked in the phoenix-metadata.log for the first time and found the URLs of the images BMT/Phoenix was attempting to download.

Example (emphasis mine):

2017-09-22 10:25:02,509 - FANART-ERROR: /var/RecordedTVFanart/TV/Independent Lens/Posters/48c032da76fca76b36839d5815b10c8c-84082-2.jpg;http://thetvdb.com/banners/posters/84082-2.jpg; Max Retry has been exceeded: 2

A simple WGET to that url shows a redirection from http to https with a 301 error. WGET follows the redirection and retrieves the file (emphasis mine):

# wget http://thetvdb.com/banners/posters/84082-2.jpg
--2017-09-22 10:44:20--  http://thetvdb.com/banners/posters/84082-2.jpg
Resolving thetvdb.com (thetvdb.com)... 104.16.230.14, 104.16.231.14, 104.16.228.14, ...
Connecting to thetvdb.com (thetvdb.com)|104.16.230.14|:80... connected.
HTTP request sent, awaiting response... 301 Moved Permanently
Location: https://www.thetvdb.com/banners/posters/84082-2.jpg [following]
--2017-09-22 10:44:20--  https://www.thetvdb.com/banners/posters/84082-2.jpg
Resolving www.thetvdb.com (www.thetvdb.com)... 104.16.231.14, 104.16.230.14, 104.16.229.14, ...
Connecting to www.thetvdb.com (www.thetvdb.com)|104.16.231.14|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 211386 (206K) [image/jpeg]
Saving to: ‘84082-2.jpg’

84082-2.jpg             100%[==============================>] 206.43K  --.-KB/s    in 0.07s

2017-09-22 10:44:21 (3.08 MB/s) - ‘84082-2.jpg’ saved [211386/211386]

However, BMT and/or Phoenix appears NOT to follow the re-direction, which can be demonstrated through the following:

In the BMT webserver, navigate to the TV show in question (in this case, "Independent Lens" s17e06, and open it to show the metadata. On the fanart tab, click download and give it the HTTP URL it is trying to retrieve.

Result: "Failed to download image from http://thetvdb.com/banners/posters/84082-2.jpg"


Repeat but use the redirected URL from WGET (which is the same URL, just using https and adding a www prefix)

Result: "Image downloaded to ... "

Please see attached.



Edit:
I see the following in the phoenix.log associated with the failed download. This is different that what I see with batch updates, so perhaps this is just a coincidence.

2017-09-22 10:51:24,243 [198011939@qtp-1773343041-6] INFO  sagex.phoenix.metadata.persistence.PersistenceUtil - Writing Image; Url: http://thetvdb.com/banners/posters/84082-2.jpg; ToFile: /var/RecordedTVFanart/TV/Independent Lens/Season 17/Posters/84082-2.jpg
2017-09-22 10:51:24,245 [198011939@qtp-1773343041-6] INFO  sagex.phoenix.download.DownloadManager - Downloading: DownloadItem [bytesDownloaded=0, id=300731300194376, localFile=/var/RecordedTVFanart/TV/Independent Lens/Season 17/Posters/84082-2.jpg, maxReties=1, remoteURL=http://thetvdb.com/banners/posters/84082-2.jpg, retries=0, state=WAITING, totalBytes=0, ]
2017-09-22 10:51:24,294 [198011939@qtp-1773343041-6] WARN  sagex.phoenix.metadata.persistence.PersistenceUtil - Failed to write image: http://thetvdb.com/banners/posters/84082-2.jpg; to file: /var/RecordedTVFanart/TV/Independent Lens/Season 17/Posters/84082-2.jpg
java.io.IOException: Download Failed for item DownloadItem [bytesDownloaded=0, id=300731300194376, localFile=/var/RecordedTVFanart/TV/Independent Lens/Season 17/Posters/84082-2.jpg, maxReties=1, remoteURL=http://thetvdb.com/banners/posters/84082-2.jpg, retries=0, state=WAITING, totalBytes=0, ]
        at sagex.phoenix.download.DownloadManager.downloadAndWait(DownloadManager.java:139)
        at sagex.phoenix.metadata.persistence.PersistenceUtil.writeImageFromUrl(PersistenceUtil.java:49)
        at org.jdna.bmt.web.server.BrowsingServicesImpl.downloadFanart(BrowsingServicesImpl.java:737)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at com.google.gwt.user.server.rpc.RPC.invokeAndEncodeResponse(RPC.java:587)
        at com.google.gwt.user.server.rpc.RemoteServiceServlet.processCall(RemoteServiceServlet.java:333)
        at com.google.gwt.user.server.rpc.RemoteServiceServlet.processCall(RemoteServiceServlet.java:303)
        at com.google.gwt.user.server.rpc.RemoteServiceServlet.processPost(RemoteServiceServlet.java:373)
        at com.google.gwt.user.server.rpc.AbstractRemoteServiceServlet.doPost(AbstractRemoteServiceServlet.java:62)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
        at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:502)
        at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:389)
        at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
        at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
        at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
        at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:417)
        at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
        at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
        at org.mortbay.jetty.handler.rewrite.RewriteHandler.handle(RewriteHandler.java:230)
        at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
        at org.mortbay.jetty.Server.handle(Server.java:326)
        at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:534)
        at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:879)
        at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:747)
        at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218)
        at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
        at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
        at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:520)
Caused by: java.io.IOException: Download Failed no data for DownloadItem [bytesDownloaded=0, id=300731300194376, localFile=/var/RecordedTVFanart/TV/Independent Lens/Season 17/Posters/84082-2.jpg, maxReties=1, remoteURL=http://thetvdb.com/banners/posters/84082-2.jpg, retries=0, state=WAITING, totalBytes=0, ]
        at sagex.phoenix.download.DownloadManager.downloadAndWait(DownloadManager.java:135)
        ... 32 more

I see the following in the phoenix.log associated with a successful download.

2017-09-22 11:09:48,189 [198011939@qtp-1773343041-6] INFO  sagex.phoenix.metadata.persistence.PersistenceUtil - Writing Image; Url: https://www.thetvdb.com/banners/posters/84082-2.jpg; ToFile: /var/RecordedTVFanart/TV/Independent Lens/Season 17/Posters/84082-2.jpg
2017-09-22 11:09:48,191 [198011939@qtp-1773343041-6] INFO  sagex.phoenix.download.DownloadManager - Downloading: DownloadItem [bytesDownloaded=0, id=301835246390455, localFile=/var/RecordedTVFanart/TV/Independent Lens/Season 17/Posters/84082-2.jpg, maxReties=1, remoteURL=https://www.thetvdb.com/banners/posters/84082-2.jpg, retries=0, state=WAITING, totalBytes=0, ]

I see no additional entries in phoenix-metadata.log.

[jusjoken]

I think this is a much more widespread issue...not just you.

I just tried to refresh fanart for a specific season of a series and retrieved NOTHING.

Same error messages in the log.

We will need to dig further and see what is causing this.

Perhaps others can verify if this is affecting everyone or just some.

k

[stuckless]

This is a bug in phoenix core. While I do use the java api to follow redirects, java apparently won't follow a redirect from http to https (or vice versa). Seems silly, but that's the problem here.

I'll need to manually manage the redirects, but the bigger challenge, is finding the time. I've been travelling alot lately, and, working on another paid side project, but i'll see about getting a fix out for this.

I should point out, that the original error (ie from the first post) is different, and is coming from the internal tvdb apis, so, not sure that error is about, so my comments are for the BMT errors you posted.

[Polypro]

Originally Posted by stuckless

This is a bug in phoenix core. While I do use the java api to follow redirects, java apparently won't follow a redirect from http to https (or vice versa). Seems silly, but that's the problem here.

I'll need to manually manage the redirects, but the bigger challenge, is finding the time. I've been travelling alot lately, and, working on another paid side project, but i'll see about getting a fix out for this.

I should point out, that the original error (ie from the first post) is different, and is coming from the internal tvdb apis, so, not sure that error is about, so my comments are for the BMT errors you posted.

I'm glad you know what's up, I was lost. I just know that in the Fanart folders, 0 byte .jpg's are getting downloaded and display as just blank, black boxes.

Here's hoping you get some free time.

Thanks!

[texneus]

Hmmm, I interpreted @stuckless' post as the redirection issue I found is the known issue. The issue noted in my original post is new. Your issue seems somewhat unique though, same symptoms overall except I don't get 0 byte files...I get NO files at all.

[jusjoken]

For those following this issue....the solution is discussed here....

A new phoenix core update should be coming soon!

k

[jusjoken]

Originally Posted by jusjoken

For those following this issue....the solution is discussed here....

A new phoenix core update should be coming soon!

k

Try it with the updated phoenix. It solved my issue.

k

[texneus]

Indeed, yes, I now have TV fanart.

[Polypro]

Same here, great support from the community!