Does "not enough repair blocks" trigger postproc?

[slvrdragn]

master branch, python 3.8, opensuse tumbleweed x64


Noticing in my logs that when there aren't enough repair blocks, it says "PostProcessing was aborted (see logfile)" and there is no indication that it ran the postproc script nzbToMedia at all. I do have the setting to postproc all jobs to get SickChill to process the next release.
Any thoughts on this? Bug or intended or am I just missing something?

Seems these 2 lines are what I expect, clearly it can't unpack but the script isn't called. (separate job, just to show what i was expecting)
Unpack[NCIS.S09E24.DVDRip.REPACK.XviD] Unusable RAR file
ScriptSickBeard: Successfully post-processed NCIS.S09E24.DVDRip.REPACK.XviD! (More)


meInvasion.S01E03.720p.HDTV
Completed43 minutes ago
StatusFailed
Size3.7 MB
Categorytv
Path/home/@send/TV/Invasion/Invasion.S01E03.720p.HDTV
Sourcehttps://api.nzbgeek.info/api?t=get&id=ba787db1852d966cc809aafe6d50999f&apikey=f04334346488c4a863dedb9fdc52b58d
DownloadDownloaded in 4 seconds at an average of 797 KB/s
Age: 2396d
ServersfrugalSSL=12 KB, usenetserverSSL=3.7 MB
Repair[Invasion.S01E03.720p.HDTV.AC3.5.1.XviD-BamHD] Verified in 2 seconds, repair is required
[Invasion.S01E03.720p.HDTV.AC3.5.1.XviD-BamHD] Repair failed, not enough repair blocks (2985 short)

[safihre]

In your case there was a crash in SABnzbd.
Can you enable +Debug logging?
Just below the "PostProcessing was aborted" it will actually show a log of what crashed.
Could you share that?

[slvrdragn]

OK, Ill enable debug and what for another instance. Thanks.

[slvrdragn]

Hmm apparently setting to debug didn't take. Trying again.

[slvrdragn]

So I haven't managed to catch one of those jobs but skimming through the logs after notice what seemed to be a lot of restarts, I found that around the time of directunpack actions, it restarts. I was wondering why it kept reloading so often. Nothing really useful to my eyes in the log. it just stops cold. I've notice it reloading the nzbqueue a few times lately but didn't really clue in that it was a hard shutdown.
Any thoughts on what I can check / try here?

Code: Select all

 
2021-02-01 09:59:58,842::INFO::[assembler:114] Decoding finished /home/@downloads/Star.Wars.Resistance.S01E10.720p.HDTV.x264-W4F-Obfuscated.1/73e3f236a0b441d7a9787c8e6838378a.part04.rar
2021-02-01 09:59:58,856::DEBUG::[nzbstuff:451] Removing article database for SABnzbd_nzf_fb713wom
2021-02-01 09:59:58,857::DEBUG::[filesystem:804] [sabnzbd.nzbstuff.remove_admin] Deleting file /home/@downloads/Star.Wars.Resistance.S01E10.720p.HDTV.x264-W4F-Obfuscated.1/__ADMIN__/SABnzbd_nzf_fb713wom
2021-02-01 09:59:58,957::DEBUG::[assembler:356] File contains: 73e3f236a0b441d7a9787c8e6838378a.mkv
2021-02-01 09:59:58,959::DEBUG::[directunpacker:143] DirectUnpack queued 73e3f236a0b441d7a9787c8e6838378a.part04.rar for 73e3f236a0b441d7a9787c8e6838378a
2021-02-01 09:59:59,069::INFO::[directunpacker:293] DirectUnpacked volume 4 for 73e3f236a0b441d7a9787c8e6838378a
2021-02-01 10:00:00,183::DEBUG::[api:118] API-call from 127.0.0.1 [okhttp/3.14.6] {'apikey': 'key', 'output': 'json', 'mode': 'queue'}
2021-02-01 10:00:30,496::INFO::[SABnzbd:1148] --------------------------------
2021-02-01 10:01:03,448::INFO::[SABnzbd:1149] SABnzbd.py-3.1.1 (rev=99b5a00c12c1d8e17bb3e4a9a98339f59152c842)
2021-02-01 10:01:03,448::INFO::[SABnzbd:1150] Full executable path = /opt/sabnzbd/SABnzbd.py
2021-02-01 10:01:03,449::INFO::[SABnzbd:1160] Platform = posix
2021-02-01 10:01:03,449::INFO::[SABnzbd:1161] Python-version = 3.8.7 (default, Dec 22 2020, 08:33:13) [GCC]
2021-02-01 10:01:03,449::INFO::[SABnzbd:1162] Arguments = "/opt/sabnzbd/SABnzbd.py" "-f" "/opt/.sabnzbd/sabnzbd.ini"

