rivenmedia / riven

Handle your Media Library with ease!
GNU General Public License v3.0
297 stars 42 forks source link

raise RuntimeError('cannot schedule new futures after shutdown') #501

Open MVethana opened 2 months ago

MVethana commented 2 months ago

Riven starts, all pages work for a while, then after a bit, the front end pages refuse to load load, returning internal error 500 with the following log error

Jul 9, 2024 23:53:33 - INFO - Riven_frontend: TypeError: fetch failed Jul 9, 2024 23:53:33 - INFO - Riven_frontend: at node:internal/deps/undici/undici:12500:13 Jul 9, 2024 23:53:33 - INFO - Riven_frontend: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) { Jul 9, 2024 23:53:33 - INFO - Riven_frontend: [cause]: Error: connect ECONNREFUSED 127.0.0.1:8080 Jul 9, 2024 23:53:33 - INFO - Riven_frontend: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1605:16) { Jul 9, 2024 23:53:33 - INFO - Riven_frontend: errno: -111, Jul 9, 2024 23:53:33 - INFO - Riven_frontend: code: 'ECONNREFUSED', Jul 9, 2024 23:53:33 - INFO - Riven_frontend: syscall: 'connect', Jul 9, 2024 23:53:33 - INFO - Riven_frontend: address: '127.0.0.1', Jul 9, 2024 23:53:33 - INFO - Riven_frontend: port: 8080 Jul 9, 2024 23:53:33 - INFO - Riven_frontend: } Jul 9, 2024 23:53:33 - INFO - Riven_frontend: } Jul 9, 2024 23:53:35 - INFO - Riven_backend: Error submitting job "Program._submit_job (trigger: interval[0:01:00], next run at: 2024-07-09 23:53:35 UTC)" to executor "default" Jul 9, 2024 23:53:35 - INFO - Riven_backend: Traceback (most recent call last): Jul 9, 2024 23:53:35 - INFO - Riven_backend: File "/venv/lib/python3.11/site-packages/apscheduler/schedulers/base.py", line 988, in _process_jobs Jul 9, 2024 23:53:35 - INFO - Riven_backend: executor.submit_job(job, run_times) Jul 9, 2024 23:53:35 - INFO - Riven_backend: File "/venv/lib/python3.11/site-packages/apscheduler/executors/base.py", line 71, in submit_job Jul 9, 2024 23:53:35 - INFO - Riven_backend: self._do_submit_job(job, run_times) Jul 9, 2024 23:53:35 - INFO - Riven_backend: File "/venv/lib/python3.11/site-packages/apscheduler/executors/pool.py", line 28, in _do_submit_job Jul 9, 2024 23:53:35 - INFO - Riven_backend: f = self._pool.submit(run_job, job, job._jobstore_alias, run_times, self._logger.name) Jul 9, 2024 23:53:35 - INFO - Riven_backend: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Jul 9, 2024 23:53:35 - INFO - Riven_backend: File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 167, in submit Jul 9, 2024 23:53:35 - INFO - Riven_backend: raise RuntimeError('cannot schedule new futures after shutdown') Jul 9, 2024 23:53:35 - INFO - Riven_backend: RuntimeError: cannot schedule new futures after shutdown Jul 9, 2024 23:53:35 - INFO - Riven_backend: Error submitting job "Program._submit_job (trigger: interval[0:01:00], next run at: 2024-07-09 23:53:35 UTC)" to executor "default" Jul 9, 2024 23:53:35 - INFO - Riven_backend: Traceback (most recent call last): Jul 9, 2024 23:53:35 - INFO - Riven_backend: File "/venv/lib/python3.11/site-packages/apscheduler/schedulers/base.py", line 988, in _process_jobs Jul 9, 2024 23:53:35 - INFO - Riven_backend: executor.submit_job(job, run_times) Jul 9, 2024 23:53:35 - INFO - Riven_backend: File "/venv/lib/python3.11/site-packages/apscheduler/executors/base.py", line 71, in submit_job Jul 9, 2024 23:53:35 - INFO - Riven_backend: self._do_submit_job(job, run_times) Jul 9, 2024 23:53:35 - INFO - Riven_backend: File "/venv/lib/python3.11/site-packages/apscheduler/executors/pool.py", line 28, in _do_submit_job Jul 9, 2024 23:53:35 - INFO - Riven_backend: f = self._pool.submit(run_job, job, job._jobstore_alias, run_times, self._logger.name) Jul 9, 2024 23:53:35 - INFO - Riven_backend: ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ Jul 9, 2024 23:53:35 - INFO - Riven_backend: File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 167, in submit Jul 9, 2024 23:53:35 - INFO - Riven_backend: raise RuntimeError('cannot schedule new futures after shutdown') Jul 9, 2024 23:53:35 - INFO - Riven_backend: RuntimeError: cannot schedule new futures after shutdown

