Edit show stops/hangs with "error 500"

[rafi-d]

V 0.24, unclear what triggers this. Usually re-starting helps to recover. Screenshot: http://www.imagebam.com/image/866b7f872960494 Edit: Test clip (replaced): https://drive.google.com/file/d/1cLlRIYILPpmhGKm-skV-qrpzLp-RYCO1/view?usp=sharing

Seems to also be confirmed inn Slack..

[rafi-d]

Error logs:

2018-05-24 09:30:30 ERROR    SEARCHQUEUE-DAILY-SEARCH :: [Zooqle] :: [212cd1c] BraceMessage string formatting failed. Using representation instead.
u'  File "D:\\Program Files\\Medusa\\Python\\lib\\threading.py", line 774, in __bootstrap\n    self.__bootstrap_inner()\n  File "D:\\Program Files\\Medusa\\Python\\lib\\threading.py", line 801, in __bootstrap_inner\n    self.run()\n  File "D:\\Program Files\\Medusa\\Medusa\\medusa\\search\\queue.py", line 296, in run\n    log.exception(\'DailySearchQueueItem Exception, error: {error}\', {\'error\': error})\n  File "D:\\Program Files\\Medusa\\Medusa\\medusa\\logger\\adapters\\style.py", line 101, in exception\n    self.log(logging.ERROR, msg, *args, **kwargs)\n  File "D:\\Program Files\\Medusa\\Medusa\\medusa\\logger\\adapters\\style.py", line 96, in log\n    self.logger.log(level, msg, **kwargs)\n  File "D:\\Program Files\\Medusa\\Python\\lib\\logging\\__init__.py", line 1489, in log\n    self.logger.log(level, msg, *args, **kwargs)\n  File "D:\\Program Files\\Medusa\\Python\\lib\\logging\\__init__.py", line 1231, in log\n    self._log(level, msg, args, **kwargs)\n  File "D:\\Program Files\\Medusa\\Python\\lib\\logging\\__init__.py", line 1286, in _log\n    self.handle(record)\n  File "D:\\Program Files\\Medusa\\Python\\lib\\logging\\__init__.py", line 1296, in handle\n    self.callHandlers(record)\n  File "D:\\Program Files\\Medusa\\Python\\lib\\logging\\__init__.py", line 1336, in callHandlers\n    hdlr.handle(record)\n  File "D:\\Program Files\\Medusa\\Python\\lib\\logging\\__init__.py", line 759, in handle\n    self.emit(record)\n  File "D:\\Program Files\\Medusa\\Python\\lib\\logging\\handlers.py", line 78, in emit\n    logging.FileHandler.emit(self, record)\n  File "D:\\Program Files\\Medusa\\Python\\lib\\logging\\__init__.py", line 957, in emit\n    StreamHandler.emit(self, record)\n  File "D:\\Program Files\\Medusa\\Python\\lib\\logging\\__init__.py", line 861, in emit\n    msg = self.format(record)\n  File "D:\\Program Files\\Medusa\\Python\\lib\\logging\\__init__.py", line 734, in format\n    return fmt.format(record)\n  File "D:\\Program Files\\Medusa\\Medusa\\medusa\\logger\\__init__.py", line 549, in format\n    msg = super(CensoredFormatter, self).format(record)\n  File "D:\\Program Files\\Medusa\\Python\\lib\\logging\\__init__.py", line 465, in format\n    record.message = record.getMessage()\n  File "D:\\Program Files\\Medusa\\Python\\lib\\logging\\__init__.py", line 325, in getMessage\n    msg = str(self.msg)\n  File "D:\\Program Files\\Medusa\\Medusa\\medusa\\init\\logconfig.py", line 84, in __str__\n    result = text_type(self.fmt)\n  File "D:\\Program Files\\Medusa\\Medusa\\ext\\future\\types\\newobject.py", line 78, in __unicode__\n    s = type(self).__str__(self)\n  File "D:\\Program Files\\Medusa\\Medusa\\medusa\\logger\\adapters\\style.py", line 55, in __str__\n    \'\'.join(traceback.format_stack()),\n'
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\logger\adapters\style.py", line 40, in __str__
    return self.msg.format(*args, **kwargs)
  File "D:\Program Files\Medusa\Python\lib\encodings\cp1255.py", line 15, in decode
    return codecs.charmap_decode(input,errors,decoding_table)
