search

sabnzbd / sabnzbd

SABnzbd - The automated Usenet download tool
http://sabnzbd.org
Other
2.33k stars 340 forks source link

Getting tired of `Restarting because of crashed downloader` #1351

Closed XxUnkn0wnxX closed 4 years ago

XxUnkn0wnxX commented 4 years ago

Hi, i'm on the stable release version of Sab V 2.3.9 - macOS

i have been noticing when downloading some nzb's sab just randomly shuts down and never starts.

the message in the log is Restarting because of crashed downloader <--never restarts just shuts down

& it usually occurs after a few Missing Articles missing (error=430), Badly formed yEnc article

Logs: Logs.zip

Sample Log:

2019-12-14 11:59:50,271::DEBUG::[decoder:122] Decoding YfYhJlVzZaHgRtAhZlRbTvQe-1571246200671@nyuu
2019-12-14 11:59:50,301::DEBUG::[bpsmeter:268] bps: 7482197.11091
2019-12-14 11:59:50,405::DEBUG::[decoder:122] Decoding DhBlZfUjQkSrMmEyTeRgLrPi-1571246200087@nyuu
2019-12-14 11:59:50,434::DEBUG::[decoder:122] Decoding WfJrArEyDaPvOzWsUzNoKuZd-1571246199340@nyuu
2019-12-14 11:59:50,560::DEBUG::[decoder:122] Decoding IdIiLfXpTvKrCqBdGuHrRuJi-1571246183777@nyuu
2019-12-14 11:59:50,560::INFO::[decoder:183] Badly formed yEnc article in IdIiLfXpTvKrCqBdGuHrRuJi-1571246183777@nyuu
2019-12-14 11:59:50,560::INFO::[decoder:324] <Article: article=IdIiLfXpTvKrCqBdGuHrRuJi-1571246183777@nyuu, bytes=739308, partnum=440, art_id=None> => missing from all servers, discarding
2019-12-14 12:00:23,189::INFO::[__init__:1068] Restarting because of crashed downloader
2019-12-14 12:00:23,189::INFO::[__init__:772] [/Applications/SABnzbd.app/Contents/Resources/SABnzbd.py.main] Performing SABnzbd shutdown
2019-12-14 12:00:23,189::INFO::[__init__:385] SABnzbd shutting down...
2019-12-14 12:00:23,189::INFO::[directunpacker:472] Aborting all DirectUnpackers
2019-12-14 12:00:23,189::DEBUG::[__init__:398] Stopping URLGrabber
2019-12-14 12:00:23,189::INFO::[urlgrabber:77] URLGrabber shutting down
2019-12-14 12:00:23,189::DEBUG::[__init__:405] Stopping rating
2019-12-14 12:00:24,184::DEBUG::[rating:156] Stopping ratings
2019-12-14 12:00:24,184::DEBUG::[__init__:412] Stopping dirscanner
2019-12-14 12:00:24,184::INFO::[dirscanner:321] Dirscanner shutting down
2019-12-14 12:00:24,195::DEBUG::[__init__:420] Stopping downloader
2019-12-14 12:00:24,304::DEBUG::[__init__:423] Stopping assembler
2019-12-14 12:00:24,305::INFO::[assembler:67] Shutting down
2019-12-14 12:00:24,305::DEBUG::[__init__:430] Stopping postprocessor
2019-12-14 12:00:25,128::INFO::[nzbqueue:260] Saving queue
2019-12-14 12:00:25,129::DEBUG::[__init__:888] [sabnzbd/nzbstuff.pyc.save_to_disk] Saving data for SABnzbd_nzo_3jZmhZ in /Users/ovidijus/Downloads/NZB Downloads/Temp/[KH] Nakaimo - My Sister is Among Them (BD 1080p) [Dual-Audio]/__ADMIN__
2019-12-14 12:00:25,186::DEBUG::[__init__:959] [sabnzbd/nzbqueue.pyc.save] Saving data for queue10.sab in /Users/ovidijus/Library/Application Support/SABnzbd/admin/queue10.sab
2019-12-14 12:00:25,186::DEBUG::[__init__:959] [sabnzbd/bpsmeter.pyc.save] Saving data for totals10.sab in /Users/ovidijus/Library/Application Support/SABnzbd/admin/totals10.sab
2019-12-14 12:00:25,190::DEBUG::[__init__:959] [sabnzbd/rss.pyc.save] Saving data for rss_data.sab in /Users/ovidijus/Library/Application Support/SABnzbd/admin/rss_data.sab
2019-12-14 12:00:25,190::DEBUG::[__init__:959] [sabnzbd/dirscanner.pyc.save] Saving data for watched_data2.sab in /Users/ovidijus/Library/Application Support/SABnzbd/admin/watched_data2.sab
2019-12-14 12:00:25,190::INFO::[postproc:94] Saving postproc queue
2019-12-14 12:00:25,190::DEBUG::[__init__:959] [sabnzbd/postproc.pyc.save] Saving data for postproc2.sab in /Users/ovidijus/Library/Application Support/SABnzbd/admin/postproc2.sab
2019-12-14 12:00:25,191::DEBUG::[scheduler:257] Terminating scheduler
2019-12-14 12:00:25,191::INFO::[__init__:449] All processes stopped
2019-12-14 12:00:25,191::INFO::[_cplogging:219] [14/Dec/2019:12:00:25] ENGINE Bus STOPPING
2019-12-14 12:00:25,193::INFO::[_cplogging:219] [14/Dec/2019:12:00:25] ENGINE HTTP Server cherrypy._cpwsgi_server.CPWSGIServer(('0.0.0.0', 8080)) shut down
2019-12-14 12:00:25,193::INFO::[_cplogging:219] [14/Dec/2019:12:00:25] ENGINE Bus STOPPED
2019-12-14 12:00:25,193::INFO::[_cplogging:219] [14/Dec/2019:12:00:25] ENGINE Bus EXITING
2019-12-14 12:00:25,193::INFO::[_cplogging:219] [14/Dec/2019:12:00:25] ENGINE Bus EXITED
2019-12-14 12:00:30,522::INFO::[SABnzbd:1157] Console logging for OSX App disabled

