Weird number of GET commands for a piece on US1

Node Operators troubleshooting
1

Hello

There is something strange happening on one of my nodes, ID 12DzDryqsv6Yp2M3CgJ5BXxGR8kc1cMLUDen4bzcEDqpwdzap8v.

The node gets endless GET-Requests for a piece from the US-Satellite::
subfolder ‘2v’

-rw------- 1 root root 2319872 Dez 30 2022 5ke6j6xyakr7d7op3oypodt3n7clq35gbce32j224yphf7qk2q.sj1

The piece is temporary renamed, now all GET for this piece are simply failing.

I have taken a snapshot from logs with about 430MB in size,
starting time: 2024-02-15T18:01:12Z, ending time: 2024-02-16T03:41:10Z,
that’s around 9:40 hours.

Got the lines from the log:

grep “2V5KE6J6XYAKR7D7OP3OYPODT3N7CLQ35GBCE32J224YPHF7QK2Q” node.log | grep “download started” >piece-download-started.txt

Count it:

wc -l piece-download-started.txt

Result: 314001 entries for this piece, so there is an average of 9 GET commands per second and would be an egress of 19.9 Megabyte/s!

Extracting the IP-Addresses gave me this as sources:

5.161.51.162 = static.162.51.161.5.clients.your-server.de
5.161.56.161 = static.161.56.161.5.clients.your-server.de
5.161.61.225 = static.225.61.161.5.clients.your-server.de
5.161.64.186 = static.186.64.161.5.clients.your-server.de
5.161.76.253 = static.253.76.161.5.clients.your-server.de
5.161.104.6 = static.6.104.161.5.clients.your-server.de
5.161.192.160 = static.160.192.161.5.clients.your-server.de
5.161.213.246 = static.246.213.161.5.clients.your-server.de

→ Hetzner Online GmbH

Is anybody here seeing similar behavior from these IPs?

I see two possible explanations:

  • Misconfigured or buggy software
  • DDOS attack (but a poor one)

@Alexey. perhaps this is something the devs at Storj Labs wants to investigate, i have uploaded the log to Storj DCS already and can provide the link to it.

2

:open_mouth: How?!

Could you please post an excerpt from the logs? I do not recognize anything you said.

P.S. Any customers behavior is normal. There is no stable pattern.

1 Like
3

I got your logs, but, sorry, I did not recognize anything that you said…
Could you please explain?

4

There’s nothing wrong with customers fetching their files even hundreds of thousands of time. And if it’s the same piece again and again, great, it stays in cache. As long as you get paid for egress, you shouldn’t worry.

1 Like
5

Looks normal to me

root@server030:/disk102/storj/logs/storagenode# grep "^2024-02-09T" server051-v1.95.1-30051.log | grep "B5IKK2TSZPDWDHU2RLAFBZKBTCU2T554AVLCVENDLXPOCE25CWZA" | grep -c 'download started'
0
root@server030:/disk102/storj/logs/storagenode# grep "^2024-02-10T" server051-v1.95.1-30051.log | grep "B5IKK2TSZPDWDHU2RLAFBZKBTCU2T554AVLCVENDLXPOCE25CWZA" | grep -c 'download started'
33943
root@server030:/disk102/storj/logs/storagenode# grep "^2024-02-11T" server051-v1.95.1-30051.log | grep "B5IKK2TSZPDWDHU2RLAFBZKBTCU2T554AVLCVENDLXPOCE25CWZA" | grep -c 'download started'
1109849
root@server030:/disk102/storj/logs/storagenode# grep "^2024-02-12T" server051-v1.95.1-30051.log | grep "B5IKK2TSZPDWDHU2RLAFBZKBTCU2T554AVLCVENDLXPOCE25CWZA" | grep -c 'download started'
1151622
root@server030:/disk102/storj/logs/storagenode# grep "^2024-02-13T" server051-v1.95.1-30051.log | grep "B5IKK2TSZPDWDHU2RLAFBZKBTCU2T554AVLCVENDLXPOCE25CWZA" | grep -c 'download started'
1150782
root@server030:/disk102/storj/logs/storagenode# grep "^2024-02-14T" server051-v1.95.1-30051.log | grep "B5IKK2TSZPDWDHU2RLAFBZKBTCU2T554AVLCVENDLXPOCE25CWZA" | grep -c 'download started'
969805
root@server030:/disk102/storj/logs/storagenode# grep "^2024-02-15T" server051-v1.95.1-30051.log | grep "B5IKK2TSZPDWDHU2RLAFBZKBTCU2T554AVLCVENDLXPOCE25CWZA" | grep -c 'download started'
757012

root@server030:/disk102/storj/logs/storagenode# grep "B5IKK2TSZPDWDHU2RLAFBZKBTCU2T554AVLCVENDLXPOCE25CWZA" server051-v1.95.1-30051.log | grep "download started" | awk -F':|"' '{print $34}' | sort -n | uniq
5.161.104.6
5.161.53.58
5.161.51.162
5.161.56.161
5.161.61.225
5.161.64.186
5.161.76.253
5.161.192.160
5.161.213.246

Th3Van.dk

6

The zip file contains also a small bash script to extract the GET commands for the piece with the ID 2V5KE6J6XYAKR7D7OP3OYPODT3N7CLQ35GBCE32J224YPHF7QK2Q into a second file (and a third file with the failed messages).

Count the number of lines in the file with the extracted GET commands, it should be 314001.

Or take a look at the GET commands in the first complete second, timestamp is 2024-02-15T18:01:17Z, the number is 88 GET.

88 times download multiplied with the size of 2319872 (2.3MB) Bytes equals to 204148736 (194.69MB) in one second. (The average over the complete 9:40 hours is 9 GET per second and 19.9MB/s)

I had most of the downloads failed when the file was accessible and the node has completely saturated my upload capabilities and therefore affecting other nodes which behave ‘normal’.

Another point: which customer loads the same piece with this frequency and waste his bandwitch and his money?
If i would be able to upload arround 20 Megabyte per second i could transfer 1.7TB each day, 51.58TB in one month paying me $77.37 frome a single piece,

Since a customer needs 29 pieces to restore he would pay $2244 for a single segment per month.

Some sort of cache should be cheaper.

Makes this any sense?

7

This could be completely normal behavior if someone posted up a very popular file hosted on Storj and the public is downloading it. As a node operator this would be a good “problem” to have as you earn egress.

2 Likes