UnicodeDecodeError: 'charmap' codec can't decode byte 0x9a in position 194: character maps to <undefined>
2018-05-24 09:30:30 ERROR    SEARCHQUEUE-DAILY-SEARCH :: [Zooqle] :: [212cd1c] BraceMessage(u'DailySearchQueueItem Exception, error: {error}', {u'error': GuessitException('An internal error has occured in guessit.\n===================== Guessit Exception Report =====================\nversion=2.1.4\nstring=\xd0\x91\xd0\xb0\xd1\x80\xd1\x80\xd0\xb8./.Barry.[S01].(2018).WEB-DLRip.\xd0\xbe\xd1\x82.Generalfilm.|.\xd0\x9a\xd0\x9f\xd0\x9a.|.Amedia\noptions={\'allowed_languages\': [\'de\', \'en\', \'es\', \'ca\', \'fr\', \'he\', \'hu\', \'it\', \'jp\', \'nl\', \'pl\', \'pt\', \'ro\', \'ru\', \'sv\', \'uk\', \'mul\', \'und\'], \'expected_group\': [\'TV2LAX9\', \'DHD\', \'20-40\'], \'expected_title\': [\'The 100\'], \'allowed_countries\': [\'us\', \'gb\'], \'episode_prefer_number\': False, \'show_type\': None, \'type\': \'episode\', \'implicit\': True}\n--------------------------------------------------------------------\nTraceback (most recent call last):\n  File "D:\\Program Files\\Medusa\\Medusa\\ext\\guessit\\api.py", line 120, in guessit\n    matches = self.rebulk.matches(string, options)\n  File "D:\\Program Files\\Medusa\\Medusa\\ext\\rebulk\\rebulk.py", line 288, in matches\n    self._execute_rules(matches, context)\n  File "D:\\Program Files\\Medusa\\Medusa\\ext\\rebulk\\rebulk.py", line 319, in _execute_rules\n    rules.execute_all_rules(matches, context)\n  File "D:\\Program Files\\Medusa\\Medusa\\ext\\rebulk\\rules.py", line 318, in execute_all_rules\n    when_response = execute_rule(rule, matches, context)\n  File "D:\\Program Files\\Medusa\\Medusa\\ext\\rebulk\\rules.py", line 339, in execute_rule\n    when_response = rule.when(matches, context)\n  File "D:\\Program Files\\Medusa\\Medusa\\medusa\\name_parser\\rules\\rules.py", line 1328, in when\n    value = value.split(\'-\')[0]\n  File "D:\\Program Files\\Medusa\\Python\\lib\\encodings\\cp1255.py", line 15, in decode\n    return codecs.charmap_decode(input,errors,decoding_table)\nUnicodeDecodeError: \'charmap\' codec can\'t decode byte 0x9a in position 15: character maps to <undefined>\n--------------------------------------------------------------------\nPlease report at https://github.com/guessit-io/guessit/issues.\n====================================================================',)}, exc_info=1, extra=None)
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\medusa\search\queue.py", line 263, in run
    found_results = search_for_needed_episodes(force=self.force)
  File "D:\Program Files\Medusa\Medusa\medusa\search\core.py", line 676, in search_for_needed_episodes
    cur_provider.cache.update_cache()
  File "D:\Program Files\Medusa\Medusa\medusa\tv\cache.py", line 229, in update_cache
    result = self._parse_item(item)
  File "D:\Program Files\Medusa\Medusa\medusa\tv\cache.py", line 308, in _parse_item
    leechers, size, pubdate)
  File "D:\Program Files\Medusa\Medusa\medusa\tv\cache.py", line 377, in add_cache_entry
    parse_result = parsed_result or NameParser().parse(name)
  File "D:\Program Files\Medusa\Medusa\medusa\name_parser\parser.py", line 366, in parse
    result = self._parse_string(name)
  File "D:\Program Files\Medusa\Medusa\medusa\name_parser\parser.py", line 274, in _parse_string
    guess = guessit.guessit(name, dict(show_type=self.show_type))
  File "D:\Program Files\Medusa\Medusa\medusa\name_parser\guessit_parser.py", line 77, in guessit
    result = default_api.guessit(name, options=final_options)
  File "D:\Program Files\Medusa\Medusa\ext\guessit\api.py", line 132, in guessit
    raise GuessitException(string, options)
