Sabndzb crashes

[Notknown]

since 3.6.0/1 my sabnzdb crashed alot if i give an order via sonarr/radarr to download stuff. New (old) series with a lot of seasons/episodes for example.

Gui error is:
restarting because of crashed downloader

after some while also an popup error on the machine it self:
There was image link here that i may not use yet

Sabnzdb doenst restart then and is not available trough the browser.

Virtual Machine is a:
Server 2022
4 cores/ 6Ram (3 available)
23GB free disk space
1TB of free space on my file server (trough share/unc path)
So there is enough space. Speed is also available without issues.

I turned on debug logging, but it that stopped after a while when the file hits 5MB...
But debug are not complety helping atm:

Can post the log because the forums thinks there are links in it....


I hope someone has an idea what is happening. Never had this strange stuff going on.

[safihre]

Can you run SABnzbd-console.exe instead of Sabnzbd.exe? First shutdown SABnzbd.
It will probably show a crash that is not logged, a Traceback.

[Notknown]

I will try this.

[Notknown]

Did run it console, and no real difference of the error.
See log in next post

[Notknown]

From Console log:

Code: Select all

2022-08-26 08:13:28,052::INFO::[notifier:123] Sending notification: Warning - Restarting because of crashed downloader (type=warning, job_cat=None)
2022-08-26 08:13:28,052::WARNING::[__init__:482] Restarting because of crashed downloader
2022-08-26 08:13:28,058::INFO::[SABnzbd:1579] Performing triggered restart
2022-08-26 08:13:28,058::INFO::[__init__:441] [SABnzbd.py.main] Performing SABnzbd shutdown
2022-08-26 08:13:28,058::INFO::[__init__:353] SABnzbd shutting down...
2022-08-26 08:13:28,211::INFO::[ssdp:102] Stopping SSDP
2022-08-26 08:13:28,214::INFO::[directunpacker:542] Aborting all DirectUnpackers
2022-08-26 08:13:28,246::DEBUG::[__init__:371] Stopping RSSReader
2022-08-26 08:13:28,291::DEBUG::[nzbstuff:1897] Saving attributes {'cat': 'tv', 'pp': 3, 'script': 'None', 'priority': 0, 'final_name': 'Two And A Half Men S04E02 720p AMZN WEB-DL DDP2 0 H 264-PlayWEB', 'password': None, 'url': None} for Two And A Half Men S04E02 720p AMZN WEB-DL DDP2 0 H 264-PlayWEB
2022-08-26 08:13:28,291::DEBUG::[__init__:374] Stopping URLGrabber
2022-08-26 08:13:28,323::DEBUG::[__init__:381] Stopping dirscanner
2022-08-26 08:13:28,323::DEBUG::[__init__:388] Stopping downloader
2022-08-26 08:13:28,340::INFO::[notifier:123] Sending notification: SABnzbd - Shutting down (type=startup, job_cat=None)
2022-08-26 08:13:28,371::DEBUG::[__init__:396] Stopping decoders
2022-08-26 08:13:28,371::DEBUG::[decoder:131] Shutting down decoder Thread-3
2022-08-26 08:13:28,371::DEBUG::[decoder:131] Shutting down decoder Thread-2
2022-08-26 08:13:28,406::DEBUG::[__init__:400] Stopping assembler
2022-08-26 08:13:28,406::DEBUG::[assembler:72] Shutting down assembler
2022-08-26 08:13:28,406::DEBUG::[__init__:407] Stopping postprocessor
2022-08-26 08:13:28,496::INFO::[postproc:370] Starting Post-Processing on Two And A Half Men S04E02 720p AMZN WEB-DL DDP2 0 H 264-PlayWEB => Repair:True, Unpack:True, Delete:True, Script:None, Cat:tv
2022-08-26 08:13:28,496::INFO::[notifier:123] Sending notification: Post-processing - Two And A Half Men S04E02 720p AMZN WEB-DL DDP2 0 H 264-PlayWEB (type=pp, job_cat=tv)
2022-08-26 08:13:28,496::INFO::[postproc:727] Starting verification and repair of Two And A Half Men S04E02 720p AMZN WEB-DL DDP2 0 H 264-PlayWEB
2022-08-26 08:13:28,505::INFO::[filesystem:1139] [sabnzbd\postproc.py.parring] \\?\U:\incomplete\Two.And.A.Half.Men.S04E02.720p.AMZN.WEB-DL.DDP2.0.H.264-PlayWEB\__ADMIN__\__verified__ missing
2022-08-26 08:13:28,505::DEBUG::[postproc:733] Verified sets: {}

Normal log (yesterday):

Code: Select all

