Page 1 of 1

Losing connection every 10 seconds for half a minute

Posted: August 21st, 2015, 8:58 am
by yekezei
Hi

I'm using astraweb and have limited my connections to 5. I even limited my download speed to 2mb/s and I have a 200 mbit line.
I have SABnzbd running on a VM and it seems to have plenty of resources left. During the download speed drops my web UI becomes unreachable too.

When capping to the speed to 200KB/s it seems to work, capping it to 400KB/s gives me disconnects.

Can anyone figure out what's causing this? My internet connection is steady and everything else works perfectly.

I've been looking in my logs but I don't seem to find anything.

Code: Select all

2015-08-21 15:53:31,882::INFO::[downloader:236] Resuming
2015-08-21 15:53:31,887::INFO::[downloader:236] Resuming
2015-08-21 15:53:32,924::INFO::[downloader:424] 1@news.astraweb.com: Initiating connection
2015-08-21 15:53:32,935::INFO::[downloader:424] 4@news.astraweb.com: Initiating connection
2015-08-21 15:53:32,943::INFO::[downloader:424] 3@news.astraweb.com: Initiating connection
2015-08-21 15:53:32,968::INFO::[downloader:424] 5@news.astraweb.com: Initiating connection
2015-08-21 15:53:32,989::INFO::[downloader:424] 2@news.astraweb.com: Initiating connection
2015-08-21 15:53:34,552::INFO::[downloader:617] Connecting 1@news.astraweb.com finished
2015-08-21 15:53:34,563::INFO::[downloader:617] Connecting 5@news.astraweb.com finished
2015-08-21 15:53:34,569::INFO::[downloader:617] Connecting 4@news.astraweb.com finished
2015-08-21 15:53:34,576::INFO::[downloader:617] Connecting 3@news.astraweb.com finished
2015-08-21 15:53:34,581::INFO::[downloader:617] Connecting 2@news.astraweb.com finished
2015-08-21 15:55:42,394::INFO::[downloader:236] Resuming
2015-08-21 15:55:42,395::INFO::[downloader:245] Pausing
2015-08-21 15:55:42,396::INFO::[nzbqueue:257] Saving queue
2015-08-21 15:55:42,454::INFO::[downloader:703] Thread 5@news.astraweb.com: forcing disconnect
2015-08-21 15:55:43,186::INFO::[__init__:918] Saving data for queue10.sab in /apps/data/.sabnzbd/admin/queue10.sab
2015-08-21 15:55:43,187::INFO::[__init__:918] Saving data for totals10.sab in /apps/data/.sabnzbd/admin/totals10.sab
2015-08-21 15:55:43,189::INFO::[__init__:918] Saving data for rss_data.sab in /apps/data/.sabnzbd/admin/rss_data.sab
2015-08-21 15:55:43,191::INFO::[__init__:918] Saving data for watched_data2.sab in /apps/data/.sabnzbd/admin/watched_data2.sab
2015-08-21 15:55:43,193::INFO::[postproc:85] Saving postproc queue
2015-08-21 15:55:43,194::INFO::[__init__:918] Saving data for postproc2.sab in /apps/data/.sabnzbd/admin/postproc2.sab
2015-08-21 15:55:43,301::INFO::[downloader:703] Thread 3@news.astraweb.com: forcing disconnect
2015-08-21 15:55:43,407::INFO::[downloader:703] Thread 2@news.astraweb.com: forcing disconnect
2015-08-21 15:55:43,516::INFO::[downloader:703] Thread 1@news.astraweb.com: forcing disconnect
2015-08-21 15:55:43,622::INFO::[downloader:703] Thread 4@news.astraweb.com: forcing disconnect
I did get a little bit of those, but even if I don't get them it still disconnects:

Code: Select all

2015-08-21 15:48:34,006::INFO::[downloader:641] Thread 3@news.astraweb.com: Article 558d78bd$0$29516$b1db1813$abfccb7@news.astraweb.com missing (error=430)
2015-08-21 15:48:34,011::INFO::[decoder:224] <Article: article=558d78bd$0$29516$b1db1813$abfccb7@news.astraweb.com, bytes=793289, partnum=188, art_id=None> => missing from all servers, discarding
2015-08-21 15:48:39,030::INFO::[downloader:641] Thread 4@news.astraweb.com: Article 558d78be$1$41356$b1db1813$fc1cfe20@news.astraweb.com missing (error=430)
2015-08-21 15:48:39,034::INFO::[decoder:224] <Article: article=558d78be$1$41356$b1db1813$fc1cfe20@news.astraweb.com, bytes=793218, partnum=204, art_id=None> => missing from all servers, discarding
2015-08-21 15:48:46,238::INFO::[downloader:641] Thread 3@news.astraweb.com: Article 558d78bf$0$41356$b1db1813$fc1cfe20@news.astraweb.com missing (error=430)
2015-08-21 15:48:50,340::INFO::[decoder:224] <Article: article=558d78bf$0$41356$b1db1813$fc1cfe20@news.astraweb.com, bytes=793305, partnum=221, art_id=None> => missing from all servers, discarding

