SABnzdb server test failure

atrooper-0005 · Post by **atrooper-0005** » May 16th, 2016, 10:08 pm

Host: FreeNAS-9.10-STABLE-201604181743 (74ef270)
SABnzdb plugin installed 1.0.1 [c257b1b]
Configure & test server with the following results:
[Errno 61] Failed to connect: (60, '[Errno 65] No route to host') -[email protected]:563
The DNS path is resolved by ping from the jail.

The nature of the error report from SABnzdb seems like an application configuration problem: something that I have not entered properly or a new configuration setting that is missed. But not certain what it could be.

Found the following release notes for 0.8.0 Beta 6:
SSL protocol by default auto-negotiated with server

Regressed to SABnzdb version 0.7.20 and it operates properly.

I would like to run the latest version, but for now 0.7.20 is operating correctly. I have not tried any other versions to see if the results are different.

I brought this question to this forum from:
https://forums.freenas.org/index.php?th ... ost-285697

Any thoughts about what configuration issues to try?
Any diagnostic thoughts on how to narrow the problem further?

Post by **sander** » May 17th, 2016, 12:59 am

First check: in Server settings, is there a a space after "us-secure.newsdemon.com"? If so, remove that.

atrooper-0005 · Post by **atrooper-0005** » May 26th, 2016, 4:23 pm

Upgraded to v1.0.2. No leading or trailing spaces. No change in the error response.

Post by **sander** » May 27th, 2016, 3:59 am

trial-and-error:

add a few other newsservers, like:
news.astraweb.com
news.giganews.com
newsreader.eweka.nl

with fake username/password, and try again. What do you get?

atrooper-0005 · Post by **atrooper-0005** » May 27th, 2016, 6:17 pm

I added news.giganews.com enable SSL port 563.
un: micky pw: mouse
test server result:
481 Invalid username or password

Did the same with news.astraweb.com
test server result:
[Errno 61] Failed to connect: (60, '[Errno 61] Connection refused') -[email protected]:563

also alternate site us.newsdemon.com
[Errno 61] Failed to connect: (60, '[Errno 65] No route to host') -[email protected]:563
then turned off ssl to port 119
[Errno 61] Failed to connect: (60, '[Errno 65] No route to host') -[email protected]:119

Ping succeeds to each of these sites.

atrooper-0005 · Post by **atrooper-0005** » May 27th, 2016, 6:27 pm

Also tried bogus username to the newsdemon server. Same result, for some reason not getting to the server. Please note that SABnzdb v 0.7.20 is running properly in a jail on the same server used for this testing. I wonder if the newsdemon server is reachable from another location with this version?

Post by **sander** » May 27th, 2016, 11:41 pm

I tried for you, and I get:

Cannot connect to server us-secure.newsdemon.com [Authentication failed, check username/password.]

So that works on my system.

In sabnzbd.log, can you find the lines with "happyeyeballs" in it? Like this:

Code: Select all

2016-05-17 07:15:40,961::INFO::[happyeyeballs:111] Quickest IP address for us-secure.newsdemon.com (port 563, ssl True, preferipv6 True) is 69.16.179.22
2016-05-28 06:29:17,419::INFO::[happyeyeballs:111] Quickest IP address for us-secure.newsdemon.com (port 563, ssl True, preferipv6 True) is 2001:4de0:2101:119e::22

Can you post them?

If you fill out

Code: Select all

newszilla6.xs4all.nl

as newsserver, what do you get as result? What is the happyeyeballs output?

atrooper-0005 · Post by **atrooper-0005** » May 28th, 2016, 7:12 am

Thank you for testing the newsdemon path from your server.

I setup the newszilla server with the following results:
with ssl enabled
[Errno 61] Failed to connect: (60, '[Errno 65] No route to host') -[email protected]:563
with ssl disabled
[Errno 61] Failed to connect: (60, '[Errno 65] No route to host') -[email protected]:119

Note: for all previous and current testing, I must manually set the proper port number for ssl enable/disable. The config menu does not provide auto fill for these values.

