search

pymedusa / Medusa

Automatic Video Library Manager for TV Shows. It watches for new episodes of your favorite shows, and when they are posted it does its magic.
https://pymedusa.com
GNU General Public License v3.0
1.79k stars 276 forks source link

Medusa has ramdom disk related I/O errors after waking from hibernation [Win10] #6539

Open rafi-d opened 5 years ago

rafi-d commented 5 years ago

Following up on my IRC report:

23:47 22:05 08:00 Just booted from hibernation on W10. Medusa is completely dead, with like 16 errors. A known limitation? 23:50 medusabot p0psicles> I Dont know. Never tried that. But it shouldn't happen ofcourse 23:50 medusabot p0psicles> You can always create a bug report. Maybe someone picks it up?

When waling up from Hibernation using Windows 10 (my case is 7-8 hours, overnight) , Medusae seems to show random/different disk I/O errors.

To Reproduce

  1. shut down->hibernate your PC while medusa service (and uTorrent in my case) is running
  2. Go to sleep ...
  3. check it up after booting in the next morning
  4. I/O errors are showing, sometimes, medusa may not search any more sometimes.

Expected behavior None of these errors

Logs - below

Maybe we need to check if we are waking up from hibernation/sleep and give a bit of delay in this case before disk I/O ?

Medusa (please complete the following information):


2019-04-13 08:36:30 ERROR    Thread_1 :: [54da0c7] DB error: Error: 'disk I/O error'
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 285, in action
    sql_results = self._execute(query, args, fetchall=fetchall, fetchone=fetchone)
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 113, in _execute
    sql_results = cursor.execute(query)
OperationalError: disk I/O error
2019-04-13 08:36:30 ERROR    Thread_1 :: [54da0c7] DB error: OperationalError('disk I/O error',)
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 113, in _execute
    sql_results = cursor.execute(query)
OperationalError: disk I/O error
2019-04-13 08:36:30 ERROR    Thread_1 :: [54da0c7] Exception generated: disk I/O error
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\server\web\core\base.py", line 262, in async_call
    result = function(**kwargs)
  File "D:\Program Files\Medusa\Medusa\medusa\server\web\home\handler.py", line 169, in index
    stats = self.show_statistics()
  File "D:\Program Files\Medusa\Medusa\medusa\server\web\home\handler.py", line 237, in show_statistics
    today=date.today().toordinal())
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 315, in select
    sql_results = self.action(query, args, fetchall=True)
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 285, in action
    sql_results = self._execute(query, args, fetchall=fetchall, fetchone=fetchone)
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 113, in _execute
    sql_results = cursor.execute(query)
OperationalError: disk I/O error
2019-04-13 08:13:11 ERROR    SHOWQUEUE-REFRESH :: [54da0c7] 71663: Error while refreshing show The Simpsons. Error: disk I/O error
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\show_queue.py", line 688, in run
    self.show.refresh_dir()
  File "D:\Program Files\Medusa\Medusa\medusa\tv\series.py", line 1745, in refresh_dir
    self.load_episodes_from_dir()
  File "D:\Program Files\Medusa\Medusa\medusa\tv\series.py", line 1008, in load_episodes_from_dir
    cur_episode = self.make_ep_from_file(os.path.join(self.location, media_file))
  File "D:\Program Files\Medusa\Medusa\medusa\tv\series.py", line 1369, in make_ep_from_file
    main_db_con.mass_action(sql_l)
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 222, in mass_action
    sql_results.append(self._execute(qu[0], qu[1], fetchall=fetchall))
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 115, in _execute
    sql_results = cursor.execute(query, args)
OperationalError: disk I/O error
2019-04-13 08:13:06 ERROR    SHOWQUEUE-REFRESH :: [54da0c7] 279536: Error while refreshing show Billions. Error: disk I/O error
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\show_queue.py", line 688, in run
    self.show.refresh_dir()
  File "D:\Program Files\Medusa\Medusa\medusa\tv\series.py", line 1745, in refresh_dir
    self.load_episodes_from_dir()
  File "D:\Program Files\Medusa\Medusa\medusa\tv\series.py", line 1057, in load_episodes_from_dir
    main_db_con.mass_action(sql_l)
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 223, in mass_action
    self.connection.commit()
