Hellowlol / bw_plex

binge watching for plex
MIT License
368 stars 23 forks source link

Crashes after "ghost" media is added to Plex #114

Closed deepfriedmind closed 4 years ago

deepfriedmind commented 4 years ago

It starts up fine and is then "Watching for media on NAS". After a while it says "was added to NAS", i.e. empty string was added. I did not add anything to my Plex library at the time. It then tries to process this nothing and gets a bad request from the Plex API since it's a 404, and then the Docker container crashes/restarts and the process is repeated. I do have process_recently_added enabled for TV, so watching for added media is correct. process_deleted is disabled (I'm not sure why this setting exists). It does work when actual files are added so that's great. Since I have Plex set to delete episodes a while after being watched, my best guess is that this deletion triggers bw_plex – which then tries to find metadata for something that no longer exists.

Here's the log:

2019-12-31 13:43:40,707 :: bw_plex :: INFO :: __init__.py:172 :: Using bw_plex version 0.1.dev1+g864e2a2
2019-12-31 13:43:40,708 :: bw_plex :: INFO :: __init__.py:173 :: default folder set to /config
2019-12-31 13:43:41,485 :: bw_plex :: INFO :: plex.py:1383 :: Added signal handler.
2019-12-31 13:43:41,521 :: bw_plex :: DEBUG :: misc.py:64 :: Getting server NAS
2019-12-31 13:43:41,523 :: bw_plex :: DEBUG :: misc.py:572 :: Getting hashtable
2019-12-31 13:43:41,735 :: bw_plex :: INFO :: misc.py:658 :: Loading existing files in db
2019-12-31 13:43:44,740 :: bw_plex :: DEBUG :: misc.py:587 :: Files in the hashtable
Watching for media on NAS
2019-12-31 13:43:44,753 :: bw_plex :: DEBUG :: plex.py:1311 :: ws event Ready(response=<response HTTP/1.1 101 Switching Protocols>, protocol=None, extensions=set())
2019-12-31 14:48:37,509 :: bw_plex :: DEBUG :: plex.py:1252 ::  was added to NAS
disconnecting websocket
Traceback (most recent call last):
  File "/usr/local/bin/bw_plex", line 11, in <module>
    load_entry_point('bw-plex', 'console_scripts', 'bw_plex')()
  File "/app/bw_plex/bw_plex/cli.py", line 24, in fake_main
    real_main()
  File "/app/bw_plex/bw_plex/plex.py", line 1394, in real_main
    cli()
  File "/usr/local/lib/python3.6/dist-packages/click/core.py", line 764, in __call__
    return self.main(*args, **kwargs)
  File "/usr/local/lib/python3.6/dist-packages/click/core.py", line 717, in main
    rv = self.invoke(ctx)
  File "/usr/local/lib/python3.6/dist-packages/click/core.py", line 1137, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/lib/python3.6/dist-packages/click/core.py", line 956, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/usr/local/lib/python3.6/dist-packages/click/core.py", line 555, in invoke
    return callback(*args, **kwargs)
  File "/app/bw_plex/bw_plex/plex.py", line 1308, in watch
    check(data['NotificationContainer'])
  File "/app/bw_plex/bw_plex/plex.py", line 1262, in check
    ep = PMS.fetchItem(int(ratingkey))
  File "/usr/local/lib/python3.6/dist-packages/plexapi/base.py", line 137, in fetchItem
    for elem in self._server.query(ekey):
  File "/usr/local/lib/python3.6/dist-packages/plexapi/server.py", line 381, in query
    raise BadRequest('(%s) %s; %s %s' % (response.status_code, codename, response.url, errtext))
plexapi.exceptions.BadRequest: (404) not_found; http://localhost:32400/library/metadata/57918 <html><head><title>Not Found</title></head><body><h1>404 Not Found</h1></body></html>
Hellowlol commented 4 years ago

Can you check what 57918 is? just pass the url in plex webui. process_deleted is inteded to be used as cleanup. it something get removed from plex, delete it from bw_plex too

deepfriedmind commented 4 years ago

57918 and all others I've encountered in the log don't exist in the library, hence why I think it's TV episodes that have been deleted.

Hellowlol commented 4 years ago

Ok, thanks. Ill look into that.

Hellowlol commented 4 years ago

Note to self. check how tautulli handles the timeline websocket events. https://github.com/Tautulli/Tautulli/blob/a7a9ed86280d87cded8930a2cb15b8909db2354e/plexpy/activity_handler.py#L366

deepfriedmind commented 4 years ago

Thanks for the update. I tested it now and got the following in the log:

2020-01-01 22:23:42,753 :: bw_plex :: DEBUG :: plex.py:1250 ::  was added to NAS
2020-01-01 22:23:42,785 :: bw_plex :: ERROR :: plex.py:1265 :: Didn't start to process 57949
Traceback (most recent call last):
  File "/app/bw_plex/bw_plex/plex.py", line 1262, in check
    ep = PMS.fetchItem(int(ratingkey))
  File "/usr/local/lib/python3.6/dist-packages/plexapi/base.py", line 137, in fetchItem
    for elem in self._server.query(ekey):
  File "/usr/local/lib/python3.6/dist-packages/plexapi/server.py", line 381, in query
    raise BadRequest('(%s) %s; %s %s' % (response.status_code, codename, response.url, errtext))
plexapi.exceptions.BadRequest: (404) not_found; http://localhost:32400/library/metadata/57949 <html><head><title>Not Found</title></head><body><h1>404 Not Found</h1></body></html>
2020-01-01 22:23:42,829 :: bw_plex :: DEBUG :: plex.py:1275 :: Didn't start to process  is process_deleted is disabled for

It didn't crash, so that's great :)