2022-08-25 18:51:39,856::INFO::[notifier:123] Sending notification: Warning - Restarting because of crashed decoder (type=warning, job_cat=None)
2022-08-25 18:51:39,856::WARNING::[__init__:485] Restarting because of crashed decoder
2022-08-25 18:51:39,857::INFO::[SABnzbd:1579] Performing triggered restart
2022-08-25 18:51:39,858::INFO::[__init__:441] [SABnzbd.py.main] Performing SABnzbd shutdown
2022-08-25 18:51:39,859::INFO::[__init__:353] SABnzbd shutting down...
2022-08-25 18:51:40,011::INFO::[ssdp:102] Stopping SSDP
2022-08-25 18:51:40,011::INFO::[directunpacker:542] Aborting all DirectUnpackers
2022-08-25 18:51:40,012::DEBUG::[__init__:371] Stopping RSSReader
2022-08-25 18:51:40,012::DEBUG::[__init__:374] Stopping URLGrabber
2022-08-25 18:51:40,013::DEBUG::[__init__:381] Stopping dirscanner
2022-08-25 18:51:40,013::DEBUG::[__init__:388] Stopping downloader
2022-08-25 18:51:40,014::INFO::[notifier:123] Sending notification: SABnzbd - Shutting down (type=startup, job_cat=None)

A LOT of disconnects from the provider

2022-08-25 18:51:41,471::INFO::[downloader:705] Shutting down
2022-08-25 18:51:41,471::DEBUG::[__init__:396] Stopping decoders
2022-08-25 18:51:41,471::DEBUG::[__init__:400] Stopping assembler
2022-08-25 18:51:41,471::DEBUG::[assembler:72] Shutting down assembler
2022-08-25 18:51:41,471::DEBUG::[__init__:407] Stopping postprocessor
2022-08-25 18:51:41,471::DEBUG::[articlecache:138] Saving 1 cached articles to disk

saving atttributres entrys

2022-08-25 18:51:47,702::DEBUG::[__init__:424] Terminating scheduler
2022-08-25 18:51:47,702::INFO::[__init__:427] All processes stopped
2022-08-25 18:51:47,702::INFO::[_cplogging:213] [25/Aug/2022:18:51:47] ENGINE Bus STOPPING
2022-08-25 18:51:47,857::INFO::[_cplogging:213] [25/Aug/2022:18:51:47] ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('192.168.2.207', 8080)) shut down
2022-08-25 18:51:47,857::INFO::[_cplogging:213] [25/Aug/2022:18:51:47] ENGINE Bus STOPPED
2022-08-25 18:51:47,857::INFO::[_cplogging:213] [25/Aug/2022:18:51:47] ENGINE Bus EXITING
2022-08-25 18:51:47,857::INFO::[_cplogging:213] [25/Aug/2022:18:51:47] ENGINE Bus EXITED
2022-08-25 18:51:49,613::INFO::[SABnzbd:1167] --------------------------------
2022-08-25 18:51:49,613::INFO::[SABnzbd:1168] SABnzbd.exe-3.6.1
2022-08-25 18:51:49,614::INFO::[SABnzbd:1178] Commit = <HASH>8db2eeb27ddd4c5
2022-08-25 18:51:49,614::INFO::[SABnzbd:1180] Full executable path = C:\Program Files\SABnzbd\SABnzbd.exe
2022-08-25 18:51:49,614::INFO::[SABnzbd:1181] Arguments = "C:\Program Files\SABnzbd\SABnzbd.exe" "--autorestarted"
2022-08-25 18:51:49,615::INFO::[SABnzbd:1182] Python-version = 3.10.6 (tags/v3.10.6:9c7b4bd, Aug  1 2022, 21:53:49) [MSC v.1932 64 bit (AMD64)]
2022-08-25 18:51:49,615::INFO::[SABnzbd:1183] Dockerized = False
2022-08-25 18:51:49,616::INFO::[SABnzbd:1184] CPU architecture = AMD64
2022-08-25 18:51:49,715::INFO::[SABnzbd:1187] Platform = nt - Windows-10-10.0.20348-SP0
2022-08-25 18:51:49,716::INFO::[SABnzbd:1193] Preferred encoding = cp1252
2022-08-25 18:51:49,717::DEBUG::[SABnzbd:1212] JSON-module = orjson 3.7.11
2022-08-25 18:51:49,717::INFO::[SABnzbd:1215] SSL version = OpenSSL 1.1.1n  15 Mar 2022
2022-08-25 18:51:49,719::INFO::[SABnzbd:1224] Certifi version = 2022.06.15
2022-08-25 18:51:49,720::INFO::[SABnzbd:1225] Loaded additional certificates from C:\Program Files\SABnzbd\certifi\cacert.pem
2022-08-25 18:51:49,774::DEBUG::[SABnzbd:1234] Available certificates = {'x509': 154, 'crl': 0, 'x509_ca': 152}
2022-08-25 18:51:49,775::DEBUG::[getipaddress:101] Local IPv4 address = <REMOVED>
2022-08-25 18:51:49,828::DEBUG::[getipaddress:149] Public IPv4 address = <REMOVED> (in 0.05 seconds)
2022-08-25 18:51:49,829::DEBUG::[getipaddress:162] IPv6 address = <REMOVED>
2022-08-25 18:51:49,831::DEBUG::[getipaddress:88] DNS Lookup = True (in 0.00 seconds)
2022-08-25 18:51:50,072::DEBUG::[getperformance:66] Pystone performance = 87316 (in 0.24 seconds)
2022-08-25 18:51:50,072::DEBUG::[getperformance:50] CPU model = Intel(R) Core(TM) i5-4570 CPU @ 3.20GHz
2022-08-25 18:51:50,072::INFO::[SABnzbd:1246] Using INI file -?\C:\Users\<USERNAME>\AppData\Local\sabnzbd\sabnzbd.ini
2022-08-25 18:51:50,090::DEBUG::[filesystem:1184] [sabnzbd\bpsmeter.py.read] Loading data for totals10.sab
2022-08-25 18:51:50,091::DEBUG::[filesystem:1143] [sabnzbd\filesystem.py.load_admin] Loading data for totals10.sab from -?\C:\Users\<USERNAME>\AppData\Local\sabnzbd\admin\totals10.sab
2022-08-25 18:51:50,092::DEBUG::[downloader:262] Initializing downloader
2022-08-25 18:51:50,092::DEBUG::[downloader:458] Sleep time: 0.001000 seconds
2022-08-25 18:51:50,093::DEBUG::[decoder:77] Initializing 2 decoder(s)
2022-08-25 18:51:50,094::DEBUG::[decoder:121] Initializing decoder Thread-2
2022-08-25 18:51:50,094::DEBUG::[decoder:121] Initializing decoder Thread-3
2022-08-25 18:51:50,095::INFO::[postproc:134] Loading postproc queue
2022-08-25 18:51:50,095::DEBUG::[filesystem:1184] [sabnzbd\postproc.py.load] Loading data for postproc2.sab
2022-08-25 18:51:50,096::DEBUG::[filesystem:1143] [sabnzbd\filesystem.py.load_admin] Loading data for postproc2.sab from -?\C:\Users\<USERNAME>\AppData\Local\sabnzbd\admin\postproc2.sab
2022-08-25 18:51:50,102::DEBUG::[filesystem:1184] [sabnzbd\dirscanner.py.__init__] Loading data for watched_data2.sab
2022-08-25 18:51:50,103::DEBUG::[filesystem:1143] [sabnzbd\filesystem.py.load_admin] Loading data for watched_data2.sab from -?\C:\Users\<USERNAME>\AppData\Local\sabnzbd\admin\watched_data2.sab
2022-08-25 18:51:50,106::DEBUG::[filesystem:1184] [sabnzbd\rss.py.__init__] Loading data for rss_data.sab
2022-08-25 18:51:50,106::DEBUG::[filesystem:1143] [sabnzbd\filesystem.py.load_admin] Loading data for rss_data.sab from -?\C:\Users\<USERNAME>\AppData\Local\sabnzbd\admin\rss_data.sab
2022-08-25 18:51:50,107::INFO::[scheduler:179] Scheduling restart([]) on days [1, 2, 3, 4, 5, 6, 7] at 01:00
2022-08-25 18:51:50,108::INFO::[scheduler:188] Scheduling RSS interval task every 60 min (delay=39)
2022-08-25 18:51:50,108::INFO::[scheduler:199] Scheduling VersionCheck on day 1 at 5:25
2022-08-25 18:51:50,108::INFO::[scheduler:213] Setting schedule for midnight BPS reset
2022-08-25 18:51:50,109::INFO::[scheduler:216] Setting schedule for server expiration check
2022-08-25 18:51:50,110::INFO::[scheduler:221] Setting schedule for server quota check
2022-08-25 18:51:50,110::DEBUG::[filesystem:1184] [sabnzbd\nzbqueue.py.read_queue] Loading data for queue10.sab

