Page 2 of 3
Re: 060b3: one faulty server spoiling the others?
Posted: March 18th, 2011, 6:05 am
by sander
Interesting: with a fresh sabnzbd.ini and only one server (3 connections), I still get the messages.
Code: Select all
2011-03-18 12:01:32,669::INFO::[misc:689] Lauching browser with http://localhost:8080/sabnzbd
Created new window in existing browser session.
2011-03-18 12:01:33,556::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:01:33,657::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:01:33,658::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:01:33,660::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:01:33,661::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:01:33,662::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:01:33,703::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:01:33,705::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:01:33,707::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:01:38,668::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:01:38,670::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:01:38,671::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:01:38,672::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:01:38,673::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:01:38,673::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:01:38,717::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:01:38,718::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:01:38,720::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:01:43,678::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:01:43,680::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:01:43,680::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:01:43,682::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:01:43,682::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:01:43,683::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:01:43,726::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:01:43,727::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:01:43,730::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
Re: 060b3: one faulty server spoiling the others?
Posted: March 18th, 2011, 6:08 am
by sander
Ah, this could be useful: I've setup three connections, and I get the error messages on Thread 2 and 3.
http://localhost:8080/sabnzbd/connections/ is showing one connection (so Thread 1). So they are each other's complement.
Code: Select all
2011-03-18 12:04:48,014::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:04:48,014::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:04:48,112::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:04:48,113::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:04:53,014::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:04:53,015::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:04:53,017::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:04:53,018::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:04:53,121::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:04:53,121::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:04:58,019::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:04:58,021::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:04:58,022::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:04:58,023::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:04:58,067::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:04:58,076::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
Re: 060b3: one faulty server spoiling the others?
Posted: March 18th, 2011, 6:25 am
by sander
More results
Clean sabnzbd.ini, another server (eweka), only one connections ... and still error messages. And no download at all.
Raising number of connections of 1 to 2 results in doubling error messages and still no download.
Adding another server (with 1 connection), also spoils that server, and no download.
Restarting SAB does not solve it.
I'll now stop SAB for 15 minutes to cause a timeout on the newsservers, and see if that changes things.
Code: Select all
2011-03-18 12:14:15,029::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:14:15,030::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:14:20,033::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:14:20,036::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:14:20,036::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:14:25,042::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:14:25,043::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:14:25,044::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:14:30,049::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:14:30,050::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:14:33,104::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:14:35,057::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:14:35,064::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:14:35,110::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:14:40,070::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:14:40,071::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:14:40,072::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
eweka: 2 connections
newszilla6: 1 connection
Still problems after restarting SAB:
Code: Select all
2011-03-18 12:23:16,646::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:23:16,648::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:23:16,649::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 12:23:16,650::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:23:16,651::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:23:16,651::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 12:23:16,689::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:23:16,694::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 12:23:16,699::INFO::[newswrapper:214] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
Re: 060b3: one faulty server spoiling the others?
Posted: March 18th, 2011, 1:32 pm
by shypike
Odd, I didn't see any such message,
despite having about 5 non-functioning server in the list.
Did a system reboot make a difference?
Maybe SABnzbd consumes some system resource.
Re: 060b3: one faulty server spoiling the others?
Posted: March 18th, 2011, 1:53 pm
by jcfp
Maybe the bad file descriptor is somehow a result of using a thread for each connection?
Another observation: server that time out (i.e. "Failed to connect: (110, 'timed out')
[email protected]:119" message on the status page) are not put on ignore for 10 mins. 'Connection refused' servers on the other hand are.
Re: 060b3: one faulty server spoiling the others?
Posted: March 18th, 2011, 1:57 pm
by jcfp
And now it is anyway?! But not the first time, just checked the logs
1070:2011-03-18 19:48:36,894::INFO::[downloader:347]
[email protected]:119: Initiating connection
1071:2011-03-18 19:48:36,906::INFO::[downloader:347]
[email protected]:119: Initiating connection
1145:2011-03-18 19:49:36,964::INFO::[newswrapper:215] Failed to connect: (110, 'timed out')
[email protected]:119
1146:2011-03-18 19:49:36,964::INFO::[newswrapper:215] Failed to connect: (110, 'timed out')
[email protected]:119
1281:2011-03-18 19:51:37,635::INFO::[downloader:347]
[email protected]:119: Initiating connection
1282:2011-03-18 19:51:37,636::INFO::[downloader:347]
[email protected]:119: Initiating connection
1339:2011-03-18 19:52:37,704::INFO::[newswrapper:215] Failed to connect: (110, 'timed out')
[email protected]:119
1340:2011-03-18 19:52:37,709::INFO::[newswrapper:215] Failed to connect: (110, 'timed out')
[email protected]:119
1474:2011-03-18 19:54:38,547::INFO::[downloader:347]
[email protected]:119: Initiating connection
1475:2011-03-18 19:54:38,548::INFO::[downloader:347]
[email protected]:119: Initiating connection
1538:2011-03-18 19:55:38,609::INFO::[newswrapper:215] Failed to connect: (110, 'timed out')
[email protected]:119
1539:2011-03-18 19:55:38,609::INFO::[newswrapper:215] Failed to connect: (110, 'timed out')
[email protected]:119
1541:2011-03-18 19:55:38,862::WARNING::[downloader:267] Server example.org will be ignored for 10 minutes
1542:2011-03-18 19:55:38,863::DEBUG::[downloader:669] Set planned server resume example.org in 10 mins
Re: 060b3: one faulty server spoiling the others?
Posted: March 18th, 2011, 2:07 pm
by sander
shypike wrote:
Odd, I didn't see any such message,
despite having about 5 non-functioning server in the list.
Did a system reboot make a difference?
Maybe SABnzbd consumes some system resource.
After a reboot I still get the same errors. The bad news is that - with both one or two good servers and no bad server- SAB can't download anything with the patched newswrapper.py.
So I've put back the oringal newswrapper.py ... and the downloads flows in ...
#confused
The log of the patched newswrapper.py (with some extra logging to find what's going on)
Code: Select all
2011-03-18 20:02:11,873::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 20:02:11,873::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 20:02:12,003::INFO::[newswrapper:212] in the def error ...
2011-03-18 20:02:12,003::INFO::[newswrapper:221] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 20:02:12,004::INFO::[newswrapper:212] in the def error ...
2011-03-18 20:02:12,005::INFO::[newswrapper:221] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 20:02:16,880::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 20:02:16,881::INFO::[newswrapper:171] just before the Thread call
2011-03-18 20:02:16,881::INFO::[newswrapper:173] after the Thread call
2011-03-18 20:02:16,882::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 20:02:16,883::INFO::[newswrapper:171] just before the Thread call
2011-03-18 20:02:16,883::INFO::[newswrapper:173] after the Thread call
2011-03-18 20:02:16,884::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 20:02:16,885::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 20:02:17,023::INFO::[newswrapper:212] in the def error ...
2011-03-18 20:02:17,024::INFO::[newswrapper:221] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 20:02:17,025::INFO::[newswrapper:212] in the def error ...
2011-03-18 20:02:17,025::INFO::[newswrapper:221] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 20:02:21,891::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 20:02:21,892::INFO::[newswrapper:171] just before the Thread call
2011-03-18 20:02:21,893::INFO::[newswrapper:173] after the Thread call
2011-03-18 20:02:21,893::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-18 20:02:21,894::INFO::[newswrapper:171] just before the Thread call
2011-03-18 20:02:21,895::INFO::[newswrapper:173] after the Thread call
2011-03-18 20:02:21,895::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 20:02:21,896::INFO::[downloader:607] Thread [email protected]:119: server closed connection
2011-03-18 20:02:21,897::INFO::[newswrapper:212] in the def error ...
2011-03-18 20:02:21,897::INFO::[newswrapper:221] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
2011-03-18 20:02:21,977::INFO::[newswrapper:212] in the def error ...
2011-03-18 20:02:21,977::INFO::[newswrapper:221] Failed to connect: (110, '[Errno 9] Bad file descriptor') [email protected]:119
Re: 060b3: one faulty server spoiling the others?
Posted: March 18th, 2011, 2:09 pm
by sander
shypike wrote:
Odd, I didn't see any such message, despite having about 5 non-functioning server in the list.
On Linux, or on another OS?
Re: 060b3: one faulty server spoiling the others?
Posted: March 18th, 2011, 2:22 pm
by shypike
Ubuntu 10.10
Re: 060b3: one faulty server spoiling the others?
Posted: March 18th, 2011, 2:32 pm
by sander
shypike wrote:
Ubuntu 10.10
I'm too on Ubuntu 10.10. It's on wifi but I don't that matters.
Re: 060b3: one faulty server spoiling the others?
Posted: March 18th, 2011, 3:07 pm
by shypike
Your logging is rather confusing, because you patched the file.
I cannot relate the logged line numbers to the code anymore.
Re: 060b3: one faulty server spoiling the others?
Posted: March 18th, 2011, 3:46 pm
by shypike
I'm discovering quite some issues with the code.
It makes me wonder how this can work on Windows.
On Linux it gives race conditions that are much more likely to fail.
You can stop testing for now, I'll get back to you.
Re: 060b3: one faulty server spoiling the others?
Posted: March 19th, 2011, 5:09 am
by shypike
The timing problems aren't as bad as I thought.
Can you try the attached replacement modules?
My problem is that I cannot reproduce Sander's "error 9" problem,
although I understand why it may happen.
Both modules need to be replaced.
Re: 060b3: one faulty server spoiling the others?
Posted: March 19th, 2011, 5:52 am
by sander
shypike wrote:
The timing problems aren't as bad as I thought.
Can you try the attached replacement modules?
My problem is that I cannot reproduce Sander's "error 9" problem,
although I understand why it may happen.
Both modules need to be replaced.
The results look very good with these patched modules:
one good server: downloads OK
two good servers: downloads OK
added
www.cisco.com: download is still OK,
www.cisco.com is correctly handled ("timed out")
added news.tiscali.nl (text only): download is still OK, news.tiscali.nl is tried, but gives 430, which is correctly handled.
Good work!
Re: 060b3: one faulty server spoiling the others?
Posted: March 19th, 2011, 6:29 am
by sander
BTW / FWIW:
I thought SAB would throttle down it's connection setups to a non-responding server? In the current setup it keeps on connecting to
www.cisco.com each minute.
Code: Select all
2011-03-19 11:49:45,466::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:49:45,516::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:49:45,704::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:49:45,719::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:50:15,468::INFO::[downloader:604] Thread [email protected]:119: timed out
2011-03-19 11:50:15,520::INFO::[downloader:604] Thread [email protected]:119: timed out
2011-03-19 11:50:45,474::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:50:45,522::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:50:45,726::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:50:50,684::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:51:15,483::INFO::[downloader:604] Thread [email protected]:119: timed out
2011-03-19 11:51:15,542::INFO::[downloader:604] Thread [email protected]:119: timed out
2011-03-19 11:51:45,484::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:51:45,544::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:51:45,694::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:51:45,759::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:52:15,486::INFO::[downloader:604] Thread [email protected]:119: timed out
2011-03-19 11:52:15,550::INFO::[downloader:604] Thread [email protected]:119: timed out
2011-03-19 11:52:45,487::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:52:45,554::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:52:45,698::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:52:45,739::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:53:15,490::INFO::[downloader:604] Thread [email protected]:119: timed out
2011-03-19 11:53:15,561::INFO::[downloader:604] Thread [email protected]:119: timed out
2011-03-19 11:53:45,494::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:53:45,563::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:53:45,690::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:53:45,735::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:54:15,496::INFO::[downloader:604] Thread [email protected]:119: timed out
2011-03-19 11:54:15,566::INFO::[downloader:604] Thread [email protected]:119: timed out
2011-03-19 11:54:45,499::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:54:45,568::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:54:45,715::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:54:45,763::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:55:15,501::INFO::[downloader:604] Thread [email protected]:119: timed out
2011-03-19 11:55:15,571::INFO::[downloader:604] Thread [email protected]:119: timed out
2011-03-19 11:55:45,503::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:55:45,573::INFO::[downloader:347] [email protected]:119: Initiating connection
2011-03-19 11:55:45,714::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:55:45,751::INFO::[newswrapper:222] Failed to connect: (110, 'timed out') [email protected]:119
2011-03-19 11:56:15,626::INFO::[downloader:604] Thread [email protected]:119: timed out
2011-03-19 11:56:15,626::INFO::[downloader:604] Thread [email protected]:119: timed out