HAMA not functioning anymore

Lalaberri commented 5 years ago

I've enjoyed the struggle to learn the ins and outs of using HAMA with ASS and I'd like to believe I'm a level 8/10 master at this despites some quirky inconsistencies I can't make sense of sometimes, but, as of today after not adding a series for a couple of days (maybe 3-4) I notice the HAMA agent doesn't appear to be working any longer. I have changed nothing in that time and have been using this agent for some time on 3 different devices but now I get 'no results' from any 'match' requests and it doesn't match automatically any longer. Other agents appear to be still working like the default TVDB ones, but we all know this is better. Doesn't appear to be specific to any series. Even going back to already matched ones, it now shows no results as well

I have: -Stopped/restarted service and server -updated/reinstalled HAMA and ASS by removing old files and replacing with new. -restarted computer

I did see mention of something about AniDB denying requests in the common.py file update and presumed that updating would help as it appeared to be addressed but that didn't appear to help

ZeroQI commented 5 years ago

You need to delete or manually update anime-titles.xml in Hama agent data folders Anidb... They now need double decompression and Plex may have n issue with xml>1Mb. The fix work but the cache file is still left corrupted in cache folder...

alexwh commented 5 years ago

I don't know if I am experiencing the same issue, but the following logs are in my console:

AnimeLists:35: FutureWarning: The behavior of this method will change in future versions. Use specific 'len(elem)' or 'elem is not None' test instead.
AnimeLists:21: FutureWarning: The behavior of this method will change in future versions. Use specific 'len(elem)' or 'elem is not None' test instead.
AnimeLists:23: FutureWarning: The behavior of this method will change in future versions. Use specific 'len(elem)' or 'elem is not None' test instead.
AnimeLists:24: FutureWarning: The behavior of this method will change in future versions. Use specific 'len(elem)' or 'elem is not None' test instead.
AnimeLists:60: FutureWarning: The behavior of this method will change in future versions. Use specific 'len(elem)' or 'elem is not None' test instead.
Traceback (most recent call last):
  File "/usr/lib/plexmediaserver/Resources/Python/lib/python2.7/logging/handlers.py", line 76, in emit
    if self.shouldRollover(record):
  File "/usr/lib/plexmediaserver/Resources/Python/lib/python2.7/logging/handlers.py", line 156, in shouldRollover
    msg = "%s\n" % self.format(record)
  File "/usr/lib/plexmediaserver/Resources/Python/lib/python2.7/logging/__init__.py", line 734, in format
    return fmt.format(record)
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-bb4a2cb6c/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/core.py", line 77, in format
    record.__dict__[key] = uni(record.__dict__[key])
UnicodeDecodeError: 'utf8' codec can't decode byte 0x8b in position 32: invalid start byte
Logged from file sandbox.py, line 19

This was caused by clicking "Fix match" on a title, then clicking search options and search with HAMA selected. I cloned the latest version, and deleted all files named anime-titles.xml I could find (AniDB/anime-titles.xml and XMLs/anime-titles.xml). I could not find logs in Plug-in Support/Data/com.plexapp.agents.hama/DataItems/_Logs or Logs/PMS Plugin Logs. I am running the latest version of PMS from the docker image pms-docker:public.

ZeroQI commented 5 years ago

it doesn't like one character in a title... I need complete agent logs to narrow down

alexwh commented 5 years ago

I was looking in the wrong folder - /var/lib/plex/Logs instead of /var/lib/plex/Library/Application Support/Plex Media Server/Logs. Here's where the error seems to occur:

2019-05-06 20:35:55,814 - 7f33caffd700 - Exception in the search function of agent named 'HamaTV', called with keyword arguments {'show': 'Lucky Star', 'id': '2280', 'year': '2007'} (most recent call last):
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-bb4a2cb6c/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/api/agentkit.py", line 1007, in _search
    agent.search(*f_args, **f_kwargs)
  File "/config/Library/Application Support/Plex Media Server/Plug-ins/Hama.bundle/Contents/Code/__init__.py", line 151, in search
    def search (self, results,  media, lang, manual):  Search (results,  media, lang, manual, False)
  File "/config/Library/Application Support/Plex Media Server/Plug-ins/Hama.bundle/Contents/Code/__init__.py", line 100, in Search
    if movie or max(map(int, media.seasons.keys()))<=1:  maxi, n =         AniDB.Search(results, media, lang, manual, movie)
  File "/config/Library/Application Support/Plex Media Server/Plug-ins/Hama.bundle/Contents/Code/AniDB.py", line 45, in Search
    for element in AniDBTitlesDB.xpath(u"/animetitles/anime/title[text()[contains(lower-case(.), '%s')]]" % orig_title.lower().replace("'", " ")):
AttributeError: 'str' object has no attribute 'xpath'