The error popup i got when it complety crashed:



Edit 9:00
I have enabled pause during post-processing and direct unpack in the settings, and now did not have any crashes any more.

edit:9:15
To bad, still crashes

[safihre]

It should occur a bit above the lines you copied from the console. Thats only after it detected that the Downloader crashed.

Also, the popup is interesting. How are your disks doing? Seems like your OS disk might be full.

[Notknown]

DIsk space is on that server C:\ > is 23GB. DOwnload location about 1TB. There is enough space. Memory around 3GB free.

The console is not running anymore atm, i will check this weekend. The problem is there is a LOT of code moving on the screen, so it wil be hard to catch it

[sander]

If you Google "OSError: [Errno 12] Not enough space", you get hits with (variants of) "os.execv()" ... which is also on that line 1609 of SABNzbd.py. It starts a process (SAB itself). And that is not directly related to disk space.

Google also gives a hit with a bit different error, but interesting info: "Hypothesis: if your VM is 32-bit, you may be running out of address space."
https://stackoverflow.com/questions/238 ... -not-the-i

So "Not enough space" could be related to something else than disk space. So I think it has to do with your VM system setup.

Worth a try:
reboot the VM, and try again
reboot the whole host, and try again

If that works, you know it's indeed no disk space, but something else got filled up.

@safihre ... I don't know how relevant and true this is: https://github.com/swar/Swar-Chia-Plot- ... ent-741019

[safihre]

I wonder if this is also the source of your Downloader crash. That it runs out of VM resources.
What if it's run directly on the host? As a test.