Very low internet speed downloading with ethernet [raspi]

[andyxhadji]

I'm having an issue when using my raspberry pi 4 on ethernet downloading anything with sabnzbd. Connection tests on the pi itself have proper downloading speed (300mb/s) but in SABnzbd, downloads start high but quickly taper off to a crawl. Using wifi instead gets me a more consistent connection, but I'd like to use ethernet for my setup. Has anyone seen this behavior? I'm really struggling trying to debug it.

[sander]

Weird.

Log in on your raspi CLI, and execute this:

Code: Select all

wget -O /dev/null  http://cdimage.ubuntu.com/daily-live/current/impish-desktop-amd64.iso

Each 5 seconds or so, press enter

Post the screen output here. Here's mine:

Code: Select all

/dev/null             1%[                   ]  37,30M  22,9MB/s               
/dev/null             4%[                   ] 137,37M  35,0MB/s    eta 92s    
/dev/null            10%[>                  ] 293,04M  35,1MB/s    eta 80s    
/dev/null            17%[==>                ] 492,72M  35,2MB/s    eta 71s    
/dev/null            26%[====>              ] 770,46M  32,5MB/s    eta 63s    
/dev/null            33%[=====>             ] 967,26M  33,8MB/s    eta 57s

Do it for ethernet and wifi.

[andyxhadji]

Thanks for the response! Here's the output:

Ethernet:

Code: Select all

HTTP request sent, awaiting response... 200 OK
Length: 3025203200 (2.8G) [application/x-iso9660-image]
Saving to: ‘/dev/null’

/dev/null              5%[>                   ] 155.35M  34.3MB/s    eta 79s
/dev/null              9%[>                   ] 286.38M  36.4MB/s    eta 73s
/dev/null             13%[=>                  ] 402.79M  36.4MB/s    eta 70s
/dev/null             18%[==>                 ] 541.34M  36.4MB/s    eta 65s
/dev/null             23%[===>                ] 673.01M  36.5MB/s    eta 62s
/dev/null             27%[====>               ] 806.29M  34.5MB/s    eta 59s
/dev/null             28%[====>               ] 828.37M  34.6MB/s    eta 57s

Wifi:

Code: Select all

HTTP request sent, awaiting response... 200 OK
Length: 3025203200 (2.8G) [application/x-iso9660-image]
Saving to: ‘/dev/null’

/dev/null              0%[                    ]  26.29M  8.72MB/s    eta 5m 28s
/dev/null              2%[                    ]  69.52M  9.42MB/s    eta 5m 11s
/dev/null              4%[                    ] 116.61M  8.83MB/s    eta 5m 8s
/dev/null              5%[>                   ] 155.22M  9.03MB/s    eta 5m 1s
/dev/null              6%[>                   ] 195.99M  8.05MB/s    eta 5m 2s
/dev/null              7%[>                   ] 203.29M  8.20MB/s    eta 5m 1s

[andyxhadji]

Are there any debugging steps or configuration I could change to figure out more about my issue (given that based off network metrics it seems to only be affecting sabnzbd)?

[sander]

As your wget is fast, but your pure-Internet-speedcheck from SAB is slow (zero), I'm out of ideas what that could be.

You could set SAB's logging to +Debug, rerun the SAB status, and see the logging. Example from my system:

Code: Select all