OperationalError: disk I/O error
2019-04-13 08:13:03 ERROR    SHOWQUEUE-REFRESH :: [54da0c7] 328711: Error while refreshing show Star Trek: Discovery. Error: [Errno 12] Not enough space
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\show_queue.py", line 688, in run
    self.show.refresh_dir()
  File "D:\Program Files\Medusa\Medusa\medusa\tv\series.py", line 1745, in refresh_dir
    self.load_episodes_from_dir()
  File "D:\Program Files\Medusa\Medusa\medusa\tv\series.py", line 1047, in load_episodes_from_dir
    cur_episode.refresh_subtitles()
  File "D:\Program Files\Medusa\Medusa\medusa\tv\episode.py", line 442, in refresh_subtitles
    current_subtitles = subtitles.get_current_subtitles(self)
  File "D:\Program Files\Medusa\Medusa\medusa\subtitles.py", line 593, in get_current_subtitles
    video = get_video(tv_episode, video_path)
  File "D:\Program Files\Medusa\Medusa\medusa\subtitles.py", line 722, in get_video
    video = scan_video(video_path)
  File "D:\Program Files\Medusa\Medusa\ext\subliminal\core.py", line 439, in scan_video
    video.hashes['napiprojekt'] = hash_napiprojekt(path)
  File "D:\Program Files\Medusa\Medusa\ext\subliminal\utils.py", line 68, in hash_napiprojekt
    data = f.read(readsize)
IOError: [Errno 12] Not enough space
2019-04-13 08:12:59 ERROR    SHOWQUEUE-REFRESH :: [54da0c7] 328487: Error while refreshing show The Orville. Error: [Errno 12] Not enough space
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\show_queue.py", line 688, in run
    self.show.refresh_dir()
  File "D:\Program Files\Medusa\Medusa\medusa\tv\series.py", line 1745, in refresh_dir
    self.load_episodes_from_dir()
  File "D:\Program Files\Medusa\Medusa\medusa\tv\series.py", line 1047, in load_episodes_from_dir
    cur_episode.refresh_subtitles()
  File "D:\Program Files\Medusa\Medusa\medusa\tv\episode.py", line 442, in refresh_subtitles
    current_subtitles = subtitles.get_current_subtitles(self)
  File "D:\Program Files\Medusa\Medusa\medusa\subtitles.py", line 593, in get_current_subtitles
    video = get_video(tv_episode, video_path)
  File "D:\Program Files\Medusa\Medusa\medusa\subtitles.py", line 722, in get_video
    video = scan_video(video_path)
  File "D:\Program Files\Medusa\Medusa\ext\subliminal\core.py", line 436, in scan_video
    video.hashes['opensubtitles'] = hash_opensubtitles(path)
  File "D:\Program Files\Medusa\Medusa\ext\subliminal\utils.py", line 24, in hash_opensubtitles
    filebuffer = f.read(bytesize)
IOError: [Errno 12] Not enough space
2019-04-13 08:10:58 ERROR    FINDPROPERS :: [Torrentz2] :: [54da0c7] Exception generated: disk I/O error
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\scheduler.py", line 93, in run
    self.action.run(self.force)
  File "D:\Program Files\Medusa\Medusa\medusa\search\proper.py", line 66, in run
  File "D:\Program Files\Medusa\Medusa\medusa\search\proper.py", line 124, in _get_proper_results
    cur_propers = cur_provider.find_propers(recently_aired)
  File "D:\Program Files\Medusa\Medusa\medusa\providers\generic_provider.py", line 202, in find_propers
  File "D:\Program Files\Medusa\Medusa\medusa\tv\series.py", line 807, in get_episode
  File "D:\Program Files\Medusa\Medusa\medusa\tv\episode.py", line 270, in __init__
  File "D:\Program Files\Medusa\Medusa\medusa\tv\episode.py", line 555, in _specify_episode
  File "D:\Program Files\Medusa\Medusa\medusa\tv\episode.py", line 649, in load_from_db
  File "D:\Program Files\Medusa\Medusa\medusa\scene_numbering.py", line 472, in xem_refresh
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 355, in upsert
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 286, in action
OperationalError: disk I/O error
2019-04-13 08:10:56 ERROR    FINDPROPERS :: [Torrentz2] :: [54da0c7] DB error: Error: 'disk I/O error'
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 286, in action
OperationalError: disk I/O error
2019-04-13 08:10:43 ERROR    CHECKVERSION :: [54da0c7] Environment error: HTTPSConnectionPool(host='api.github.com', port=443): Max retries exceeded with url: /orgs/pymedusa (Caused by SSLError(IOError(12, 'Not enough space'),))
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\scheduler.py", line 93, in run
    self.action.run(self.force)
  File "D:\Program Files\Medusa\Medusa\medusa\version_checker.py", line 69, in run
  File "D:\Program Files\Medusa\Medusa\medusa\version_checker.py", line 359, in list_remote_branches
    app.GIT_REMOTE_BRANCHES = self.updater.list_remote_branches()
  File "D:\Program Files\Medusa\Medusa\medusa\version_checker.py", line 1044, in list_remote_branches
    gh = get_github_repo(app.GIT_ORG, app.GIT_REPO)
  File "D:\Program Files\Medusa\Medusa\medusa\github_client.py", line 101, in get_github_repo
    return gh.get_organization(organization).get_repo(repo)
  File "D:\Program Files\Medusa\Medusa\ext2\github\MainClass.py", line 261, in get_organization
    "/orgs/" + login
  File "D:\Program Files\Medusa\Medusa\ext2\github\Requester.py", line 264, in requestJsonAndCheck
    return self.__check(*self.requestJson(verb, url, parameters, headers, input, self.__customConnection(url)))
  File "D:\Program Files\Medusa\Medusa\ext2\github\Requester.py", line 324, in requestJson
    return self.__requestEncode(cnx, verb, url, parameters, headers, input, encode)
  File "D:\Program Files\Medusa\Medusa\ext2\github\Requester.py", line 377, in __requestEncode
    status, responseHeaders, output = self.__requestRaw(cnx, verb, url, requestHeaders, encoded_input)
  File "D:\Program Files\Medusa\Medusa\ext2\github\Requester.py", line 401, in __requestRaw
    response = cnx.getresponse()
  File "D:\Program Files\Medusa\Medusa\ext2\github\Requester.py", line 109, in getresponse
    r = verb(url, headers=self.headers, data=self.input, timeout=self.timeout, verify=self.verify, allow_redirects=False)
  File "D:\Program Files\Medusa\Medusa\ext\requests\sessions.py", line 546, in get
  File "D:\Program Files\Medusa\Medusa\ext\requests\sessions.py", line 533, in request
  File "D:\Program Files\Medusa\Medusa\ext\requests\sessions.py", line 646, in send
  File "D:\Program Files\Medusa\Medusa\ext\requests\adapters.py", line 514, in send