& here is the NZB file it's failing to download: [KH] Nakaimo - My Sister is Among Them (BD 1080p) [Dual-Audio].nzb.gz gets to around 2.5 gigs & starts crapping out.. every time i start it again shuts down within 30-40 seconds.

this is not the 1st time i have noticed this with other nzb's but i cannot recall which ones. this is the most recent one that has caused this issue.

i use newshosting as my provider.

my settings: sabnzbd.ini.zip i stripped out the keys, passwords & login details.

this has become beyond frustrating, isn't sab supposed to abort the job if it's impossible to download, i have enabled that option..

albino1 commented 4 years ago

That NZB crashes the downloader on Windows as well, so I think there's something wrong with it.

2019-12-13 19:30:44,408::INFO::[__init__:1068] Restarting because of crashed downloader
2019-12-13 19:30:44,408::INFO::[__init__:772] [SABnzbd.py.main] Performing SABnzbd shutdown
2019-12-13 19:30:44,408::INFO::[__init__:385] SABnzbd shutting down...
XxUnkn0wnxX commented 4 years ago

but sab shouldn't crash because of a download. why doesnt it abort or say it cannot complete it? when i try do using newshosting client to download it goes further up to 23% & kinda just hangs there never finishes.

but that's not the case this has been happening with nzb's over the past month i have had like 3-4 others..

at least if they can find a way to fix this so it doesn't crash. its supposed to by default to try re-trying to download the pieces and if it hangs or cannot get the pieces & it gets stuck it just skips them & tries to download the rest. if they keep failing it should abort the download. why isn't it doing that?

albino1 commented 4 years ago

I don't disagree, just pointing out that it's not only a Mac issue, and that there's specifically something wrong with the NZB. It should definitely handle whatever the issue is more gracefully.

sanderjo commented 4 years ago

I had SABnzbd downloading that .NZB, with a lot of problems indeed, like this:

2019-12-14 14:45:00,477::INFO::[decoder:174] Badly formed yEnc article in PhFmMuPbNjKgJoZtBrNnChZp-1571246207825@nyuu 2019-12-14 14:45:00,480::INFO::[decoder:174] Badly formed yEnc article in WaZaPgYsLvNdMmUoRhYiYlKs-1571246191321@nyuu 2019-12-14 14:45:00,486::INFO::[decoder:174] Badly formed yEnc article in IdIiLfXpTvKrCqBdGuHrRuJi-1571246183777@nyuu 2019-12-14 14:45:28,350::INFO::[init:1017] Restarting because of crashed downloader 2019-12-14 14:45:28,351::INFO::[init:754] [main.main] Performing SABnzbd shutdown 2019-12-14 14:45:28,351::INFO::[init:374] SABnzbd shutting down... 2019-12-14 14:45:28,351::INFO::[directunpacker:463] Aborting all DirectUnpackers

So SAB does recognize and describe the problem: [decoder:174] Badly formed yEnc article in. That is at least something. Maybe a problem in the sabyenc (which is a binary module) The SABnzbd shutting down. is bad, and should not happen because of a malformed article, IMHO

@XxUnkn0wnxX did you try the same download with DirectUnpack unchecked.

XxUnkn0wnxX commented 4 years ago

@sanderjo yes i did, did not help..

Safihre commented 4 years ago

Strange NZB this is.. It's causing faulty readings in decoder and downloader. Have to see how to fix it.

puzzledsab commented 4 years ago

It may be related to a server problem as well. When I try to download only IdIiLfXpTvKrCqBdGuHrRuJi-1571246183777@nyuu using a perl downloader it will hang for 10 seconds before it continues. I get the header and nothing else, and the server responds with 430 No Such Article after QUIT.

Safihre commented 4 years ago

Contacted our technical contact at NewsHosting to debug this, I am seeing the same as @puzzledsab. The problem is that it indeed sends the end-of-article, but then the server doesn't close the connection, but sends another status code. SABnzbd can't handle that second status code, because it already received end-of-article, so it no longer has a reference to an article on the connection. So it results in a crashed downloader.

thezoggy commented 4 years ago

Contacted our technical contact at NewsHosting to debug this, I am seeing the same as @puzzledsab. The problem is that it indeed sends the end-of-article, but then the server doesn't close the connection, but sends another status code. SABnzbd can't handle that second status code, because it already received end-of-article, so it no longer has a reference to an article on the connection. So it results in a crashed downloader.

why not have sab just ignore erroneous server responses?

Safihre commented 4 years ago

Because up to now, it has never happend in this stage. We do ignore them when connecting, just not after receiving an article.

In any case, they informed me it's a bug in their server software and they'll fix it. I'll see in the mean time if I can implement a stability patch.

Safihre commented 4 years ago

I looked at improving the code, but it became such a mess that I decided for now not too apply a patch. This behavior of sending data after end-of-article just triggers a number of things throughout the code, I can't patch them all.

Safihre commented 4 years ago

Newshosting have reported that they fixed the problem on their end. I can confirm that it's no longer sending the weird status-codes. Closing this now, the patch will be distributed over their servers in the upcoming days.