0.4.0-beta2 stops downloading. Restart of SABnzbd needed.

[sander]

My 0.4.0-beta2 had stopped downloading at 09:59. Since then no more logging in sabnzbd.log. Last lines:

2008-04-10 09:59:43,487::INFO::[sabnzbd] Loading data for SABnzbd_article_MPgCFu from /home/sander/SABnzbd-0.4.0Beta2/cache/SABnzbd_article_MPgCFu
2008-04-10 09:59:43,517::INFO::[sabnzbd] /home/sander/SABnzbd-0.4.0Beta2/cache/SABnzbd_article_MPgCFu removed
2008-04-10 09:59:43,531::INFO::[sabnzbd] Loading data for SABnzbd_article_XpQQG2 from /home/sander/SABnzbd-0.4.0Beta2/cache/SABnzbd_article_XpQQG2
2008-04-10 09:59:43,532::INFO::[sabnzbd] /home/sander/SABnzbd-0.4.0Beta2/cache/SABnzbd_article_XpQQG2 removed

After this moment, the webinterface is still functional and showing a download speed of 750 kB/s (but no download was happening).

The stdout is stil putting out info like:

82.170.32.242 - - [10/Apr/2008:11:00:20] "GET /sabnzbd/m/history/?dummy=0.5939401648123276 HTTP/1.1" 200 - "http://blabla:8080/sabnzbd/m/" "Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1.13) Gecko/20080311 Firefox/2.0.0.13"
82.170.32.242 - - [10/Apr/2008:11:00:21] "GET /sabnzbd/m/history/?dummy=0.7659914216642543 HTTP/1.1" 200 - "http://blabla:8080/sabnzbd/m/" "Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9b5) Gecko/2008040514 Firefox/3.0b5"

After a restart of SABnzbd, things work again.

Strange. 

[shypike]

You probably hit this problem, described in ISSUES.txt:

Sometimes logging stops. This is a notorious bug in Python logging. SABnzbd will
function as normal. If you run from sources or use the --console option with the
Win32-binary, you will see that logging continues in the console window, but
nothing will be written to the log-files.


However, since downloading stopped, something else must have happened too.
Problem is, there is no logging!

Could you keep an eye open for the next (if any) stopped download and hopefully there
will be logging.
Alternatively you could use SABnzbd-console.exe. This wil always log to the console.
A bit inconvenient perhaps, but it may reveal the problem.

[sander]

I'm on Ubuntu Linux, so the output is always there. I showed that under 'stdout' in my original post. The thing is it only showed the browser connections, and no download/get info.

My guess: the SABnzbd web interface engine is still running, but the rest of SAB has stopped, and therefore the statistics are not *updated* anymore.

[sander]

I had a stop again. Don't know if it's the same type of stop: Download was now on 0 kB/s, and status was "Idle".

The stdout logging is below.

Network is still up and running, so that can't be the problem.

Code: Select all

2008-04-10 14:00:47,465::ERROR::[downloader] Failed to initialize [email protected]:119
Traceback (most recent call last):
  File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/downloader.py", line 244, in run
    nw.init_connect()
  File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 146, in init_connect
    self.server.username, self.server.password)
  File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 113, in __init__
    except socket.error, (_errno, strerror):
ValueError: need more than 1 value to unpack
2008-04-10 14:00:47,490::WARNING::[downloader] Thread [email protected]:119: failed to initialize
2008-04-10 14:00:47,491::INFO::[downloader] [email protected]:119: Initiating connection
127.0.0.1 - - [10/Apr/2008:14:02:03] "GET /sabnzbd/m/ HTTP/1.1" 200 - "" "Mozilla/5.0 (X11; U; Linux x86_64; en-US; rv:1.9b5) Gecko/2008                    040514 Firefox/3.0b5"
10/Apr/2008:14:02:03 HTTP INFO Page handler: "The path '/sabnzbd/m/static/PlotKit/Plotkit.js' was not found."
Traceback (most recent call last):
  File "/home/sander/SABnzbd-0.4.0Beta2/cherrypy/_cphttptools.py", line 105, in _run
    self.main()
  File "/home/sander/SABnzbd-0.4.0Beta2/cherrypy/_cphttptools.py", line 246, in main
    page_handler, object_path, virtual_path = self.mapPathToObject(path)
  File "/home/sander/SABnzbd-0.4.0Beta2/cherrypy/_cphttptools.py", line 312, in mapPathToObject
    raise cherrypy.NotFound(objectpath)
NotFound: 404

A restart didn't help:

Code: Select all

2008-04-10 14:17:29,565::ERROR::[downloader] Failed to initialize [email protected]:119
Traceback (most recent call last):
  File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/downloader.py", line 244, in run
    nw.init_connect()
  File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 146, in init_connect
    self.server.username, self.server.password)
  File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 113, in __init__
    except socket.error, (_errno, strerror):
ValueError: need more than 1 value to unpack

[sander]

A stop again. Symptoms:

Web interface is still responding
Speed is "Download speed: 1017.16 KB/s", and does not change
Actually, there's no download at all.
The ETA is regularly updated (raised)
There is no logging on stdout, except my browser requests.
"Connections" does show my normal connections.

When I click on PAUSE, SABnzbd pauses, but speed stays at "Download speed: 1017.16 KB/s". ETA is still a normal time, not infinity (which it should be). Clicking RESUME does not re-activate the downloads. Speed stays the same.