2021-08-12 17:06:51,229::DEBUG::[internetspeed:48] Basic measurement, with small download:
2021-08-12 17:06:51,229::DEBUG::[internetspeed:22] URL is https://sabnzbd.org/tests/internetspeed/5MB.bin
2021-08-12 17:06:51,618::DEBUG::[internetspeed:34] Downloaded bytes: 5242880
2021-08-12 17:06:51,618::DEBUG::[internetspeed:35] Duration in seconds: 0.387958
2021-08-12 17:06:51,618::DEBUG::[internetspeed:51] Speed in MB/s: 12.89
2021-08-12 17:06:51,618::DEBUG::[internetspeed:76] https://sabnzbd.org/tests/internetspeed/20MB.bin
2021-08-12 17:06:51,618::DEBUG::[internetspeed:22] URL is https://sabnzbd.org/tests/internetspeed/20MB.bin
2021-08-12 17:06:52,702::DEBUG::[internetspeed:34] Downloaded bytes: 20971520
2021-08-12 17:06:52,703::DEBUG::[internetspeed:35] Duration in seconds: 1.083903
2021-08-12 17:06:52,703::DEBUG::[internetspeed:78] Speed in MB/s: 18.45
2021-08-12 17:06:52,703::DEBUG::[internetspeed:76] https://sabnzbd.org/tests/internetspeed/20MB.bin
2021-08-12 17:06:52,703::DEBUG::[internetspeed:22] URL is https://sabnzbd.org/tests/internetspeed/20MB.bin
2021-08-12 17:06:53,067::DEBUG::[internetspeed:34] Downloaded bytes: 20971520
2021-08-12 17:06:53,068::DEBUG::[internetspeed:35] Duration in seconds: 0.363957
2021-08-12 17:06:53,068::DEBUG::[internetspeed:78] Speed in MB/s: 54.95

Maybe you have errors there causing the "0"?


Also: check your sabnzbd.log for errors and tracebacks.

[andyxhadji]

Here's a snippet of my logs with debug on!

Code: Select all

2021-08-12 21:52:12,180::DEBUG::[downloader:938] Re-adding article McBhApMlKwPyJuIhUfBwQkBu-1605791677464@nyuu from sometestfile-100MB.part1.rar to server <Server: us.newsdemon.com:563>
2021-08-12 21:52:12,225::DEBUG::[interface:140] Request GET / from 10.42.1.1 [kube-probe/1.20] {}
2021-08-12 21:52:13,188::DEBUG::[bpsmeter:345] Speed: 4 KB/s
2021-08-12 21:52:13,484::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628702216177'}
2021-08-12 21:52:13,491::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628804960999'}
2021-08-12 21:52:15,480::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628702216178'}
2021-08-12 21:52:15,484::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628804961000'}
2021-08-12 21:52:17,482::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628702216179'}
2021-08-12 21:52:17,485::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628804961001'}
2021-08-12 21:52:18,202::DEBUG::[bpsmeter:345] Speed: 1 KB/s
2021-08-12 21:52:19,207::INFO::[downloader:909] Thread [email protected]: timed out
2021-08-12 21:52:19,208::DEBUG::[downloader:938] Re-adding article VzNyUeEeKsKqJySyHvMhVdMs-1605791680364@nyuu from sometestfile-100MB.part2.rar to server <Server: us.newsdemon.com:563>
2021-08-12 21:52:19,477::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628804961002'}
2021-08-12 21:52:19,480::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628702216180'}
2021-08-12 21:52:21,362::DEBUG::[interface:140] Request GET / from 10.42.1.1 [kube-probe/1.20] {}
2021-08-12 21:52:21,480::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628702216181'}
2021-08-12 21:52:21,483::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628804961003'}
2021-08-12 21:52:23,224::DEBUG::[bpsmeter:345] Speed: 593 B/s
2021-08-12 21:52:23,487::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628804961004'}
2021-08-12 21:52:23,492::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628702216182'}
2021-08-12 21:52:25,485::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628804961005'}
2021-08-12 21:52:25,491::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628702216183'}
2021-08-12 21:52:26,232::INFO::[downloader:642] [email protected]: Initiating connection
2021-08-12 21:52:26,233::DEBUG::[downloader:169] us.newsdemon.com: Re-using address 185.151.13.247
2021-08-12 21:52:26,287::INFO::[newswrapper:338] [email protected]: Connected using TLSv1.3 (TLS_AES_256_GCM_SHA384)
2021-08-12 21:52:27,307::INFO::[downloader:846] Connecting [email protected] finished
2021-08-12 21:52:27,458::DEBUG::[nzbstuff:1930] Saving attributes {'cat': '*', 'pp': 3, 'script': 'None', 'priority': 2, 'final_name': 'test_download_100MB', 'password': '', 'url': 'https://sabnzbd.org/tests/test_download_100MB.nzb'} for test_download_100MB
2021-08-12 21:52:27,459::DEBUG::[assembler:109] Decoding part of /downloading/test_download_100MB/sometestfile-100MB.part1.rar
2021-08-12 21:52:27,463::DEBUG::[__init__:895] [sabnzbd.nzbstuff.save_to_disk] Saving data for SABnzbd_nzo_6bb412gs in /downloading/test_download_100MB/__ADMIN__
2021-08-12 21:52:27,468::DEBUG::[__init__:963] [sabnzbd.bpsmeter.save] Saving data for totals10.sab
2021-08-12 21:52:27,470::DEBUG::[__init__:895] [sabnzbd.save_admin] Saving data for totals10.sab in /config/admin
2021-08-12 21:52:27,489::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628702216184'}
2021-08-12 21:52:27,493::DEBUG::[interface:140] Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1) [Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/92.0.4515.131 Safari/537.36] {'limit': '1', 'start': '0', 'output': 'json', 'apikey': '1457c305ced24cafbe8c43cc05c0004c', '_': '1628804961006'}
2021-08-12 21:52:28,228::DEBUG::[bpsmeter:345] Speed: 891 KB/s
2021-08-12 21:52:28,259::DEBUG::[downloader:911] Thread [email protected]: server closed connection