SSLError: HTTPSConnectionPool(host='api.github.com', port=443): Max retries exceeded with url: /orgs/pymedusa (Caused by SSLError(IOError(12, 'Not enough space'),))
2019-04-13 00:30:31 ERROR    DAILYSEARCHER :: [54da0c7] Exception generated: astimezone() cannot be applied to a naive datetime
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\scheduler.py", line 93, in run
  File "D:\Program Files\Medusa\Medusa\medusa\search\daily.py", line 113, in run
ValueError: astimezone() cannot be applied to a naive datetime

Second time:
--------------
2019-04-20 07:15:28 ERROR    SEARCHQUEUE-BACKLOG-148581 :: [ThePirateBay] :: [54da0c7] BraceMessage string formatting failed. Using representation instead.
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\logger\adapters\style.py", line 53, in __str__
    return self.msg.format(*args)
KeyError: "'provider'"
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\logger\adapters\style.py", line 60, in __str__
    raise BraceException(self.msg)
BraceException: Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\search\queue.py", line 547, in run
    search_result = search_providers(self.show, self.segment)
  File "D:\Program Files\Medusa\Medusa\medusa\search\core.py", line 939, in search_providers
    cache_search_results = cur_provider.search_results_in_cache(episodes)
  File "D:\Program Files\Medusa\Medusa\medusa\providers\generic_provider.py", line 250, in search_results_in_cache
    return self.cache.find_episodes(episodes)
  File "D:\Program Files\Medusa\Medusa\medusa\tv\cache.py", line 638, in find_episodes
    self.searched = time()
  File "D:\Program Files\Medusa\Medusa\medusa\tv\cache.py", line 336, in searched
    self._set_time('lastSearch', value)
  File "D:\Program Files\Medusa\Medusa\medusa\tv\cache.py", line 363, in _set_time
    {'provider': self.provider_id}
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 355, in upsert
    self.action(query, list(itervalues(valueDict)) + list(itervalues(keyDict)))
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 286, in action
    self.connection.commit()
OperationalError: disk I/O error

2019-04-20 07:15:28 ERROR    SEARCHQUEUE-BACKLOG-148581 :: [ThePirateBay] :: [54da0c7] DB error: Error: 'disk I/O error'
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\db.py", line 286, in action
OperationalError: disk I/O error
2019-04-19 21:03:08 ERROR    FINDPROPERS :: [54da0c7] Exception generated: 'TorrentSearchResult' object does not support indexing
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\scheduler.py", line 93, in run
    self.action.run(self.force)
  File "D:\Program Files\Medusa\Medusa\medusa\search\proper.py", line 66, in run
    propers = self._get_proper_results()
  File "D:\Program Files\Medusa\Medusa\medusa\search\proper.py", line 211, in _get_proper_results
    wanted_results = filter_results(cur_proper)
  File "D:\Program Files\Medusa\Medusa\medusa\search\core.py", line 384, in filter_results
    ignored_words = results[0].series.show_words().ignored_words