Changing the order of the download queues does not re-activate SAB.

CTRL-C and then start SAB, 'solves' the problem.

[shypike]

Do you get the same "ValueError: need more than 1 value to unpack" error on every stop?

Looks like there is some connectivity problem with your newsprovider that SABnzbd is not
handling correctly.

Which exact Python release are you using?

[switch]

Also, are you using SSL? Or normal connections.

[sander]

I'm using SSL too. But the main stream is plain text.

Should I turn off all SSL stuff?

[meekell]

I'm having a similar problem and can't seem to recover from it. I can't configure my usenet server from the web ui. Editing my usenet server results in an "invalid parameter" message. I get the same error message regardless of using ssl or not.

# 2008-04-14 21:08:11,937 ERROR [downloader] Failed to initialize [email protected]:119 Traceback (most recent call last): File "sabnzbd\downloader.pyo", line 244, in run File "sabnzbd\newswrapper.pyo", line 146, in init_connect File "sabnzbd\newswrapper.pyo", line 86, in __init__ error: (10049, 'Address not available')
# 2008-04-14 21:08:11,937 WARNING [downloader] Thread [email protected]:119: failed to initialize

[shypike]

What exactly is the "invalid parameter"?
Looks like SABnzbd thinks it's an invalid address or one that does not resolve to an IP address.
Just to eliminate other causes. Can you try to use the numeric IP address of the server?

Check what value the "nslookup news.usenetserver.com" command gives you.

[meekell]

What exactly is the "invalid parameter"?
Looks like SABnzbd thinks it's an invalid address or one that does not resolve to an IP address.
Just to eliminate other causes. Can you try to use the numeric IP address of the server?

Check what value the "nslookup news.usenetserver.com" command gives you.

The numeric IP works fine.

[sander]

A stop again. This time more logging, and "need more than 1 value to unpack" among others. And this time a restart of SAB doesn't solved this. :-(


2008-04-16 23:20:21,362 WARNING [downloader] Thread [email protected]:119: failed to initialize
2008-04-16 23:22:21,449 ERROR [downloader] Failed to initialize [email protected]:119 Traceback (most recent call last): File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/downloader.py", line 244, in run nw.init_connect() File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 146, in init_connect self.server.username, self.server.password) File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 113, in __init__ except socket.error, (_errno, strerror): ValueError: need more than 1 value to unpack
2008-04-16 23:22:21,450 WARNING [downloader] Thread [email protected]:119: failed to initialize
2008-04-16 23:24:21,538 ERROR [downloader] Failed to initialize [email protected]:119 Traceback (most recent call last): File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/downloader.py", line 244, in run nw.init_connect() File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 146, in init_connect self.server.username, self.server.password) File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 113, in __init__ except socket.error, (_errno, strerror): ValueError: need more than 1 value to unpack
2008-04-16 23:24:21,539 WARNING [downloader] Thread [email protected]:119: failed to initialize
2008-04-16 23:24:22,520 WARNING [downloader] Thread [email protected]:119: timed out
2008-04-16 23:24:22,521 WARNING [downloader] Thread [email protected]:119: timed out
2008-04-16 23:24:22,522 WARNING [downloader] Thread [email protected]:119: timed out
2008-04-16 23:26:22,610 ERROR [downloader] Failed to initialize [email protected]:119 Traceback (most recent call last): File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/downloader.py", line 244, in run nw.init_connect() File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 146, in init_connect self.server.username, self.server.password) File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 113, in __init__ except socket.error, (_errno, strerror): ValueError: need more than 1 value to unpack
2008-04-16 23:26:22,611 WARNING [downloader] Thread [email protected]:119: failed to initialize
2008-04-16 23:28:22,700 ERROR [downloader] Failed to initialize [email protected]:119 Traceback (most recent call last): File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/downloader.py", line 244, in run nw.init_connect() File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 146, in init_connect self.server.username, self.server.password) File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 113, in __init__ except socket.error, (_errno, strerror): ValueError: need more than 1 value to unpack
2008-04-16 23:28:22,701 WARNING [downloader] Thread [email protected]:119: failed to initialize
2008-04-16 23:30:22,789 ERROR [downloader] Failed to initialize [email protected]:119 Traceback (most recent call last): File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/downloader.py", line 244, in run nw.init_connect() File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 146, in init_connect self.server.username, self.server.password) File "/home/sander/SABnzbd-0.4.0Beta2/sabnzbd/newswrapper.py", line 113, in __init__ except socket.error, (_errno, strerror): ValueError: need more than 1 value to unpack
2008-04-16 23:30:22,790 WARNING [downloader] Thread [email protected]:119: failed to initialize

[sander]

Follow-up, with good news:

After I had set all-but-one Config -> Server: Connections to 0 and restarted SABnzbd, things were working again!

FYI: one of those Server-connections was SSL and one was IPv6-only.

Running on Ubuntu.

[shypike]

Were these servers fill-servers or primary ones?
If you have multiple primary servers, SABnzbd will try to distribute the load over the servers.
I'm not sure if SABnzbd always recovers properly if you have a stuck primary server.

[sander]

All primary servers, of which some were not functioning (no account, or trying out SSL which did not work on xlned.com). So the non-functioning primary server could cause the block? Interesting.