AyushSehrawat commented 2 months ago

Backend fails due to the above error, causes API to not start, hence the error.

Does restarting fixed it? Try deleting media.pkl and media.pkl.bak and restart

@dreulavelle look into it 👍🏻.

MVethana commented 2 months ago

Happens consistently after restart within a couple min, will delete and report back

AyushSehrawat commented 2 months ago

Happens consistently after restart within a couple min, will delete and report back

Which content service you use? Overseer or some other? Lookout if any item is without poster in thenm

MVethana commented 2 months ago

I originally linked my existing overseerr that had been used for a while so all the old requests got sent to Riven. Having trouble locating the file you mentioned, currently using aio DMB if that helps

AyushSehrawat commented 2 months ago

I originally linked my existing overseerr that had been used for a while so all the old requests got sent to Riven. Having trouble locating the file you mentioned, currently using aio DMB if that helps

Can you check in overseerr's request page if some item is missing posters?

MVethana commented 2 months ago

I have over 2k requests in there, did find this one as an example image

AyushSehrawat commented 2 months ago

I have over 2k requests in there, did find this one as an example image

Remove it and then either delete media.pkl and media.pkl.bak or remove from api

AyushSehrawat commented 2 months ago

@MVethana keep it open, we need to be handle such instances

@dreulavelle ^^

dreulavelle commented 2 months ago

this isnt the error.. its above these logs. these logs show that it cant schedule new jobs since it was closed down.. the real error is above this...

@MVethana We need to see the rest of the logs above these errors

AyushSehrawat commented 2 months ago

this isnt the error.. its above these logs. these logs show that it cant schedule new jobs since it was closed down.. the real error is above this...

@MVethana We need to see the rest of the logs above these errors

I think it's related to bad item in overseerr, changed ids or removed etc

dreulavelle commented 2 months ago

it could also be a Movie error that uses the wrong attribute that doesnt exist.. I've seen that one too. It can be anything.. these logs don't show the error

MVethana commented 2 months ago

I can repro by adding my existing overseerr library again, will do

MVethana commented 2 months ago

Jul 11, 2024 14:29:47 - ERROR - Riven_backend: | main. - Error in main thread: 'NoneType' object has no attribute 'log_string' Jul 11, 2024 14:29:47 - INFO - Riven_backend: | 🤖 PROGRAM | program._remove_from_running_items - ######### Jul 11, 2024 14:29:47 - INFO - Riven_backend: | 🔍 DISCOVERY | program._push_event_queue - ######### Jul 11, 2024 14:29:47 - INFO - Riven_backend: | 📽️ LOCAL | local.run - Updated Switch Jul 11, 2024 14:29:47 - ERROR - Riven_backend: | main. - Traceback (most recent call last): Jul 11, 2024 14:29:47 - INFO - Riven_backend: File "/riven/backend/main.py", line 114, in Jul 11, 2024 14:29:47 - INFO - Riven_backend: app.program.run() Jul 11, 2024 14:29:47 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 372, in run Jul 11, 2024 14:29:47 - INFO - Riven_backend: self.add_to_running(event.item, "program.run") Jul 11, 2024 14:29:47 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 264, in add_to_running Jul 11, 2024 14:29:47 - INFO - Riven_backend: logger.log("PROGRAM", f"Item {item.log_string} started running section {service_name}" ) Jul 11, 2024 14:29:47 - INFO - Riven_backend: ^^^^^^^^^^^^^^^ Jul 11, 2024 14:29:47 - INFO - Riven_backend: File "/riven/backend/program/media/item.py", line 438, in log_string Jul 11, 2024 14:29:47 - INFO - Riven_backend: return f"{self.parent.log_string}E{self.number:02}" Jul 11, 2024 14:29:47 - INFO - Riven_backend: ^^^^^^^^^^^^^^^^^^^^^^ Jul 11, 2024 14:29:47 - INFO - Riven_backend: AttributeError: 'NoneType' object has no attribute 'log_string' Jul 11, 2024 14:29:47 - INFO - Riven_backend: Traceback (most recent call last): Jul 11, 2024 14:29:47 - INFO - Riven_backend: File "/riven/backend/main.py", line 114, in Jul 11, 2024 14:29:47 - INFO - Riven_backend: app.program.run() Jul 11, 2024 14:29:47 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 372, in run Jul 11, 2024 14:29:47 - INFO - Riven_backend: self.add_to_running(event.item, "program.run") Jul 11, 2024 14:29:47 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 264, in add_to_running Jul 11, 2024 14:29:47 - INFO - Riven_backend: logger.log("PROGRAM", f"Item {item.log_string} started running section {service_name}" ) Jul 11, 2024 14:29:47 - INFO - Riven_backend: File "/riven/backend/program/media/item.py", line 438, in log_string Jul 11, 2024 14:29:47 - INFO - Riven_backend: return f"{self.parent.log_string}E{self.number:02}" Jul 11, 2024 14:29:47 - INFO - Riven_backend: AttributeError: 'NoneType' object has no attribute 'log_string'