FWIW this happens on multiple titles - I tested JoJo's Bizzare Adventure and Lucky Star.

edit: disregard, I updated to the latest version from git in the wrong folder again - thanks plex for coherent folder structure

ZeroQI commented 5 years ago

download http://anidb.net/api/anime-titles.xml.gz, decompress until xml readable and replace manually AniDB/anime-titles.xml you probably got banned and not letting you download (more than once a day and you are banned)

alexwh commented 5 years ago

It works now, thanks. Perhaps there should be some sort of backwards compatability check to delete and redownload the file if it's detected to be a gzip?

Lalaberri commented 5 years ago

I applaud you ZeroQI for knowing exactly what I was talking about and that simple edit got everything running again. I applaud you and all you do for making this great plug-in that inspired me to further use plex for my large collection to make a proper library. Going through it painstakingly and in the O's now finally.

ZeroQI commented 5 years ago

@EndOfLine369 we should have failsafe and if saved file needs loading and not xml, we delete it ?

ZeroQI commented 5 years ago

/plex/Plex Media Server/Plug-in Support/Data/com.plexapp.agents.hama/DataItems/AniDB/anime-titles.xml is the file to replace

EndOfLine369 commented 5 years ago

@ZeroQI, Looks like they've now broken the anime-titles.xml.gz with the 403 forbidden even with a User-Agent being passed. Will need to be raised with them on their multiple changes as would believe the've probably now broken any programmatic api calls.

At least against 'http://anidb.net/api/' (for titles gz) is now not working 'http://img7.anidb.net' is still working for now that was effected earlier and got working w/header add 'http://api.anidb.net:9001' is still working

ZeroQI commented 5 years ago

We should load it from scudlee's github as backup to avoid second onslaught of agent not working bug report and delete file on disk if not correct as it impacted heavily users

icemouton commented 5 years ago

@ZeroQI yeah I figured it out by moving stuff around thing is I'm 80% sure I didn't have anime-titles in AniDB folder to begin with but I ended up putting it there and it fixed my problem and then I deleted my comment :) Keep up the amazing work!

deridiot commented 5 years ago

it's "broken" with a 403 as we got swarmed by clients that keep on downloading it hundreds of times per day for no good reason. if your clients breaks it certainly should not end up in an endless loop of ddos for us.

eitherway these clients ended up getting nftable banned which means these users can't evne use the website which is not exactly a desired effect. hence i redirected certain useragents to a 403 for the time being.

i get that you are annoyed about stuff not working, but we can't have 3rd party services waste our resources.

as for why this happened in the first place i couldn't tell. we switched to nginx a few days ago, but i see no difference in how we serve the title dump itself. the xml.gz file is created by the same script as has been for the past decade. gzip is enabled in nginx and there is no content-encoding header served with it so "double encoding" shouldn't be a thing.

and maybe try contacting us if you are having issues. i can't tell which client is causing issues when all i have is a flood of ips getting banned and all i have to go on is their similar, but nothing saying useragent. useragents exist to identify software, use it! the only reason i even found this bug was 1 user contacting us on irc and linking to this.

so ship your fix and set a new useragent and you will be good to go.

deriDIOt AniDB mod

deridiot commented 5 years ago

and maybe some people should stick to the set limits of once per day as written in the wiki. it's easy to start finger pointing. how about we fix the issue? wouldn't that be more useful

Am Fr., 10. Mai 2019 um 17:32 Uhr schrieb Alex notifications@github.com:

Perhaps you should consider investing in a rate limiting system rather than going nuclear and pulling everything?

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/ZeroQI/Hama.bundle/issues/309#issuecomment-491331096, or mute the thread https://github.com/notifications/unsubscribe-auth/AAHZRJSWFMGG5P6ZVMSVU43PUWIPPANCNFSM4HLBU7WA .

alexwh commented 5 years ago

My mistake, I misread your original message and thought you were permadropping users for exceeding these limits. On a more constructive note, if this operation is expensive, why not only update it daily and then serve it to everyone without limits (within reason)? Alternatively, provide access to the file through an API which can properly return data to the client on how often it can make that call. It's true that if this library was hammering your servers it should be fixed, and it should probably also identify itself with a proper user agent to avoid this in future, though.

deridiot commented 5 years ago

no it's a timed ban and usually short unless peopel go nuclear on us. plus i even kept unbanning people over and over the past few days, but as it kept on happening (in the past few hours alone ~10k times) i switched to a 403 to keep people to at least use the website, because i prefer external software breaking over people not being able to access our website.

the file is generated once per day. it's not generated on demand that would be silly. it's still 1mb of data compressed and 4mb uncompressed per retrieval. certain clients that shall be left unnamed have tried downloading it for every single file they parsed and hence created a massive amount of load at some point. which is why we started the limit in the first place. eitherway it adds up and while the limit of our isp is large enough i prefer to keep usage low.