[slvrdragn]

So I don't know if related but the okhttp call seems to happen around the time of. I believe this is nzbhydra and I'm going to disable it.

Code: Select all

 
2021-02-01 13:40:59,459::DEBUG::[__init__:990] [sabnzbd.postproc.save] Saving data for postproc2.sab
2021-02-01 13:40:59,461::DEBUG::[__init__:922] [sabnzbd.save_admin] Saving data for postproc2.sab in /opt/.sabnzbd/admin
2021-02-01 13:40:59,520::INFO::[downloader:500] Job Hunters.2020.S01E03.WEB.H264-GHOSTS too old for free.xsusenet.com, moving on
2021-02-01 13:40:59,521::INFO::[nzbstuff:249] <Article: article=lnFkp5N14DLAlLOJJ0q-zZkwBaBtA@N7axYcdtU.DjV, bytes=23656, art_id=None> => missing from all servers, discarding
2021-02-01 13:40:59,523::INFO::[nzbstuff:1710] Checking all filenames for Hunters.2020.S01E03.WEB.H264-GHOSTS
2021-02-01 13:40:59,524::INFO::[nzbstuff:1713] Re-sorting Hunters.2020.S01E03.WEB.H264-GHOSTS after getting filename information
2021-02-01 13:40:59,525::DEBUG::[nzbstuff:949] Unwanted Extension: putting last rar after first rar
2021-02-01 13:40:59,526::DEBUG::[nzbstuff:962] Unwanted Extension: First rar at 1, Last rar at 35
2021-02-01 13:40:59,526::DEBUG::[nzbstuff:963] Unwanted Extension: Last rar is 6f775c3ab58a41bebe1bd67ca1a0eed4.part36.rar
2021-02-01 13:40:59,527::DEBUG::[nzbstuff:1893] Saving attributes {'cat': 'tv', 'pp': 3, 'script': 'postproc.sh', 'priority': 2, 'final_name': 'Hunters.2020.S01E03.WEB.H264-GHOSTS', 'password': None, 'url': 'https://api.nzbgeek.info/api?t=get&id=315be907f9ba35f1fc11358f23164c3f&apikey='} for Hunters.2020.S01E03.WEB.H264-GHOSTS
2021-02-01 13:40:59,917::DEBUG::[__init__:922] [sabnzbd.nzbstuff.save_to_disk] Saving data for SABnzbd_nzo_zpcfqr38 in /home/@downloads/Hunters.2020.S01E03.WEB.H264-GHOSTS/__ADMIN__
2021-02-01 13:41:00,472::DEBUG::[api:118] API-call from 127.0.0.1 [okhttp/3.14.6] {'apikey': 'api', 'output': 'json', 'mode': 'queue'}
2021-02-01 13:42:25,959::INFO::[SABnzbd:1148] --------------------------------
2021-02-01 13:42:25,991::INFO::[SABnzbd:1149] SABnzbd.py-3.1.1 (rev=99b5a00c12c1d8e17bb3e4a9a98339f59152c842)
2021-02-01 13:42:25,991::INFO::[SABnzbd:1150] Full executable path = /opt/sabnzbd/SABnzbd.py
2021-02-01 13:42:25,991::INFO::[SABnzbd:1160] Platform = posix
2021-02-01 13:42:25,992::INFO::[SABnzbd:1161] Python-version = 3.8.7 (default, Dec 22 2020, 08:33:13) [GCC]
2021-02-01 13:42:25,992::INFO::[SABnzbd:1162] Arguments = "/opt/sabnzbd/SABnzbd.py" "-f" "/opt/.sabnzbd/sabnzbd.ini"
2021-02-01 13:42:25,992::INFO::[SABnzbd:1166] Not inside a docker container
2021-02-01 13:42:25,992::INFO::[SABnzbd:1169] Preferred encoding = UTF-8
2021-02-01

[safihre]

No sign of why it was killed, maybe a bit higher up in the logs.
Seems an external trigger restarted or killed it.
Maybe try to disable Direct Unpack?
It can sometimes bw too much for some system.

[slvrdragn]

Directunpack is disabled for now, so far, seems more stable. That might be subjective.
I saved the logs, let me recheck and see. I don't have anything in crontab or scripts that should be restarting or killing it.

[slvrdragn]

No Api calls except queue checks from what I believe was nzbhydra (okhttp) and Couchpotato checking history.
No other error type messages that i can see. unrars and unpacks progressed normally.

[sander]

And Traceback in your sabnzbd.log ?

[slvrdragn]

I'm not seeing a traceback in it. It just stops.

[safihre]

Can you run it from the command line?
Then it should definitely show the Traceback.