Things that appear strange to me are the "server closed connection" and thread timeouts, curious if anything here pops out to you.

[sander]

Code: Select all

Thread [email protected]: timed out

That's bad: network problems.

Code: Select all

Request GET / from 10.42.1.1 [kube-probe/1.20] {}

What is that? Are you running SAB in docker?

Code: Select all

Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1)

What is that? A proxy?

[andyxhadji]

Code: Select all

Thread [email protected]: timed out

That's bad: network problems.

Code: Select all

Request GET / from 10.42.1.1 [kube-probe/1.20] {}

What is that? Are you running SAB in docker?

Yes, running SAB in k3s so via docker container

Code: Select all

Request GET /queue/ from 10.42.1.15 (X-Forwarded-For: 10.42.1.1)

What is that? A proxy?

I believe that's either radarr/sonarr/lazylibrarian hitting the API but I'm not super certain.

I think I'll try digging in to raspberry pi timeout issues / re-install the OS when I get a chance

[sander]

Code: Select all

Yes, running SAB in k3s so via docker container

Oh, please, solve those problems yourself. And it would have helped if you had told that in your first post. I guess you did the "wget" from the host, not in docker, so now that all work and analysis proves to be irrelevant.

[fttpwatermelon]

I am experiencing the same issue as OP but I am not running it in docker, I am running it on Ubuntu Server 20.04.3 LTS. Even my HDD performance doesn't match what I get. Any help would be greatly appreciated.

Code: Select all

2021-12-08 15:50:00,549::DEBUG::[internetspeed:34] Downloaded bytes: 20971520
2021-12-08 15:50:00,550::DEBUG::[internetspeed:35] Duration in seconds: 1.023392
2021-12-08 15:50:00,550::DEBUG::[internetspeed:78] Speed in MB/s: 19.54

Code: Select all

Speedtest by Ookla

     Server: Swoop Broadband - Melbourne (id = 13057)
        ISP: DCS Internet
    Latency:    22.84 ms   (0.10 ms jitter)
   Download:   923.20 Mbps (data used: 1.1 GB )
     Upload:    43.37 Mbps (data used: 22.8 MB )
Packet Loss:     0.0%
 Result URL: 

Code: Select all

ubuntu@ubuntu:~$ sudo hdparm -Tt /dev/sda

/dev/sda:
 Timing cached reads:   1658 MB in  2.00 seconds = 829.74 MB/sec
 Timing buffered disk reads: 172 MB in  3.35 seconds =  51.27 MB/sec

[sander]

So, if you click on 100MB resp 1GB, what download speed do you get?

[Puzzled]

Code: Select all

ubuntu@ubuntu:~$ sudo hdparm -Tt /dev/sda

/dev/sda:
 Timing cached reads:   1658 MB in  2.00 seconds = 829.74 MB/sec
 Timing buffered disk reads: 172 MB in  3.35 seconds =  51.27 MB/sec

hdparm reads the disk sequentially outside the file system and it is read speed, not write speed. The result can be quite a bit higher than the actual performance. 51 MB/s is not very much so I think that is the source of your problem.

[MessamV]

my download is very slow and not competing downloads