i'm not the developer/maintainer of the api so i won't comment on implementations of that.

as for "fixed" you need to consider that there are people out there that will be using the broken version of the plugin for months or years so this issue isn't going away anytime soon. hence removing the useragent ban wouldn't resolve the issue for everyone.

and to make it abundantly clear i'm not here to pont fingers. i'm not blaming anyone. coding issues happen. you might not consider the long term implications. we are just humans. instead let's work on the issue at hand.

alexwh commented 5 years ago

no it's a timed ban and usually short unless peopel go nuclear on us. plus i even kept unbanning people over and over the past few days, but as it kept on happening (in the past few hours alone ~10k times) i switched to a 403 to keep people to at least use the website, because i prefer external software breaking over people not being able to access our website.

as for "fixed" you need to consider that there are people out there that will be using the broken version of the plugin for months or years so this issue isn't going away anytime soon. hence removing the useragent ban wouldn't resolve the issue for everyone.

That's understandable, and I agree.

the file is generated once per day. it's not generated on demand that would be silly. it's still 1mb of data compressed and 4mb uncompressed per retrieval. certain clients that shall be left unnamed have tried downloading it for every single file they parsed and hence created a massive amount of load at some point. which is why we started the limit in the first place. eitherway it adds up and while the limit of our isp is large enough i prefer to keep usage low.

Have you considered a CDN service like Cloudflare? If the problem is bandwidth, having it cached outside of your network would make a big difference on what your origin actually recieves.

Pontuzz commented 5 years ago

I'm kind of perplexed at the moment. I've managed to solve the main problem by redownloading anime-titles.xml and metadata started downloading again.

Over a few TB of series matching and downloading flawlessly, I'm now stuck with two series that refuse to download metadata. One Piece is matched to tvdb and so is Haikyuu!!, plex says its processing, downloading etc but nothing gets applied.

ZeroQI commented 5 years ago

@deridiot Thanks. We will set a user agent string. Normally plex caches it (seem to no do that for XML>1024KB compressed) and i store it locally to use, and refresh every 6 days and reuse the cached version if there was any issue.

That bug made us save an encrypted version, and people must be restarting Plex and querying multiple times... I never wanted to impact your services and for that i apologise. Why we have to double decompress is weird.

To be coded:

ensure user agent is always used with AniDB so they can prevent flood to their services in case of agent bug
delete incorect xml on disk
if error fallback to https://github.com/ScudLee/anime-lists/blob/master/animetitles.xml

purposelycryptic commented 5 years ago

@ZeroQI - I think I mentioned this in a related issue, but when I was seeing the problem with the encrypted/corrupted title xml, just replacing it with a proper copy wasn't enough to fix the issue, because it would get overwritten by the one in HTML cache on any activity like updating metadata (possibly because the file had a newer date?).

I had to search for the file in the cache by file-size, and manually overwrite it with the non-broken one. Not sure if it was just encrypted, since it was 1/4 the size of the functional one.

Also, RE: ScudLee's anime lists, I'm not sure what is going on over there, but it's been 3 weeks since the last update, and no one is responding to issues/pull-requests to add/update mappings. ScudLee's account isn't showing any activity since last November, either :-/

ZeroQI commented 5 years ago

Custom match for a series called clear-cache then cancel, that will delete Plex cache Which is why I said as fallback

deridiot commented 5 years ago

@ZeroQI thx for the fast and competent reply. if you need anything from us let me know.

EndOfLine369 commented 5 years ago

FYI @ZeroQI, a 'User-agent': 'Plex/Nine' is being passed when pulling that file. HEADERS = {'User-agent': 'Plex/Nine', 'Content-type': 'application/json'} Only image pulls were not passing a 'User-agent' which has since been fixed.

EndOfLine369 commented 5 years ago

EX of 403 w/User-agent passed.

2019-05-10 22:14:49,559 (5484) :  DEBUG (networking:166) - Requesting 'http://anidb.net/api/anime-titles.xml.gz'
2019-05-10 22:14:49,885 (5484) :  ERROR (networking:219) - Error opening URL 'http://anidb.net/api/anime-titles.xml.gz'
2019-05-10 22:14:49,887 (5484) :  WARNING (sandbox:19) - common.LoadFile() - issue loading url: 'http://anidb.net/api/anime-titles.xml.gz', filename: 'anime-titles.xml', Headers: {'Content-type': 'application/json', 'User-agent': 'Plex/Nine'}, Exception: 'HTTP Error 403: Forbidden'
2019-05-10 22:14:49,887 (5484) :  DEBUG (sandbox:19) - Completed 'http://anidb.net/api/anime-titles.xml.gz'
2019-05-10 22:14:49,887 (5484) :  INFO (sandbox:19) - LoadFile() - not xml nor json: None