GuessitException: An internal error has occured in guessit.
===================== Guessit Exception Report =====================
version=2.1.4
string=׀‘׀°ׁ€ׁ€׀¸./.Barry.[S01].(2018).WEB-DLRip.׀¾ׁ‚.Generalfilm.|.׀š׀Ÿ׀š.|.Amedia
options={'allowed_languages': ['de', 'en', 'es', 'ca', 'fr', 'he', 'hu', 'it', 'jp', 'nl', 'pl', 'pt', 'ro', 'ru', 'sv', 'uk', 'mul', 'und'], 'expected_group': ['TV2LAX9', 'DHD', '20-40'], 'expected_title': ['The 100'], 'allowed_countries': ['us', 'gb'], 'episode_prefer_number': False, 'show_type': None, 'type': 'episode', 'implicit': True}
--------------------------------------------------------------------
Traceback (most recent call last):
  File "D:\Program Files\Medusa\Medusa\ext\guessit\api.py", line 120, in guessit
    matches = self.rebulk.matches(string, options)
  File "D:\Program Files\Medusa\Medusa\ext\rebulk\rebulk.py", line 288, in matches
    self._execute_rules(matches, context)
  File "D:\Program Files\Medusa\Medusa\ext\rebulk\rebulk.py", line 319, in _execute_rules
    rules.execute_all_rules(matches, context)
  File "D:\Program Files\Medusa\Medusa\ext\rebulk\rules.py", line 318, in execute_all_rules
    when_response = execute_rule(rule, matches, context)
  File "D:\Program Files\Medusa\Medusa\ext\rebulk\rules.py", line 339, in execute_rule
    when_response = rule.when(matches, context)
  File "D:\Program Files\Medusa\Medusa\medusa\name_parser\rules\rules.py", line 1328, in when
    value = value.split('-')[0]
  File "D:\Program Files\Medusa\Python\lib\encodings\cp1255.py", line 15, in decode
    return codecs.charmap_decode(input,errors,decoding_table)
UnicodeDecodeError: 'charmap' codec can't decode byte 0x9a in position 15: character maps to <undefined>
--------------------------------------------------------------------
Please report at https://github.com/guessit-io/guessit/issues.
====================================================================

2018-05-24 07:04:23 WARNING  SHOWQUEUE-REFRESH :: [212cd1c] 321239: Show directory doesn't exist, skipping NFO generation
2018-05-24 07:04:20 WARNING  SHOWQUEUE-REFRESH :: [212cd1c] 261690: Show directory doesn't exist, skipping NFO generation
2018-05-24 07:03:05 WARNING  SHOWQUEUE-SEASON-UPDATE :: [212cd1c] 321239: The Handmaid's Tale episode statuses unchanged. Location is missing: 
2018-05-24 07:02:25 WARNING  SHOWQUEUE-SEASON-UPDATE :: [212cd1c] 261690: The Americans (2013) episode statuses unchanged. Location is missing: 
2018-05-24 07:01:26 WARNING  SHOWUPDATER :: [212cd1c] could not connect to TheTvdb.com, with reason 'Error connecting to Tvdb api. Caused by: ReadTimeout
HTTPSConnectionPool(host='api.thetvdb.com', port=443): Read timed out. (read timeout=30)'
2018-05-24 07:01:26 WARNING  SHOWUPDATER :: [212cd1c] Enabling Plex fallback as TheTvdb.com API is having some connectivity issues

[p0psicles]

Dont think the error logs have anything to do with your issue. As these are originating from separated threads. Any other logs?

[rafi-d]

You are probably right, but this is what I had at the time. No, no other logs. I suggest for you to talk to sharkykh @Slack workspace (search history there for our discussion), seemed like he had noticed it too.

As for this log, it might be related to this discussion on IRC, so you might want to tak to medariox too :) :