Re: Losing connection every 10 seconds for half a minute

Posted: August 21st, 2015, 9:19 am
by shypike
Not sure what's going on here.
Are you sure your VM doesn't throttle network traffic.
I use VMWare images all the time to test, no problems.
Astraweb can be a bit of a problem, they're a bit peculiar compared to their competitors.
See what happens if you disable the option Config->Switches->"Disconnect on empty queue".

Re: Losing connection every 10 seconds for half a minute

Posted: August 21st, 2015, 9:28 am
by yekezei
Hmm yeah pretty sure it isn't throttling, I've used Virtual Box before and never had these problems. I get 15mb/s download speeds when installing things using yum.
Tried disabling "Disconnect on empty queue" but doesn't seem to help.

It disconnects FAST, after 5 seconds of starting it it already crashes, very weird.

Log from boot to end (disconnected multiple times during):

Code: Select all

2015-08-21 16:27:06,360::INFO::[SABnzbd:1256] --------------------------------
2015-08-21 16:27:06,398::INFO::[SABnzbd:1257] SABnzbd.py-0.8.x (rev=unknown)
2015-08-21 16:27:06,399::INFO::[SABnzbd:1269] Platform = posix
2015-08-21 16:27:06,399::INFO::[SABnzbd:1270] Python-version = 2.7.5 (default, Jun 24 2015, 00:41:19) 
[GCC 4.8.3 20140911 (Red Hat 4.8.3-9)]
2015-08-21 16:27:06,399::INFO::[SABnzbd:1271] Arguments = /apps/sabnzbd/SABnzbd.py --daemon --config-file=/apps/data/.sabnzbd/sabnzbd_config.ini -s 0.0.0.0
2015-08-21 16:27:06,400::INFO::[SABnzbd:1316] Read INI file /apps/data/.sabnzbd/sabnzbd_config.ini
2015-08-21 16:27:06,466::INFO::[__init__:942] Loading data for rss_data.sab from /apps/data/.sabnzbd/admin/rss_data.sab
2015-08-21 16:27:06,480::INFO::[__init__:942] Loading data for totals10.sab from /apps/data/.sabnzbd/admin/totals10.sab
2015-08-21 16:27:06,490::INFO::[postproc:91] Loading postproc queue
2015-08-21 16:27:06,491::INFO::[__init__:942] Loading data for postproc2.sab from /apps/data/.sabnzbd/admin/postproc2.sab
2015-08-21 16:27:06,532::INFO::[__init__:942] Loading data for queue10.sab from /apps/data/.sabnzbd/admin/queue10.sab
2015-08-21 16:27:07,767::INFO::[__init__:942] Loading data for watched_data2.sab from /apps/data/.sabnzbd/admin/watched_data2.sab
2015-08-21 16:27:07,880::INFO::[__init__:942] Loading data for Rating.sab from /apps/data/.sabnzbd/admin/Rating.sab
2015-08-21 16:27:07,881::INFO::[__init__:945] /apps/data/.sabnzbd/admin/Rating.sab missing
2015-08-21 16:27:07,883::INFO::[scheduler:187] Setting schedule for midnight BPS reset
2015-08-21 16:27:07,883::INFO::[downloader:236] Resuming
2015-08-21 16:27:07,884::INFO::[__init__:333] All processes started
2015-08-21 16:27:07,885::INFO::[SABnzbd:359] Web dir is /apps/sabnzbd/interfaces/Glitter
2015-08-21 16:27:07,896::INFO::[SABnzbd:359] Web dir is /apps/sabnzbd/interfaces/Config
2015-08-21 16:27:08,270::INFO::[SABnzbd:491] _yenc module... found!
2015-08-21 16:27:08,271::INFO::[SABnzbd:499] par2 binary... found (/usr/bin/par2)
2015-08-21 16:27:08,271::INFO::[SABnzbd:504] par2-classic binary... found (/usr/bin/par2)
2015-08-21 16:27:08,271::INFO::[SABnzbd:507] unrar binary... found (/usr/bin/unrar)
2015-08-21 16:27:08,272::INFO::[SABnzbd:512] unzip binary... found (/usr/bin/unzip)
2015-08-21 16:27:08,272::INFO::[SABnzbd:517] 7za binary... found (/usr/bin/7za)
2015-08-21 16:27:08,273::INFO::[SABnzbd:523] nice binary... found (/usr/bin/nice)
2015-08-21 16:27:08,273::INFO::[SABnzbd:527] ionice binary... found (/usr/bin/ionice)
2015-08-21 16:27:08,273::INFO::[SABnzbd:532] pyOpenSSL... found (True)
2015-08-21 16:27:08,279::INFO::[SABnzbd:1525] Starting web-interface on 0.0.0.0:8082
2015-08-21 16:27:08,363::INFO::[_cplogging:216] [21/Aug/2015:16:27:08] ENGINE Bus STARTING
2015-08-21 16:27:08,493::INFO::[_cplogging:216] [21/Aug/2015:16:27:08] ENGINE Started monitor thread '_TimeoutMonitor'.
2015-08-21 16:27:08,954::INFO::[_cplogging:216] [21/Aug/2015:16:27:08] ENGINE Serving on http://0.0.0.0:8082
2015-08-21 16:27:09,876::INFO::[_cplogging:216] [21/Aug/2015:16:27:09] ENGINE Serving on http://::1:8082
2015-08-21 16:27:09,877::INFO::[_cplogging:216] [21/Aug/2015:16:27:09] ENGINE Bus STARTED
2015-08-21 16:27:09,879::INFO::[zconfig:64] No Bonjour/ZeroConfig support installed
2015-08-21 16:27:10,461::INFO::[SABnzbd:1597] Starting SABnzbd.py-0.8.x
2015-08-21 16:27:10,651::INFO::[dirscanner:299] Dirscanner starting up
2015-08-21 16:27:10,735::INFO::[urlgrabber:70] URLGrabber starting up
2015-08-21 16:27:11,654::INFO::[downloader:424] 1@news.astraweb.com: Initiating connection
2015-08-21 16:27:11,684::INFO::[downloader:424] 2@news.astraweb.com: Initiating connection
2015-08-21 16:27:11,725::INFO::[downloader:424] 3@news.astraweb.com: Initiating connection
2015-08-21 16:27:11,739::INFO::[downloader:424] 4@news.astraweb.com: Initiating connection
2015-08-21 16:27:11,779::INFO::[downloader:424] 5@news.astraweb.com: Initiating connection
2015-08-21 16:27:13,392::INFO::[downloader:617] Connecting 4@news.astraweb.com finished
2015-08-21 16:27:13,395::INFO::[downloader:617] Connecting 5@news.astraweb.com finished
2015-08-21 16:27:13,397::INFO::[downloader:617] Connecting 1@news.astraweb.com finished
2015-08-21 16:27:13,398::INFO::[downloader:617] Connecting 2@news.astraweb.com finished
2015-08-21 16:27:13,400::INFO::[downloader:617] Connecting 3@news.astraweb.com finished
2015-08-21 16:29:32,243::INFO::[downloader:236] Resuming
2015-08-21 16:29:32,244::INFO::[downloader:245] Pausing
2015-08-21 16:29:32,245::INFO::[nzbqueue:257] Saving queue
2015-08-21 16:29:33,410::INFO::[__init__:918] Saving data for queue10.sab in /apps/data/.sabnzbd/admin/queue10.sab
2015-08-21 16:29:33,412::INFO::[__init__:918] Saving data for totals10.sab in /apps/data/.sabnzbd/admin/totals10.sab
2015-08-21 16:29:33,413::INFO::[__init__:918] Saving data for rss_data.sab in /apps/data/.sabnzbd/admin/rss_data.sab
2015-08-21 16:29:33,415::INFO::[__init__:918] Saving data for watched_data2.sab in /apps/data/.sabnzbd/admin/watched_data2.sab
2015-08-21 16:29:33,416::INFO::[postproc:85] Saving postproc queue
2015-08-21 16:29:33,417::INFO::[__init__:918] Saving data for postproc2.sab in /apps/data/.sabnzbd/admin/postproc2.sab

Re: Losing connection every 10 seconds for half a minute

Posted: August 21st, 2015, 12:17 pm
by sander
I would start by setting Logging to +Debug (via Status -> tab Latest Warnings), and then inspect & post the log again.

I would also add some other newsserver like newzilla.xs4all.nl. You have no access, so you should get a clean error message. Just as reference and check about access via NNTP (ruling out network problems)

Re: Losing connection every 10 seconds for half a minute

Posted: August 21st, 2015, 2:39 pm
by yekezei
Hey, I noticed I have a process using all of my resources. Do you know what this is?

Image

Re: Losing connection every 10 seconds for half a minute

Posted: August 21st, 2015, 3:30 pm
by sander