Jul 11, 2024 14:29:46 - ERROR - Riven_backend: | program._process_future_item - Service TraktIndexer failed with exception Traceback (most recent call last): Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 291, in _process_future_item Jul 11, 2024 14:29:46 - INFO - Riven_backend: self._push_event_queue(Event(emitted_by=service, item=item)) Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 246, in _push_event_queue Jul 11, 2024 14:29:46 - INFO - Riven_backend: logger.log("DISCOVERY", f"Re-added {event.item.log_string} to the queue" ) Jul 11, 2024 14:29:46 - INFO - Riven_backend: ^^^^^^^^^^^^^^^^^^^^^ Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/media/item.py", line 438, in log_string Jul 11, 2024 14:29:46 - INFO - Riven_backend: return f"{self.parent.log_string}E{self.number:02}" Jul 11, 2024 14:29:46 - INFO - Riven_backend: ^^^^^^^^^^^^^^^^^^^^^^ Jul 11, 2024 14:29:46 - INFO - Riven_backend: AttributeError: 'NoneType' object has no attribute 'log_string' Jul 11, 2024 14:29:46 - INFO - Riven_backend: Traceback (most recent call last): Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 291, in _process_future_item Jul 11, 2024 14:29:46 - INFO - Riven_backend: self._push_event_queue(Event(emitted_by=service, item=item)) Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 246, in _push_event_queue Jul 11, 2024 14:29:46 - INFO - Riven_backend: logger.log("DISCOVERY", f"Re-added {event.item.log_string} to the queue" ) Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/media/item.py", line 438, in log_string Jul 11, 2024 14:29:46 - INFO - Riven_backend: return f"{self.parent.log_string}E{self.number:02}" Jul 11, 2024 14:29:46 - INFO - Riven_backend: AttributeError: 'NoneType' object has no attribute 'log_string' Jul 11, 2024 14:29:46 - INFO - Riven_backend: | 🤖 PROGRAM | program._remove_from_running_items - Item tt21316834 finished running section TraktIndexer Jul 11, 2024 14:29:46 - ERROR - Riven_backend: | program._process_future_item - Service TraktIndexer failed with exception Traceback (most recent call last): Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 291, in _process_future_item Jul 11, 2024 14:29:46 - INFO - Riven_backend: self._push_event_queue(Event(emitted_by=service, item=item)) Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 246, in _push_event_queue Jul 11, 2024 14:29:46 - INFO - Riven_backend: logger.log("DISCOVERY", f"Re-added {event.item.log_string} to the queue" ) Jul 11, 2024 14:29:46 - INFO - Riven_backend: ^^^^^^^^^^^^^^^^^^^^^ Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/media/item.py", line 438, in log_string Jul 11, 2024 14:29:46 - INFO - Riven_backend: return f"{self.parent.log_string}E{self.number:02}" Jul 11, 2024 14:29:46 - INFO - Riven_backend: ^^^^^^^^^^^^^^^^^^^^^^ Jul 11, 2024 14:29:46 - INFO - Riven_backend: AttributeError: 'NoneType' object has no attribute 'log_string' Jul 11, 2024 14:29:46 - INFO - Riven_backend: Traceback (most recent call last): Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 291, in _process_future_item Jul 11, 2024 14:29:46 - INFO - Riven_backend: self._push_event_queue(Event(emitted_by=service, item=item)) Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 246, in _push_event_queue Jul 11, 2024 14:29:46 - INFO - Riven_backend: logger.log("DISCOVERY", f"Re-added {event.item.log_string} to the queue" ) Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/media/item.py", line 438, in log_string Jul 11, 2024 14:29:46 - INFO - Riven_backend: return f"{self.parent.log_string}E{self.number:02}" Jul 11, 2024 14:29:46 - INFO - Riven_backend: AttributeError: 'NoneType' object has no attribute 'log_string' Jul 11, 2024 14:29:46 - INFO - Riven_backend: | 🤖 PROGRAM | program._remove_from_running_items - Item tt13820496 finished running section TraktIndexer Jul 11, 2024 14:29:46 - ERROR - Riven_backend: | program._process_future_item - Service TraktIndexer failed with exception Traceback (most recent call last): Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 291, in _process_future_item Jul 11, 2024 14:29:46 - INFO - Riven_backend: self._push_event_queue(Event(emitted_by=service, item=item)) Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 246, in _push_event_queue Jul 11, 2024 14:29:46 - INFO - Riven_backend: logger.log("DISCOVERY", f"Re-added {event.item.log_string} to the queue" ) Jul 11, 2024 14:29:46 - INFO - Riven_backend: ^^^^^^^^^^^^^^^^^^^^^ Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/media/item.py", line 438, in log_string Jul 11, 2024 14:29:46 - INFO - Riven_backend: return f"{self.parent.log_string}E{self.number:02}" Jul 11, 2024 14:29:46 - INFO - Riven_backend: ^^^^^^^^^^^^^^^^^^^^^^ Jul 11, 2024 14:29:46 - INFO - Riven_backend: AttributeError: 'NoneType' object has no attribute 'log_string' Jul 11, 2024 14:29:46 - INFO - Riven_backend: Traceback (most recent call last): Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 291, in _process_future_item Jul 11, 2024 14:29:46 - INFO - Riven_backend: self._push_event_queue(Event(emitted_by=service, item=item)) Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 246, in _push_event_queue Jul 11, 2024 14:29:46 - INFO - Riven_backend: logger.log("DISCOVERY", f"Re-added {event.item.log_string} to the queue" ) Jul 11, 2024 14:29:46 - INFO - Riven_backend: File "/riven/backend/program/media/item.py", line 438, in log_string Jul 11, 2024 14:29:46 - INFO - Riven_backend: return f"{self.parent.log_string}E{self.number:02}" Jul 11, 2024 14:29:46 - INFO - Riven_backend: AttributeError: 'NoneType' object has no attribute 'log_string'