16:57 Hey Everyone! really enjoying Medusa! I do have some questions about some warnings I am getting, and unable to find anything online. Wondering if someone here can help? 17:15 <•medusabot> Hey tlamp 17:16 <•medusabot> What warnings are you getting? 17:21 Show directory doesn't exist, not loading episodes from disk 17:21 Show directory doesn't exist, skipping NFO generation 17:21 My set up is mirrored to that i had on sickbeard / sickrage... 17:22 I do not keep the tv show folders on the server. I make it create new ones when they are downloaded 17:22 I do not use NFO files for 3rd party programs 17:23 <•medusabot> You don't have a place where the episodes are stored? 17:23 <•medusabot> Are you talking about season folders? 17:25 yes i do have a place the episodes are stored. I don't use season folders. I use Show folders 17:25 So NZB and Torrents are downloaded to "TV Shows" 17:25 post processing runs and copies" them to "Medusa" folder 17:26 Once in the medusa folder my server will pull them to a local hard drive and delete the folders / files 17:27 Again I have medusa recreate missing folders as needed 17:27 <•medusabot> Okay. If you go to a show. Where does the "location" point to 17:28 home - users - files - medusa - show name 17:30 And yes, this folder would get removed whenever I pull down the show 17:32 <•medusabot> When does the warning show? 17:32 <•medusabot> On post-processing or during backlog search or...? 17:32 SHOWQUEUE-REFRESH 17:40 What other info do you need? 17:45 <•medusabot> No more info needed, thanks 17:46 <•medusabot> Can you open an issue on github please? 17:46 <•medusabot> Just state what you wrote here 17:46 <•medusabot> We will fix it asap

[medariox]

It's not related in any way.

[rafi-d]

PS: Actually, I had the debug log enabled, so here is the log from boot time today. You are welcome to browse it. https://drive.google.com/file/d/1ME2F4fHJ8eSlFd36ZkM36GtpHNlzJspx/view?usp=sharing

And it says on IRC- 17:21 Show directory doesn't exist, not loading episodes from disk ... 17:32 SHOWQUEUE-REFRESH

So I though my logged errors (not the 500 error) was/is similar.

[sharkykh]

For the record this is the error I posted on Slack. Hasn't happened to me since but I restart Medusa a lot. I still don't know what caused it or how to reproduce it.

I should also add that none of the paths or filenames contain non-ASCII chars.

Yeah I got that error yesterday I think. I don't know what causes it. Something in the data was corrupted. A restart fixed it for me. Edit: This was the error. Show: The Crossing, Language: English

2018-05-20 20:18:59 ERROR    TORNADO :: [a4f24ff] Uncaught exception GET /api/v2/series/tvdb328631 (x.x.x.x)
HTTPServerRequest(protocol='https', host='localhost:8081', method='GET', uri='/api/v2/series/tvdb328631', version='HTTP/1.1', remote_ip='x.x.x.x')
Traceback (most recent call last):
File "C:\Medusa\ext\tornado\web.py", line 1541, in _execute
result = method(*self.path_args, **self.path_kwargs)
File "C:\Medusa\medusa\server\api\v2\series.py", line 69, in get
return self._ok(data)
File "C:\Medusa\medusa\server\api\v2\base.py", line 165, in _ok
self.api_finish(200, data=data, headers=headers, stream=stream, content_type=content_type)
File "C:\Medusa\medusa\server\api\v2\base.py", line 114, in api_finish
self.finish(json.JSONEncoder(default=json_default_encoder).encode(data))
File "C:\Python27\lib\json\encoder.py", line 207, in encode
chunks = self.iterencode(o, _one_shot=True)
File "C:\Python27\lib\json\encoder.py", line 270, in iterencode
return _iterencode(o, 0)
UnicodeDecodeError: 'utf8' codec can't decode byte 0x96 in position 162: invalid start byte

[OmgImAlexis]

@sharkykh related? https://github.com/llSourcell/tensorflow_chatbot/issues/17

[rafi-d]

Sorry, I've posted a wrong link to the test-clip... https://drive.google.com/file/d/1cLlRIYILPpmhGKm-skV-qrpzLp-RYCO1/view?usp=sharing

Please note, that there is another issue, where all shows-edit are opened in custom mode first, even if there is no custom setting. This closes after a second. Most annoying!

[rafi-d]

This 500 error happened again today, so I managed to snapshot this in case it can help: https://drive.google.com/file/d/1z_I1I05Hk4roj8J6sYTu5ObBca8Bz85-/view?usp=sharing

[sharkykh]

@rafi-d

This 500 error happened again today, so I managed to snapshot this in case it can help: drive.google.com/file/d/1z_I1I05Hk4roj8J6sYTu5ObBca8Bz85-/view?usp=sharing

You're looking in the wrong place. The issue isn't with Javascript, it's the server (Python) that has an error. If you check the logs you can see the error, just like I posted above.

Please note, that there is another issue, where all shows-edit are opened in custom mode first, even if there is no custom setting. This closes after a second. Most annoying!