TypeError: 'TorrentSearchResult' object does not support indexing

medariox commented 5 years ago

You are interrupting the program while it is running, while searched are bring made and sql queries executed. What did you expect?

rafi-d commented 5 years ago

When you are doing a shutdown - there is no way to know at what stage you are in in ANY app... Statistically it is a low chance, but possible. Maybe medusa is also being signaled by Windows shutdown somehow like it is done during a real shutdown? One thing is sure - when you wake up - 7 hours have passed, so I guess lots of search tasks might be starting up immediately.

I did not test with "Sleep", just with Hibernate. Maybe a read/write re-try after 1-2 seconds if you detect it is after hibernation/sleep can be of help?

rafi-d commented 5 years ago

Adding one more error log , after waking from Sleep (seems related to communication with github). Not sure if it is related to wakup of my LAN, but I doubt if github com com should be categorized as "Error". ->

2019-04-24 07:59:15 ERROR CHECKVERSION :: [54da0c7] Environment error: HTTPSConnectionPool(host='api.github.com', port=443): Max retries exceeded with url: /orgs/pymedusa (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x08C8EBD0>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed',)) Traceback (most recent call last): File "D:\Program Files\Medusa\Medusa\medusa\scheduler.py", line 93, in run self.action.run(self.force) File "D:\Program Files\Medusa\Medusa\medusa\version_checker.py", line 69, in run self.list_remote_branches() File "D:\Program Files\Medusa\Medusa\medusa\version_checker.py", line 359, in list_remote_branches app.GIT_REMOTE_BRANCHES = self.updater.list_remote_branches() File "D:\Program Files\Medusa\Medusa\medusa\version_checker.py", line 1044, in list_remote_branches gh = get_github_repo(app.GIT_ORG, app.GIT_REPO) File "D:\Program Files\Medusa\Medusa\medusa\github_client.py", line 101, in get_github_repo return gh.get_organization(organization).get_repo(repo) File "D:\Program Files\Medusa\Medusa\ext2\github\MainClass.py", line 261, in get_organization "/orgs/" + login File "D:\Program Files\Medusa\Medusa\ext2\github\Requester.py", line 264, in requestJsonAndCheck return self.check(*self.requestJson(verb, url, parameters, headers, input, self.customConnection(url))) File "D:\Program Files\Medusa\Medusa\ext2\github\Requester.py", line 324, in requestJson return self.requestEncode(cnx, verb, url, parameters, headers, input, encode) File "D:\Program Files\Medusa\Medusa\ext2\github\Requester.py", line 377, in requestEncode status, responseHeaders, output = self.__requestRaw(cnx, verb, url, requestHeaders, encoded_input) File "D:\Program Files\Medusa\Medusa\ext2\github\Requester.py", line 401, in __requestRaw response = cnx.getresponse() File "D:\Program Files\Medusa\Medusa\ext2\github\Requester.py", line 109, in getresponse r = verb(url, headers=self.headers, data=self.input, timeout=self.timeout, verify=self.verify, allow_redirects=False) File "D:\Program Files\Medusa\Medusa\ext\requests\sessions.py", line 546, in get return self.request('GET', url, kwargs) File "D:\Program Files\Medusa\Medusa\ext\requests\sessions.py", line 533, in request resp = self.send(prep, send_kwargs) File "D:\Program Files\Medusa\Medusa\ext\requests\sessions.py", line 646, in send r = adapter.send(request, **kwargs) File "D:\Program Files\Medusa\Medusa\ext\requests\adapters.py", line 516, in send raise ConnectionError(e, request=request) ConnectionError: HTTPSConnectionPool(host='api.github.com', port=443): Max retries exceeded with url: /orgs/pymedusa (Caused by NewConnectionError('<urllib3.connection.VerifiedHTTPSConnection object at 0x08C8EBD0>: Failed to establish a new connection: [Errno 11001] getaddrinfo failed',))

p0psicles commented 5 years ago

We could throw in some error handling for the timeout

rafi-d commented 5 years ago

You think this will resolve both the com and HD related issues?

p0psicles commented 5 years ago

The network error, you will always have. Your aborting open connections. The HD should not error unless it's network mounted

rafi-d commented 5 years ago

Using an internal SATA drive here for medusa (but not C/system drive). Maybe network timeout error can be categorized as a "Warning" ?