Jul 11, 2024 14:29:45 - ERROR - Riven_backend: | program._process_future_item - Service TraktIndexer failed with exception Traceback (most recent call last): Jul 11, 2024 14:29:45 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 291, in _process_future_item Jul 11, 2024 14:29:45 - INFO - Riven_backend: self._push_event_queue(Event(emitted_by=service, item=item)) Jul 11, 2024 14:29:45 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 246, in _push_event_queue Jul 11, 2024 14:29:45 - INFO - Riven_backend: logger.log("DISCOVERY", f"Re-added {event.item.log_string} to the queue" ) Jul 11, 2024 14:29:45 - INFO - Riven_backend: ^^^^^^^^^^^^^^^^^^^^^ Jul 11, 2024 14:29:45 - INFO - Riven_backend: File "/riven/backend/program/media/item.py", line 438, in log_string Jul 11, 2024 14:29:45 - INFO - Riven_backend: return f"{self.parent.log_string}E{self.number:02}" Jul 11, 2024 14:29:45 - INFO - Riven_backend: ^^^^^^^^^^^^^^^^^^^^^^ Jul 11, 2024 14:29:45 - INFO - Riven_backend: AttributeError: 'NoneType' object has no attribute 'log_string' Jul 11, 2024 14:29:45 - INFO - Riven_backend: Traceback (most recent call last): Jul 11, 2024 14:29:45 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 291, in _process_future_item Jul 11, 2024 14:29:45 - INFO - Riven_backend: self._push_event_queue(Event(emitted_by=service, item=item)) Jul 11, 2024 14:29:45 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 246, in _push_event_queue Jul 11, 2024 14:29:45 - INFO - Riven_backend: logger.log("DISCOVERY", f"Re-added {event.item.log_string} to the queue" ) Jul 11, 2024 14:29:45 - INFO - Riven_backend: File "/riven/backend/program/media/item.py", line 438, in log_string Jul 11, 2024 14:29:45 - INFO - Riven_backend: return f"{self.parent.log_string}E{self.number:02}" Jul 11, 2024 14:29:45 - INFO - Riven_backend: AttributeError: 'NoneType' object has no attribute 'log_string' Jul 11, 2024 14:29:45 - INFO - Riven_backend: | 🤖 PROGRAM | program._remove_from_running_items - Item tt21316870 finished running section TraktIndexer Jul 11, 2024 14:29:45 - ERROR - Riven_backend: | program._process_future_item - Service TraktIndexer failed with exception Traceback (most recent call last): Jul 11, 2024 14:29:45 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 291, in _process_future_item Jul 11, 2024 14:29:45 - INFO - Riven_backend: self._push_event_queue(Event(emitted_by=service, item=item)) Jul 11, 2024 14:29:45 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 246, in _push_event_queue Jul 11, 2024 14:29:45 - INFO - Riven_backend: logger.log("DISCOVERY", f"Re-added {event.item.log_string} to the queue" ) Jul 11, 2024 14:29:45 - INFO - Riven_backend: ^^^^^^^^^^^^^^^^^^^^^ Jul 11, 2024 14:29:45 - INFO - Riven_backend: File "/riven/backend/program/media/item.py", line 438, in log_string Jul 11, 2024 14:29:45 - INFO - Riven_backend: return f"{self.parent.log_string}E{self.number:02}" Jul 11, 2024 14:29:45 - INFO - Riven_backend: ^^^^^^^^^^^^^^^^^^^^^^ Jul 11, 2024 14:29:45 - INFO - Riven_backend: AttributeError: 'NoneType' object has no attribute 'log_string' Jul 11, 2024 14:29:45 - INFO - Riven_backend: Traceback (most recent call last): Jul 11, 2024 14:29:45 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 291, in _process_future_item Jul 11, 2024 14:29:45 - INFO - Riven_backend: self._push_event_queue(Event(emitted_by=service, item=item)) Jul 11, 2024 14:29:45 - INFO - Riven_backend: File "/riven/backend/program/program.py", line 246, in _push_event_queue Jul 11, 2024 14:29:45 - INFO - Riven_backend: logger.log("DISCOVERY", f"Re-added {event.item.log_string} to the queue" ) Jul 11, 2024 14:29:45 - INFO - Riven_backend: File "/riven/backend/program/media/item.py", line 438, in log_string Jul 11, 2024 14:29:45 - INFO - Riven_backend: return f"{self.parent.log_string}E{self.number:02}" Jul 11, 2024 14:29:45 - INFO - Riven_backend: AttributeError: 'NoneType' object has no attribute 'log_string'

Left the TT id's to hopefully help debug

dreulavelle commented 2 months ago

which branch is this?

MVethana commented 2 months ago

main, running through aio DMB

dreulavelle commented 2 months ago

aio DMB?

MVethana commented 2 months ago

All In One - Debrid Media Bridge https://github.com/I-am-PUID-0/DMB All it does is combine riven and the other apps together, riven itself is the one giving the error here

dreulavelle commented 2 months ago

I'm wondering if his is out of date or something. You're getting a lot of the NoneType errors. More so than you should be getting. It is a known bug, but I havent seen it pop up as many times as I'm seeing from your logs.

Are you working with a list, or did you just request a few items?

Right now, Documentaries, Mini-Series, Soaps and some old classic shows/movies don't work that great. It's coming up with NoneType because it wasn't able to index the item with an IMDb ID. Our indexing is going to get reworked to improve this as well. I'm hoping to put it in with the 0.8.0 release though.

MVethana commented 2 months ago

It pulls the latest straight from main, to repro the errors I reattached my existing overseer with 2k+ requests. It automatically added all my existing items into Riven.

image

Will remove delete and not re-link until the indexing handles this scenario better. Thanks again for the hard work