deridiot commented 5 years ago

well i just tested downloading with that specific useragent:

curl -A 'Plex/Nine' http://anidb.net/api/anime-titles.xml.gz > anime-titles.xml.gz
% Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 1043k  100 1043k    0     0   136M      0 --:--:-- --:--:-- --:--:--  145M

none of the blocked useragents i have in nginx should block that one and my test confirms it doesn't. are we absolutely certain you are really sending "plex/nine"? i will gladly check our server logs if you give me something to look for.

-edit- i skimmed over the code and found this in common.py:

file = HTTP.Request(url, headers=UpdateDict(headers, HEADERS if url.startswith('https://api.thetvdb.com') else {}), timeout=60, cacheTime=cache).content

i think the header is only sent for thetvdb. otherwise it prolly uses whatefver is the standard of that lib.

EndOfLine369 commented 5 years ago

Indeed. And logging is incorrect as well as was just printing HEADERS and not what was actually used. Log.Warning("common.LoadFile() - issue loading url: '{}', filename: '{}', Headers: {}, Exception: '{}'".format(url, filename, HEADERS, e))

duckness commented 5 years ago

@deridiot consider using the HTTP 429 status code instead of 403. It lets you optionally specify a Retry-After header to tell cilents when they are able to make a new request. You can also see how discord does rate-limiting: https://discordapp.com/developers/docs/topics/rate-limits

EndOfLine369 commented 5 years ago

Header setup reviewed/updated and pushed to master.

And FYI on prev update https://github.com/ZeroQI/Hama.bundle/commit/6ca35ca35a5976198f271a23442d8950b0f9b01b as well as HAMA would only load a preexisting file if pull was successful but data was seen as bad. So when we were hitting a 403, it would not load from local file cache even if it was aged.

ZeroQI commented 5 years ago

@EndOfLine369 Thanks a lot for the modification. The intent was a local cache when downloading, if outdated load from source and revert to local outdated in case of issues... Should also never have saved the bad file if not seen as XML as it brakes all...

TieSKey commented 5 years ago

~~I'm getting a really strange behavior when rebuilding a library (around 400 items). After the agent processes more or less 75% of the library in alphabetical order, it stops getting new metadata starting from the 'R' . Looking at the log the cause seems to be a ban from anidb but... ...deleting the library and anidb caches and rebuilding will again get metadata for around half the items and then get the banned message again. Maybe I'm missing some other cache files somewhere :S~~

2019-05-13 13:46:39,270 - 72c59470 - Fetching 'http://api.anidb.net:9001/httpapi?request=anime&client=hama&clientver=1&protover=1&aid=10553' from the HTTP cache

~~(I find it weird that the log says it will save data to an xml even if the response was a "banned")~~

~~Tried refreshing metadata for the entire library after waiting for 1 day but nothing new was pulled~~

Edit: Completely my bad, failed to read the "cache" word at the end of the line. I was under the assumption cache was handled at a higher level than http. After deleting the correct cache files it is working fine.

ZeroQI commented 5 years ago

It doesn't say that... Ban is generally 24 hours. You night want to manually matxh search for a series 'clear-cache' to clear Plex cache. Working on better saving function to avoid a flood of comments like this bug caused...

TieSKey commented 5 years ago

Thanks for the hint, I misread the log. Edited the comment above to stress that.

architdate commented 5 years ago

Hi, I'm new here and having the same issue even after replacing ASS with the latest commit and the xml file. Are there any more steps to this that I am missing? Also for me even manually specifying the tvdb id or anidb id (using [tvdb-xxxxx]) doesn't help find a match anymore. Do let me know if I'm missing any steps to fixing this! Thanks!

2019-05-18 04:11:39,957 (d450) :  CRITICAL (core:574) - Exception starting plug-in (most recent call last):
  File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-4610c6e8d\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\core.py", line 608, in start
    self.sandbox.execute(self.init_code)
  File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-4610c6e8d\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\sandbox.py", line 256, in execute
    exec(code) in self.environment
  File "C:\Users\Archit\AppData\Local\Plex Media Server\Plug-ins\Hama.bundle\Contents\Code\__init__.py", line 12, in <module>
    import AniDB             # Functions: GetMetadata, Search, GetAniDBTitlesDB, GetAniDBTitle       Variables: ANIDB_SERIE_URL
  File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-4610c6e8d\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\sandbox.py", line 333, in __import__
    return mod.load_module(_name)
  File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-4610c6e8d\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\sandbox.py", line 44, in load_module
    module = RestrictedModule(name, path, sandbox)
  File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-4610c6e8d\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\loader.py", line 30, in __init__
    exec(code) in self.__dict__
  File "C:\Users\Archit\AppData\Local\Plex Media Server\Plug-ins\Hama.bundle\Contents\Code\AniDB.py", line 340, in <module>
    AniDBTitlesDB = GetAniDBTitlesDB()
  File "C:\Users\Archit\AppData\Local\Plex Media Server\Plug-ins\Hama.bundle\Contents\Code\AniDB.py", line 301, in GetAniDBTitlesDB
    if not AniDBTitlesDB:  raise Exception("Failed to load core file '{url}'".format(url=os.path.splitext(os.path.basename(ANIDB_TITLES))[0]))