It happens like that because it only gets the quality information after the page loads. It will probably be fixed in the future.

---

@OmgImAlexis I'm not sure if it's related. I have to find out how to reproduce the issue and then try to debug it without restarting Medusa.

[rafi-d]

I see.

It happens like that because it only gets the quality information after the page loads. It will probably be >fixed in the future.

Good. I don't see why the "default" for a show page load cannot be set to w/o custom display, then open it when needed... Since custom settings are not much in use, this can we more user-friendly most of the times :)

[rafi-d]

@rafi-d Do you happen to have any shows set in language that is not English?

No. Anything in Hebrew in your list, @sharkykh ? I believe you can see the shows' list in my clip. Anyway, this was with "The Americans (2013)" and "The 100" as far as I recall. Since I do not recall seeing these two issues in the previous 0.22 version, most likely has to somehow do with your changes (Vue?).

[sharkykh]

@rafi-d Yeah, never mind that. I was wrong. I was just able to get some more info about this error, so I can do some more debugging.

[sharkykh]

The decode errors are in the episode descriptions. I was able to get that using this commit. This is the real error:

2018-05-26 19:33:44 ERROR    TORNADO :: [a4f24ff] 500 GET /api/v2/series/tvdb328631/episode/s1e2/description (192.168.44.200) 51.00ms
2018-05-26 19:33:44 ERROR    TORNADO :: [a4f24ff] UnicodeDecodeError caught while encoding data to JSON format. Error: 'utf8' codec can't decode byte 0x96 in position 162: invalid start byte.
Failed: 'In a flash-forward to the year 2187, Reece finds Leah, an orphaned Common baby, and goes against her Apex cohorts to take her in as her own. In present day, Jude \x96 hoping for a peaceful solution with the Feds \x96 is blindsided by a mysterious black-ops team\x92s intent on capturing Reece by any means necessary.'

Our data: In a flash-forward to the year 2187, Reece finds Leah, an orphaned Common baby, and goes against her Apex cohorts to take her in as her own. In present day, Jude \x96 hoping for a peaceful solution with the Feds \x96 is blindsided by a mysterious black-ops team\x92s intent on capturing Reece by any means necessary.

On TheTVDB.com: In a flash-forward to the year 2187, Reece finds Leah, an orphaned Common baby, and goes against her Apex cohorts to take her in as her own. In present day, Jude – hoping for a peaceful solution with the Feds – is blindsided by a mysterious black-ops team’s intent on capturing Reece by any means necessary.

From TVDB API v2 (https://api.thetvdb.com/series/328631/episodes/query?airedSeason=1&airedEpisode=2):

{
  "links": {
    "first": 1,
    "last": 1,
    "next": null,
    "prev": null
  },
  "data": [
    {
      "absoluteNumber": 2,
      "airedEpisodeNumber": 2,
      "airedSeason": 1,
      "airedSeasonID": 745823,
      "dvdEpisodeNumber": 2,
      "dvdSeason": 1,
      "episodeName": "A Shadow Out of Time",
      "firstAired": "2018-04-09",
      "id": 6533132,
      "language": {
        "episodeName": "en",
        "overview": "en"
      },
      "lastUpdated": 1526938777,
      "overview": "In a flash-forward to the year 2187, Reece finds Leah, an orphaned Common baby, and goes against her Apex cohorts to take her in as her own. In present day, Jude – hoping for a peaceful solution with the Feds – is blindsided by a mysterious black-ops team’s intent on capturing Reece by any means necessary."
    }
  ]
}

@p0psicles @medariox I restarted Medusa yesterday, and according to my logs, at 8am today Medusa ran the SHOWUPDATER for The Crossing season 1. It completed it and saved it to the database. Now the error is back.

Since we know a restart temporarily fixes the issue, and when starting Medusa the show info is loaded from the database, my guess is that the value we set to the database is correct, but the value that stays in Python isn't.

I have to do more debugging, but I hope the error is actually there. I haven't started looking at the database save/load codes, but if you have any ideas please share.

[rafi-d]

Sounds like good catch/progress!

[rafi-d]

What is the ETA for the next release (also with this fixed)?

[sharkykh]

Currently planned for next weekend. v0.2.5

[rafi-d]

Seems like one after the next, June 8 ... Will in include also - #4056 you've merged?

[sharkykh]

Everything that is in develop will be in master. So yes.