sabnzdb.log shows this:
2016-05-28 04:37:22,020::DEBUG::[config:659] Missing configuration item servers,newszilla6.xs4all.nl
2016-05-28 04:37:22,020::DEBUG::[config:659] Missing configuration item servers,newszilla6.xs4all.nl

I checked the newszilla configuration page and it is set up the same way as the newsdemon config (except the mouse user credentials

)

The string "happyeyeballs" does not appear in sabnzdb.log
The log filters "Errors/Warnings", "info" and "Debug" all appear to produce the same results. (Same length log file. Did not try diff, but the first 30 lines or so are visually identical)

Also, no log entries are entered when I test the newsdemon server and the string "newsdemon" or any related names does not appear in the log. I cleared the log on May 26 when I started testing based on your suggestions and the file is now only 192 lines. Only two lines added today ( Missing configuration..).
I did not knowingly change any settings (switches or special) and a quick visual of these settings does not immediately say that there is more logging information available.

Is there another sabnzdb.log file or method to access it? I download it from home->status and interface options (the wrench icon) then the show logging button. Then open in Notepad++.

atrooper-0005 · Post by **atrooper-0005** » May 28th, 2016, 7:19 am

I also tried ping newszilla6.xs4all.nl from the jail and that host is unreachable. It does not appear to be a valid name because it also fails from windows cmd ping too.

Post by **sander** » May 28th, 2016, 11:48 am

OK, I'm quite sure it's an IPv6 problem. Those should not exist anymore as of SABnzbd 1.0.0. That, plus the fact you can't find any lines in sabnzbd.log with 'happyeyeballs' makes me think you have an older SABnzbd running, so something like 0.7.x.

So which version of SABnzbd are you running?

Post by **safihre** » May 28th, 2016, 1:03 pm

You need to change the settings to Debug and then repeat all steps. The log doesn't suddenly get longer after changing the log level, it is how much logging happens after changing the setting.

So set it to Debug and then try to connect. After this the lines Sander speaks of should be there.

atrooper-0005 · Post by **atrooper-0005** » May 29th, 2016, 9:43 am

I set the logging level to "Debugging" then restarted SABnzdb. I ran the test sequence again for news.giganews.com and us-secure.newsdemon.com. Same failures as above for both.

Log entries as follows:

Code: Select all