Exception: Failed to load core file 'anime-titles.xml'

relevant logs ^ I can confirm however that anime-titles.xml is located where its supposed to be (refer to the path on windows explorer)

ZeroQI commented 5 years ago

Why is anime-titles.xml NOT in AniDB folder?

architdate commented 5 years ago

Why is anime-titles.xml NOT in AniDB folder?

Oh its there too (although, that one isn't manually updated)

Will update and report back! Its still a bit weird that it couldnt load a file that was already existing in the folder

EDIT: That fixed it! Thanks! Stupidity on my part :) Hope this gets fixed though!

ZeroQI commented 5 years ago

you can delete the one outside AniDB The issue was the xml needed uncompressing twice from a point in time and HAMA saved it compressed, therefore loading incorrect cache afterwards... Since online pulling didn't work neither (and prob banned at that point) we have this issues...

Still coding to only save not corrupted and adaptative cache (1 day if ongoing, 1 year if completed and 6 days if unknown, can be tweaked latter. That should allow series in progress refresh and cached by metadata source and lowe the load greatly on old series that won't change, and just a day plex cache as backup...

sheik124 commented 5 years ago

I can't get Hama to download an individual XML file for a series, so under "Plex Media Server\Plug-in Support\Data\com.plexapp.agents.hama\DataItems\AniDB" the new anidb ID doesn't show up as an XML file, and typing "[anidb-AID#]" into Plex's manual match box isn't working for those same series either, although it can find them by title.

I updated anime-titles.xml manually, decompressed it with 7Zip, and placed it in the AniDB folder

ZeroQI commented 5 years ago

@sheik124 Logs required

DarthKnight12 commented 5 years ago

hi,

i still don't know what is happening at my end, but i have tried multiple things now:

deleted anime-titles.xml deleted HAMA and ASS Reinstalled Hama and ASS after inital scan, deleted anime-titles.xml everywhere and replaced it with the provided version. Still i have multiple shows that just refuse to load/show/fetch metadata and are left completely blank. Im slowly but surely losing my mind

log (with the relevant info):

com.plexapp.agents.hama_relevantinfo.log

ZeroQI commented 5 years ago

@DarthKnight12 Error ValueError: invalid literal for int() with base 10: '' already reported in https://github.com/ZeroQI/Hama.bundle/issues/314. Didn't had time to look into it yet.

mvegetto commented 5 years ago

I have downloaded http://anidb.net/api/anime-titles.xml.gz, unpacked it, replaced the file and cleared cache. That solved it for now :).

ZeroQI commented 5 years ago

Just published fix for tvdb4 and adaptive cache system which handle even compressed xml which should stop the onslaught of agent issue with the anidb title xml file Please test and report. It did fix without manual download the issue for me

crazygambit commented 5 years ago

Just published fix for tvdb4 and adaptive cache system which handle even compressed xml which should stop the onslaught of agent issue with the anidb title xml file Please test and report. It did fix without manual download the issue for me

I updated both HAMA and the Scanner, redownloaded the anime-titles.xml (the 4.6MB one), cleared the cache and I still can't get it to work at all. When I refresh a show I keep getting these errors in the com.plexapp.agents.hama.log

2019-06-10 13:46:50,405 (14fe9f9fc700) : INFO (common:152) - ==== common.PlexLog(file="/config/Library/Application Support/Plex Media Server/Plug-in Support/Data/com.plexapp.agents.hama/DataItems/_Logs/Test/One Piece [tvdb4-81797].agent-update.log") 2019-06-10 13:46:50,557 (14fe9f9fc700) : DEBUG (networking:166) - Requesting 'https://api.thetvdb.com/episodes/619671' 2019-06-10 13:46:51,444 (14fe9f9fc700) : ERROR (networking:219) - Error opening URL 'https://api.thetvdb.com/episodes/619671'

Edit: It had been a few hours since I updated everything and I made this post. Of course as soon as I posted this, it decided to fixed itself and now it's working fine. I guess I must have been temporarily banned from AniDB. Thanks for all your work!

ZeroQI commented 5 years ago

@crazygambit Thanks for kepping me updated. It was TheTVDB that gave errors? Unusual... Please let me know any issues

mvegetto commented 5 years ago

I am getting these errors:

Jun 12, 2019 01:39:41.079 [0x7fc208ff9700] WARN - Held transaction for too long (../Statistics/StatisticsManager.cpp:248): 0.110000 seconds Jun 12, 2019 01:40:11.190 [0x7fc208ff9700] WARN - Held transaction for too long (../Statistics/StatisticsManager.cpp:248): 0.110000 seconds Jun 12, 2019 01:40:41.307 [0x7fc209ffb700] WARN - Held transaction for too long (../Statistics/StatisticsManager.cpp:248): 0.120000 seconds Jun 12, 2019 01:41:49.620 [0x7fc1a77fe700] ERROR - Timeout or error reading status line from plug-in pipe [com.plexapp.agents.hama], we're killing it. Jun 12, 2019 01:41:49.620 [0x7fc1a77fe700] DEBUG - Stopping [com.plexapp.agents.hama]. Jun 12, 2019 01:41:49.620 [0x7fc1a77fe700] DEBUG - [com.plexapp.agents.hama] Killing. Jun 12, 2019 01:41:49.620 [0x7fc1a77fe700] ERROR - Error received reading configuration for com.plexapp.agents.hama Jun 12, 2019 01:41:49.620 [0x7fc1a77fe700] DEBUG - Stopping [com.plexapp.agents.hama].

ZeroQI commented 5 years ago

Do you know from hama agent logs (check series log in Hama agent data folder> Logs) which step of the agent was the agent stuck in a loop at?

mvegetto commented 5 years ago

2019-06-12 02:02:20,207 (7fb567f26b80) : CRITICAL (core:615) - Exception starting plug-in (most recent call last): File "/usr/lib/plexmediaserver/Resources/Plug-ins-eadbcbb45/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/core.py", line 608, in start self.sandbox.execute(self.init_code) File "/usr/lib/plexmediaserver/Resources/Plug-ins-eadbcbb45/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/code/sandbox.py", line 256, in execute exec(code) in self.environment File "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-ins/Hama.bundle/Contents/Code/init.py", line 8, in import common # Functions: Logging, SaveFile, LoadFile, metadata_download, WriteLogs, cleanse_title, GetMetadata, UpdateMeta, UpdateMetaField File "/usr/lib/plexmediaserver/Resources/Plug-ins-eadbcbb45/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/code/sandbox.py", line 333, in import return mod.load_module(_name) File "/usr/lib/plexmediaserver/Resources/Plug-ins-eadbcbb45/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/code/sandbox.py", line 44, in load_module module = RestrictedModule(name, path, sandbox) File "/usr/lib/plexmediaserver/Resources/Plug-ins-eadbcbb45/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/code/loader.py", line 20, in init code = sandbox._core.loader.load(filename, sandbox.policy.elevated_execution) File "/usr/lib/plexmediaserver/Resources/Plug-ins-eadbcbb45/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/code/loader.py", line 47, in load code = self.compile(str(source), str(uni(filename)), elevated) File "/usr/lib/plexmediaserver/Resources/Plug-ins-eadbcbb45/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/code/loader.py", line 52, in compile return RestrictedPython.compile_restricted(source, name, 'exec', elevated=elevated) File "/usr/lib/plexmediaserver/Resources/Plug-ins-eadbcbb45/Framework.bundle/Contents/Resources/Platforms/Shared/Libraries/RestrictedPython/RCompile.py", line 115, in compile_restricted gen.compile() File "/usr/lib/plexmediaserver/Resources/Plug-ins-eadbcbb45/Framework.bundle/Contents/Resources/Platforms/Shared/Libraries/RestrictedPython/RCompile.py", line 68, in compile tree = self._get_tree() File "/usr/lib/plexmediaserver/Resources/Plug-ins-eadbcbb45/Framework.bundle/Contents/Resources/Platforms/Shared/Libraries/RestrictedPython/RCompile.py", line 59, in _get_tree tree = self.parse() File "/usr/lib/plexmediaserver/Resources/Plug-ins-eadbcbb45/Framework.bundle/Contents/Resources/Platforms/Shared/Libraries/RestrictedPython/RCompile.py", line 56, in parse return niceParse(self.source, self.filename, self.mode) File "/usr/lib/plexmediaserver/Resources/Plug-ins-eadbcbb45/Framework.bundle/Contents/Resources/Platforms/Shared/Libraries/RestrictedPython/RCompile.py", line 38, in niceParse compile(source, filename, mode) File "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-ins/Hama.bundle/Contents/Code/common.py", line 7 <!DOCTYPE html> ^ SyntaxError: invalid syntax

2019-06-12 02:02:20,341 (7fb551ffb700) : DEBUG (services:362) - Loaded services 2019-06-12 02:02:20,341 (7fb550ff9700) : DEBUG (core:538) - Machine identifier is 299f8d44fa731de659f015eec957cfa78779f6f9 2019-06-12 02:02:20,347 (7fb5517fa700) : DEBUG (services:438) - No shared code to load 2019-06-12 02:02:20,347 (7fb550ff9700) : DEBUG (core:539) - Server version is 1.15.8.1198-eadbcbb45

ZeroQI commented 5 years ago

Please check the File "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-ins/Hama.bundle/Contents/Code/common.py", line 7 on your disk then in github as line 7 is not empty and your last log seem to indicate otherwise...

mvegetto commented 5 years ago

Thanks, I replaced the files and it's fixed. Unpack screw up I believe :)

kanjieater commented 5 years ago

http://anidb.net/api/anime-titles.xml.gz,

I've replaced this file twice. It works for a week then stops being able to scan again.

2019-06-15 21:00:43,270 (182c) :  DEBUG (core:361) - Using the elevated policy
2019-06-15 21:00:43,270 (182c) :  DEBUG (core:450) - Starting runtime component.
2019-06-15 21:00:43,282 (182c) :  DEBUG (core:450) - Starting caching component.
2019-06-15 21:00:43,283 (182c) :  DEBUG (core:450) - Starting data component.
2019-06-15 21:00:43,283 (182c) :  DEBUG (core:450) - Starting networking component.
2019-06-15 21:00:43,286 (182c) :  DEBUG (networking:284) - Loaded HTTP cookies
2019-06-15 21:00:43,312 (182c) :  DEBUG (networking:452) - Setting the default network timeout to 20.0
2019-06-15 21:00:43,312 (182c) :  DEBUG (core:450) - Starting localization component.
2019-06-15 21:00:43,313 (182c) :  INFO (localization:409) - Setting the default locale to en-us
2019-06-15 21:00:43,315 (182c) :  DEBUG (core:450) - Starting messaging component.
2019-06-15 21:00:43,316 (182c) :  DEBUG (core:450) - Starting debugging component.
2019-06-15 21:00:43,319 (281c) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/system/messaging/clear_events/com.plexapp.agents.hama'
2019-06-15 21:00:43,319 (182c) :  DEBUG (core:450) - Starting services component.
2019-06-15 21:00:43,323 (182c) :  DEBUG (core:450) - Starting myplex component.
2019-06-15 21:00:43,326 (182c) :  DEBUG (core:450) - Starting notifications component.
2019-06-15 21:00:43,655 (182c) :  DEBUG (accessor:68) - Creating a new model access point for provider com.plexapp.agents.hama in namespace 'metadata'
2019-06-15 21:00:43,671 (182c) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/resourceHashes'
2019-06-15 21:00:43,730 (2334) :  DEBUG (services:265) - Plug-in is not daemonized - loading services from system
2019-06-15 21:00:43,730 (182c) :  DEBUG (runtime:1117) - Created a thread named 'load_all_services'
2019-06-15 21:00:43,734 (182c) :  DEBUG (runtime:1117) - Created a thread named 'get_server_info'
2019-06-15 21:00:43,734 (2334) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_'
2019-06-15 21:00:43,737 (182c) :  DEBUG (core:150) - Finished starting framework core
2019-06-15 21:00:43,737 (18c4) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400'
2019-06-15 21:00:43,740 (182c) :  DEBUG (core:560) - Loading plug-in code
2019-06-15 21:00:43,769 (18c4) :  DEBUG (core:538) - Machine identifier is 66904f313c942862ef0750d52193d31eb8597faf
2019-06-15 21:00:43,769 (18c4) :  DEBUG (core:539) - Server version is 1.15.6.1079-78232c603
2019-06-15 21:00:44,710 (182c) :  DEBUG (core:566) - Finished loading plug-in code
2019-06-15 21:00:45,115 (2334) :  DEBUG (services:362) - Loaded services
2019-06-15 21:00:45,160 (80c) :  DEBUG (services:438) - No shared code to load
2019-06-15 21:00:46,104 (182c) :  DEBUG (networking:166) - Requesting 'http://127.0.0.1:32400/library/sections/'
2019-06-15 21:00:46,118 (182c) :  INFO (logkit:16) - Libraries: 
2019-06-15 21:00:46,118 (182c) :  INFO (logkit:16) - [ ] id: 13, type:   show, library: Anime Archive           , path: Z:\Videos\Anime Archive
2019-06-15 21:00:46,118 (182c) :  INFO (logkit:16) - [ ] id: 22, type: artist, library: Audiobooks              , path: Z:\MusicBee\Audiobooks
2019-06-15 21:00:46,118 (182c) :  INFO (logkit:16) - [ ] id:  7, type:  movie, library: J-Anime Movies          , path: Z:\Videos\J-Anime Movies
2019-06-15 21:00:46,118 (182c) :  INFO (logkit:16) - [ ] id:  5, type:   show, library: J-Anime Shows           , path: Z:\Videos\J-Anime Shows
2019-06-15 21:00:46,119 (182c) :  INFO (logkit:16) - [ ] id: 19, type:  movie, library: J-Movies                , path: Z:\Videos\J-Movies
2019-06-15 21:00:46,119 (182c) :  INFO (logkit:16) - [ ] id: 23, type:   show, library: J-Shows                 , path: Z:\Videos\J-Shows
2019-06-15 21:00:46,121 (182c) :  INFO (logkit:16) - [ ] id: 21, type: artist, library: Music                   , path: Z:\MusicBee\Music
2019-06-15 21:00:46,121 (182c) :  INFO (logkit:16) - [ ] id: 18, type:   show, library: Music Videos            , path: Z:\Videos\Music Videos
2019-06-15 21:00:46,121 (182c) :  INFO (logkit:16) - [ ] id: 20, type:   show, library: US-Comedy               , path: Z:\Videos\US-Comedy Shows
2019-06-15 21:00:46,121 (182c) :  INFO (logkit:16) - [ ] id: 14, type:  movie, library: US-Movies               , path: Z:\Videos\US-Movies
2019-06-15 21:00:46,121 (182c) :  INFO (logkit:16) - [ ] id: 12, type:   show, library: US-Shows                , path: Z:\Videos\US-Shows
2019-06-15 21:00:46,122 (182c) :  INFO (logkit:16) - [ ] id: 17, type:   show, library: Web Shows               , path: Z:\Videos\Web Shows
2019-06-15 21:00:46,894 (182c) :  DEBUG (networking:166) - Requesting 'http://anidb.net/api/anime-titles.xml.gz'
2019-06-15 21:00:47,576 (182c) :  ERROR (networking:219) - Error opening URL 'http://anidb.net/api/anime-titles.xml.gz'
2019-06-15 21:00:47,578 (182c) :  WARNING (sandbox:19) - common.LoadFile() - issue loading url: 'http://anidb.net/api/anime-titles.xml.gz', filename: 'anime-titles.xml', Headers: {'Content-type': 'application/json', 'User-agent': 'Plex/Nine'}, Exception: 'HTTP Error 403: Forbidden'
2019-06-15 21:00:47,578 (182c) :  DEBUG (sandbox:19) - Completed 'http://anidb.net/api/anime-titles.xml.gz'
2019-06-15 21:00:47,578 (182c) :  INFO (sandbox:19) - LoadFile() - not xml nor json: None                                                                            
2019-06-15 21:00:47,585 (182c) :  CRITICAL (core:574) - Exception starting plug-in (most recent call last):
  File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-78232c603\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\core.py", line 608, in start
    self.sandbox.execute(self.init_code)
  File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-78232c603\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\sandbox.py", line 256, in execute
    exec(code) in self.environment
  File "C:\Users\micah\AppData\Local\Plex Media Server\Plug-ins\Hama.bundle\Contents\Code\__init__.py", line 11, in <module>
    import AnimeLists        # Functions: GetMetadata, GetAniDBTVDBMap, GetAniDBMovieSet, MergeMaps  Variables: MAPPING_FEEDBACK
  File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-78232c603\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\sandbox.py", line 333, in __import__
    return mod.load_module(_name)
  File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-78232c603\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\sandbox.py", line 44, in load_module
    module = RestrictedModule(name, path, sandbox)
  File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-78232c603\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\loader.py", line 30, in __init__
    exec(code) in self.__dict__
  File "C:\Users\micah\AppData\Local\Plex Media Server\Plug-ins\Hama.bundle\Contents\Code\AnimeLists.py", line 6, in <module>
    import AniDB
  File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-78232c603\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\sandbox.py", line 333, in __import__
    return mod.load_module(_name)
  File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-78232c603\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\sandbox.py", line 44, in load_module
    module = RestrictedModule(name, path, sandbox)
  File "C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-78232c603\Framework.bundle\Contents\Resources\Versions\2\Python\Framework\code\loader.py", line 30, in __init__
    exec(code) in self.__dict__
  File "C:\Users\micah\AppData\Local\Plex Media Server\Plug-ins\Hama.bundle\Contents\Code\AniDB.py", line 367, in <module>
    AniDBTitlesDB = GetAniDBTitlesDB()
  File "C:\Users\micah\AppData\Local\Plex Media Server\Plug-ins\Hama.bundle\Contents\Code\AniDB.py", line 328, in GetAniDBTitlesDB
    if not AniDBTitlesDB:  raise Exception("Failed to load core file '{url}'".format(url=os.path.splitext(os.path.basename(ANIDB_TITLES))[0]))
Exception: Failed to load core file 'anime-titles.xml'

ZeroQI / Hama.bundle

HAMA not functioning anymore #309