2016-05-28 16:11:07,975::DEBUG::[misc:616] Checked for a new release, cur= 1000299, latest= 1000299 (on https://github.com/sabnzbd/sabnzbd/releases/tag/1.0.2/), latest_test= 0 (on https://github.com/sabnzbd/sabnzbd/releases/tag/1.0.2/)
2016-05-29 07:33:08,930::DEBUG::[config:659] Missing configuration item servers,news.giganews.com
2016-05-29 07:33:08,930::DEBUG::[config:659] Missing configuration item servers,news.giganews.com

The "happyeyeballs" string does not appear in the log.

atrooper-0005 · Post by **atrooper-0005** » May 29th, 2016, 11:03 am

OK, I'm quite sure it's an IPv6 problem. Those should not exist anymore as of SABnzbd 1.0.0

Freenas host does not have ipv6 enabled.

Post by **sander** » May 29th, 2016, 2:38 pm

Can you restart SABnzbd, have us-secure.newsdemon.com and newszilla.xs4all.nl active as newsserver, let SAB download something, and post the full sabnzbd.log, starting from the restart.

So start with:

Code: Select all

2016-05-29 21:33:06,851::INFO::[SABnzbd:1245] --------------------------------
2016-05-29 21:33:06,852::INFO::[SABnzbd:1246] SABnzbd.py-1.1.x (rev=unknown)
2016-05-29 21:33:06,852::INFO::[SABnzbd:1247] Full executable path = /home/sander/git/sabnzbd/SABnzbd.py
2016-05-29 21:33:06,852::INFO::[SABnzbd:1259] Platform = posix
2016-05-29 21:33:06,853::INFO::[SABnzbd:1260] Python-version = 2.7.6 (default, Jun 22 2015, 17:58:13) 

2016-05-29 21:36:42,804::INFO::[happyeyeballs:111] Quickest IP address for newszilla.xs4all.nl (port 119, ssl 0, preferipv6 True) is 2001:888:0:18::119
2016-05-29 21:36:42,805::DEBUG::[happyeyeballs:113] Happy Eyeballs lookup took 17.083 microseconds
2016-05-29 21:36:42,827::INFO::[happyeyeballs:111] Quickest IP address for newszilla.xs4all.nl (port 119, ssl 0, preferipv6 True) is 2001:888:0:18::119
2016-05-29 21:36:42,828::DEBUG::[happyeyeballs:113] Happy Eyeballs lookup took 9.586 microseconds
2016-05-29 21:36:42,856::INFO::[happyeyeballs:111] Quickest IP address for newszilla.xs4all.nl (port 119, ssl 0, preferipv6 True) is 2001:888:0:18::119
2016-05-29 21:36:42,856::DEBUG::[happyeyeballs:113] Happy Eyeballs lookup took 10.624 microseconds
2016-05-29 21:36:42,883::INFO::[happyeyeballs:111] Quickest IP address for newszilla.xs4all.nl (port 119, ssl 0, preferipv6 True) is 2001:888:0:18::119
2016-05-29 21:36:42,884::DEBUG::[happyeyeballs:113] Happy Eyeballs lookup took 12.502 microseconds
2016-05-29 21:36:42,999::INFO::[happyeyeballs:111] Quickest IP address for us-secure.newsdemon.com (port 119, ssl 0, preferipv6 True) is 2001:4de0:2101:119e::22
2016-05-29 21:36:42,999::DEBUG::[happyeyeballs:113] Happy Eyeballs lookup took 15.235 microseconds

Otherwise I can't help you

atrooper-0005 · Post by **atrooper-0005** » May 29th, 2016, 8:12 pm

I do not know how to complete this request with NewsDemon server. SABnzdb v1.0.2 does not work with the news server I've signed up for. The test fails and I cannot complete a download from this server with this version. I have signed up for only one news service.

Are you suggesting that I sign up for another service to see what happens there?

Please remember that SABnzdb v0.7.20 is operating correctly in another jail. It is servicing all of my download requests without issue. Running in this same FreeNAS host, SABnzdb v 1.0.2 is running in another jail and it does not work with the same server credentials.

The server configuration in v1.0.2 has a few more fields than v0.7.20, so the configuration is not identical (but the host credentials are)
New fields with the settings used are:
priority [0]
SSL Type [Default]
Send Group []
Categories []
Server description [us-secure.newsdemon.com] ** same as the host name
Personal notes []

Is it possibly a configuration mishap?

Code: Select all

2016-05-28 16:11:07,501::INFO::[SABnzbd:1246] --------------------------------
2016-05-28 16:11:07,501::INFO::[SABnzbd:1247] SABnzbd.py-1.0.2 (rev=b7e2bd96844d85623458ea5ad02432becdb199e5)
2016-05-28 16:11:07,501::INFO::[SABnzbd:1248] Full executable path = /usr/pbi/sabnzbd-amd64/bin/SABnzbd.py
2016-05-28 16:11:07,501::INFO::[SABnzbd:1260] Platform = posix
2016-05-28 16:11:07,501::INFO::[SABnzbd:1261] Python-version = 2.7.9 (default, May 14 2016, 17:13:54) 
[GCC 4.2.1 20070831 patched [FreeBSD]]
2016-05-28 16:11:07,502::INFO::[SABnzbd:1262] Arguments = /usr/pbi/sabnzbd-amd64/bin/SABnzbd.py --daemon -f /var/db/sabnzbd/sabnzbd.ini --pidfile /var/run/sabnzbd/sabnzbd.pid
2016-05-28 16:11:07,502::INFO::[SABnzbd:1264] Preferred encoding = 
2016-05-28 16:11:07,502::DEBUG::[SABnzbd:1274] My local IPv4 address = XX.XX.XX.XXX [manual edit]
2016-05-28 16:11:07,587::DEBUG::[SABnzbd:1280] My public IPv4 address = XX.XX.XX.XX [manual edit]
2016-05-28 16:11:07,587::DEBUG::[SABnzbd:1288] Could not determine my IPv6 address
2016-05-28 16:11:07,611::DEBUG::[SABnzbd:1294] CPU Pystone available performance is 64000
2016-05-28 16:11:07,611::INFO::[SABnzbd:1312] Read INI file /var/db/sabnzbd/sabnzbd.ini
2016-05-28 16:11:07,624::DEBUG::[__init__:1180] Test IPv6: Cannot reach IPv6 test host. Disabling IPv6
2016-05-28 16:11:07,624::DEBUG::[__init__:297] External IPv6 test result: False
2016-05-28 16:11:07,624::INFO::[__init__:965] Loading data for rss_data.sab from /var/db/sabnzbd/admin/rss_data.sab
2016-05-28 16:11:07,624::INFO::[__init__:965] Loading data for totals10.sab from /var/db/sabnzbd/admin/totals10.sab
2016-05-28 16:11:07,625::INFO::[__init__:968] /var/db/sabnzbd/admin/totals10.sab missing
2016-05-28 16:11:07,625::INFO::[__init__:965] Loading data for totals9.sab from /var/db/sabnzbd/admin/totals9.sab
2016-05-28 16:11:07,625::INFO::[__init__:968] /var/db/sabnzbd/admin/totals9.sab missing
2016-05-28 16:11:07,625::DEBUG::[bpsmeter:159] Setting default BPS meter values
2016-05-28 16:11:07,645::INFO::[postproc:89] Loading postproc queue
2016-05-28 16:11:07,645::INFO::[__init__:965] Loading data for postproc2.sab from /var/db/sabnzbd/admin/postproc2.sab
2016-05-28 16:11:07,646::INFO::[__init__:965] Loading data for queue10.sab from /var/db/sabnzbd/admin/queue10.sab
2016-05-28 16:11:07,646::DEBUG::[downloader:154] Initializing downloader/decoder
2016-05-28 16:11:07,648::INFO::[__init__:965] Loading data for watched_data2.sab from /var/db/sabnzbd/admin/watched_data2.sab
2016-05-28 16:11:07,648::INFO::[__init__:965] Loading data for Rating.sab from /var/db/sabnzbd/admin/Rating.sab
2016-05-28 16:11:07,649::INFO::[__init__:968] /var/db/sabnzbd/admin/Rating.sab missing
2016-05-28 16:11:07,649::DEBUG::[scheduler:168] Scheduling RSS interval task every 60 min (delay=14)
2016-05-28 16:11:07,649::DEBUG::[scheduler:180] Scheduling VersionCheck on day 5 at 9:4
2016-05-28 16:11:07,649::INFO::[scheduler:190] Setting schedule for midnight BPS reset
2016-05-28 16:11:07,649::INFO::[downloader:241] Resuming
2016-05-28 16:11:07,650::DEBUG::[__init__:555] PAUSED_ALL inactive
2016-05-28 16:11:07,662::INFO::[__init__:350] All processes started
2016-05-28 16:11:07,662::INFO::[SABnzbd:358] Web dir is /usr/pbi/sabnzbd-amd64/share/sabnzbdplus/interfaces/Glitter
2016-05-28 16:11:07,663::INFO::[SABnzbd:358] Web dir is /usr/pbi/sabnzbd-amd64/share/sabnzbdplus/interfaces/Config
2016-05-28 16:11:07,663::DEBUG::[SABnzbd:1349] Unwanted extensions are ... []
2016-05-28 16:11:07,699::DEBUG::[newsunpack:149] UNRAR binary version 5.10
2016-05-28 16:11:07,700::INFO::[SABnzbd:486] _yenc module... found!
2016-05-28 16:11:07,700::INFO::[SABnzbd:494] par2 binary... found (/usr/local/bin/par2)
2016-05-28 16:11:07,701::INFO::[SABnzbd:499] par2-classic binary... found (/usr/local/bin/par2)
2016-05-28 16:11:07,701::INFO::[SABnzbd:502] UNRAR binary... found (/usr/local/bin/unrar)
2016-05-28 16:11:07,701::INFO::[SABnzbd:508] unzip binary... found (/usr/bin/unzip)
2016-05-28 16:11:07,701::INFO::[SABnzbd:514] 7za binary... found (/usr/local/bin/7za)
2016-05-28 16:11:07,702::INFO::[SABnzbd:521] nice binary... found (/usr/bin/nice)
2016-05-28 16:11:07,702::INFO::[SABnzbd:527] ionice binary... NOT found!
2016-05-28 16:11:07,702::INFO::[SABnzbd:530] pyOpenSSL... found (True)
2016-05-28 16:11:07,702::INFO::[SABnzbd:1375] SSL version OpenSSL 1.0.2d 9 Jul 2015
2016-05-28 16:11:07,703::INFO::[SABnzbd:1376] pyOpenSSL version 0.15.1
2016-05-28 16:11:07,703::INFO::[SABnzbd:1377] SSL potentially supported protocols ['SSLv2', 'SSLv23', 'SSLv3', 'TLSv1', 'TLSv1_1', 'TLSv1_2']
2016-05-28 16:11:07,704::INFO::[SABnzbd:1378] SSL actually supported protocols ['t12', 't11', 't1', 'v23', 'v3', 'v2']
2016-05-28 16:11:07,707::INFO::[SABnzbd:1525] Starting web-interface on 0.0.0.0:8080
2016-05-28 16:11:07,708::INFO::[_cplogging:216] [28/May/2016:16:11:07] ENGINE Bus STARTING
2016-05-28 16:11:07,714::INFO::[_cplogging:216] [28/May/2016:16:11:07] ENGINE Started monitor thread '_TimeoutMonitor'.
2016-05-28 16:11:07,823::INFO::[_cplogging:216] [28/May/2016:16:11:07] ENGINE Serving on http://0.0.0.0:8080
2016-05-28 16:11:07,824::INFO::[_cplogging:216] [28/May/2016:16:11:07] ENGINE Bus STARTED
2016-05-28 16:11:07,824::INFO::[zconfig:64] No Bonjour/ZeroConfig support installed
2016-05-28 16:11:07,975::DEBUG::[misc:616] Checked for a new release, cur= 1000299, latest= 1000299 (on https://github.com/sabnzbd/sabnzbd/releases/tag/1.0.2/), latest_test= 0 (on https://github.com/sabnzbd/sabnzbd/releases/tag/1.0.2/)
2016-05-28 16:11:07,975::INFO::[SABnzbd:1597] Starting SABnzbd.py-1.0.2
2016-05-28 16:11:07,975::DEBUG::[__init__:361] Starting postprocessor
2016-05-28 16:11:07,976::DEBUG::[__init__:364] Starting assembler
2016-05-28 16:11:07,976::DEBUG::[__init__:367] Starting downloader
2016-05-28 16:11:07,976::DEBUG::[scheduler:202] Starting scheduler
2016-05-28 16:11:07,977::DEBUG::[__init__:372] Starting dirscanner
2016-05-28 16:11:07,977::INFO::[dirscanner:302] Dirscanner starting up
2016-05-28 16:11:07,977::DEBUG::[__init__:377] Starting urlgrabber
2016-05-28 16:11:07,978::INFO::[urlgrabber:69] URLGrabber starting up
2016-05-29 07:33:08,930::DEBUG::[config:659] Missing configuration item servers,news.giganews.com
2016-05-29 07:33:08,930::DEBUG::[config:659] Missing configuration item servers,news.giganews.com

Support Forum

SABnzdb server test failure

SABnzdb server test failure

Re: SABnzdb server test failure

Re: SABnzdb server test failure

Re: SABnzdb server test failure

Re: SABnzdb server test failure

Re: SABnzdb server test failure

Re: SABnzdb server test failure

Re: SABnzdb server test failure

Re: SABnzdb server test failure

Re: SABnzdb server test failure

Re: SABnzdb server test failure

Re: SABnzdb server test failure

Re: SABnzdb server test failure

Re: SABnzdb server test failure

Re: SABnzdb server test failure