Failed to settle orders for satellite "error": "order: sending settlement agreements returned an error: timeout: no recent network activity"

I think if more people start having the same issue then it might become an issue for now we got different errors.

It seems that the error occurs once a day:

2022-03-30T04:31:04.074Z        ERROR   orders.121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6      rpc client when sending new orders settlements  {"error": "order: sending settlement agreements returned an error: timeout: no recent network activity", "errorVerbose": "order: sending settlement agreements returned an error: timeout: no recent network activity
\tstorj.io/storj/storagenode/orders.(*Service).settleWindow:264
\tstorj.io/storj/storagenode/orders.(*Service).SendOrders.func1:205
\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57", "request": {"limit":{"serial_number":"AAAAAADCIZPWF2ON4K575GWA3A","satellite_id":"121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6","uplink_public_key":{},"storage_node_id":"1veqEG5xuBNkt6cK1NbmL5fbNxXq6E7JzB7CiiaptoapoWnB1i","piece_id":"IKRSDWP5X72TYBOPGRHWPJYEEOC5RCAE6KVUV6B4WT2HKPCAQS2Q","limit":2319360,"action":1,"piece_expiration":"0001-01-01T00:00:00Z","order_expiration":"2022-04-01T02:11:46.324021576Z","order_creation":"2022-03-30T02:11:46.324021576Z","encrypted_metadata_key_id":"4VwE2lxbA3w=","encrypted_metadata":"isdi6hu2w6AqOCxWfytxVCSQ0hWyjKdCWeP/xkfdVt/CsIP4//KgSVM=","satellite_signature":"MEYCIQCCRys4dW5kae74vslis/Di+WNcgekAyR7MSP6NpbJPuwIhALTZ9zjTRlyn/O5Q7rPzjCOtjAa/Uup4kKFuFsOkj84N"},"order":{"serial_number":"AAAAAADCIZPWF2ON4K575GWA3A","amount":768,"uplink_signature":"USLZK/9L7xBLtwY+0d6T1iJirkZkCjxbt5kFkaIfGBQmEFJqyaX0DZiauCpuphJBgEYClXH3mmb4TfZnc8N2Aw=="}}}
2022-03-30T04:31:04.075Z        ERROR   orders.121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6      failed to settle orders for satellite   {"satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "error": "order: sending settlement agreements returned an error: timeout: no recent network activity", "errorVerbose": "order: sending settlement agreements returned an error: timeout: no recent network activity
\tstorj.io/storj/storagenode/orders.(*Service).settleWindow:264
\tstorj.io/storj/storagenode/orders.(*Service).SendOrders.func1:205
\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}

Created an issue on GitHub in order to further investigate of timeouts, cancelled contexts and EOF error messages:

1 Like

Hi @stefanbenten , @Alexey , @thepaul

I’ve added more log details from the 3 issues mentioned here. All around successful uploads, but turning into errors with order settlements:

cc @deathlessdd

1 Like

Just in case it helps - another EOF case from today @thepaul :

docker logs sn1 2>&1 | grep "FR2SMNDWNAWL7FHKTB5EXUHJQFOMMB5MP636L2CWOFZPFPGMIGMQ"
2022-04-01T05:32:09.958Z	INFO	piecestore	upload started	{"Piece ID": "FR2SMNDWNAWL7FHKTB5EXUHJQFOMMB5MP636L2CWOFZPFPGMIGMQ", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "PUT_REPAIR", "Available Space": 7393398771712}
2022-04-01T05:32:10.000Z	INFO	piecestore	uploaded	{"Piece ID": "FR2SMNDWNAWL7FHKTB5EXUHJQFOMMB5MP636L2CWOFZPFPGMIGMQ", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "PUT_REPAIR", "Size": 768}
2022-04-01T07:30:59.261Z	ERROR	orders.1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE	rpc client when sending new orders settlements	{"error": "order: sending settlement agreements returned an error: EOF", "errorVerbose": "order: sending settlement agreements returned an error: EOF\n\tstorj.io/storj/storagenode/orders.(*Service).settleWindow:264\n\tstorj.io/storj/storagenode/orders.(*Service).SendOrders.func1:205\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57", "request": {"limit":{"serial_number":"AAAAAADCJEYVAZCMVEUUW6XQAE","satellite_id":"1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE","uplink_public_key":{},"storage_node_id":"1veqEG5xuBNkt6cK1NbmL5fbNxXq6E7JzB7CiiaptoapoWnB1i","piece_id":"FR2SMNDWNAWL7FHKTB5EXUHJQFOMMB5MP636L2CWOFZPFPGMIGMQ","limit":768,"action":5,"piece_expiration":"0001-01-01T00:00:00Z","order_expiration":"2022-04-03T05:32:00.108146921Z","order_creation":"2022-04-01T05:32:00.108146921Z","encrypted_metadata_key_id":"QDs91VL1vug=","encrypted_metadata":"JgcC0RQWge474mV/+j8pb6BOY43qyQsZTkOVrVnbiCycsA==","satellite_signature":"MEUCIQDC0vLZ+qgwtgRX2D2CrHTAXWuvPBVKNDQ/Z9TYCi5BwgIgb9SzGAFw3eLa04YEUTioLGMCwIQSEi2hBceQTBaDA2w="},"order":{"serial_number":"AAAAAADCJEYVAZCMVEUUW6XQAE","amount":768,"uplink_signature":"tgtvxY5QEZU2Ka185cmdAHmxthm0B/4P0eetf7KK7SUI+AmTlcRxOtp8au4YGGM1lM3F7wNb7MkDhn/GgUbTCA=="}}}

Another “context cancelled” one @thepaul :

2022-04-01T18:31:13.176Z        ERROR   orders.12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB      rpc client error when closing sender    {"error": "order: CloseAndRecv settlement agreements returned an error: context canceled", "errorVerbose": "order: CloseAndRecv settlement agreements returned an error: context canceled
\tstorj.io/storj/storagenode/orders.(*Service).settleWindow:275
\tstorj.io/storj/storagenode/orders.(*Service).SendOrders.func1:205
\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}
2022-04-01T18:31:13.177Z        ERROR   orders.12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB      failed to settle orders for satellite   {"satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "error": "order: CloseAndRecv settlement agreements returned an error: context canceled", "errorVerbose": "order: CloseAndRecv settlement agreements returned an error: context canceled
\tstorj.io/storj/storagenode/orders.(*Service).settleWindow:275
\tstorj.io/storj/storagenode/orders.(*Service).SendOrders.func1:205
\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}

Still issues with release 1.52.2 @thepaul

2022-04-09T14:16:29.863Z        ERROR   orders.121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6      rpc client when sending new orders settlements  {"error": "order: sending settlement agreements returned an error: EOF", "errorVerbose": "order: sending settlement agreements returned an error: EOF
\tstorj.io/storj/storagenode/orders.(*Service).settleWindow:264
\tstorj.io/storj/storagenode/orders.(*Service).SendOrders.func1:205
\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57", "request": {"limit":{"serial_number":"AAAAAADCKQNUL4NPXEZX462QIE","satellite_id":"121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6","uplink_public_key":"HRUW4B3ZQZNR3LYJGQXZYQUC3TPEVXGWQFFPREJUVE6DZ6A2R2FQ","storage_node_id":"1veqEG5xuBNkt6cK1NbmL5fbNxXq6E7JzB7CiiaptoapoWnB1i","piece_id":"JOMCR5G54MPGSL633WFPSB7S5IMCFSQGVBZ77IW3XZOLEW33GK7A","limit":2319360,"action":1,"piece_expiration":"0001-01-01T00:00:00Z","order_expiration":"2022-04-11T12:12:53.197172388Z","order_creation":"2022-04-09T12:12:53.197172388Z","encrypted_metadata_key_id":"4VwE2lxbA3w=","encrypted_metadata":"2eNnsB+PiXX5IVlEwkhtr1K62yxzNYV4xWpqRnZIPcYvJlhxNaym1cOV87NgXpxvQN+KI+6f","satellite_signature":"MEYCIQDF8CJV80b/V5qU6og3UISudDHf3nf2z3JlnAYfK6nNiwIhANABaKvOxvaj/J6/fxfsFBHe593hweH6eTtdJSP/Sh+o"},"order":{"serial_number":"AAAAAADCKQNUL4NPXEZX462QIE","amount":213504,"uplink_signature":"ixSUxl+psHlxowdgBIs4tKifVH4NmcF8gNvw51GBqNogtssHgBpXNjKR9kv5yBUwMnX9nff4YDwQK
 bW/ABUcCw=="}}}
2022-04-09T14:16:29.864Z        ERROR   orders.121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6      failed to settle orders for satellite   {"satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "error": "order: sending settlement agreements returned an error: EOF", "errorVerbose": "order: sending settlement agreements returned an error: EOF
\tstorj.io/storj/storagenode/orders.(*Service).settleWindow:264
\tstorj.io/storj/storagenode/orders.(*Service).SendOrders.func1:205
\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}

Regarding the “context cancelled” topic:

$ docker logs sn1 2>&1 | grep 'JQESQTSS3CVE2GUFVJQDMGKOK5EPVLOZ4SAYMHLUQ63EYT5QL4YQ'
2022-04-25T00:16:21.657Z	INFO	piecestore	upload started	{"Piece ID": "JQESQTSS3CVE2GUFVJQDMGKOK5EPVLOZ4SAYMHLUQ63EYT5QL4YQ", "Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Action": "PUT", "Available Space": 7083656769536}
2022-04-25T00:16:22.214Z	INFO	piecestore	uploaded	{"Piece ID": "JQESQTSS3CVE2GUFVJQDMGKOK5EPVLOZ4SAYMHLUQ63EYT5QL4YQ", "Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Action": "PUT", "Size": 208128}
2022-04-25T00:16:34.874Z	INFO	piecestore	download started	{"Piece ID": "JQESQTSS3CVE2GUFVJQDMGKOK5EPVLOZ4SAYMHLUQ63EYT5QL4YQ", "Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Action": "GET"}
2022-04-25T00:16:35.632Z	INFO	piecestore	downloaded	{"Piece ID": "JQESQTSS3CVE2GUFVJQDMGKOK5EPVLOZ4SAYMHLUQ63EYT5QL4YQ", "Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Action": "GET"}
2022-04-25T02:16:36.276Z	ERROR	orders.121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6	rpc client when sending new orders settlements	{"error": "order: sending settlement agreements returned an error: context canceled", "errorVerbose": "order: sending settlement agreements returned an error: context canceled\n\tstorj.io/storj/storagenode/orders.(*Service).settleWindow:264\n\tstorj.io/storj/storagenode/orders.(*Service).SendOrders.func1:205\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57", "request": {"limit":{"serial_number":"AAAAAADCNCFWEMPSUOIDJV4PII","satellite_id":"121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6","uplink_public_key":"CNSPY5QWKQEJFUC247UISIVWWTSGMLGPNY4O3IXC2RLUYRBZTNXA","storage_node_id":"1veqEG5xuBNkt6cK1NbmL5fbNxXq6E7JzB7CiiaptoapoWnB1i","piece_id":"JQESQTSS3CVE2GUFVJQDMGKOK5EPVLOZ4SAYMHLUQ63EYT5QL4YQ","limit":207872,"action":2,"piece_expiration":"0001-01-01T00:00:00Z","order_expiration":"2022-04-27T00:16:34.289052113Z","order_creation":"2022-04-25T00:16:34.289052113Z","encrypted_metadata_key_id":"4VwE2lxbA3w=","encrypted_metadata":"Desy7TbjDU8E64XNOYiUOTcZRX/8C5FW+RbJ5EkRoIOGnkmivNUs9N8=","satellite_signature":"MEUCIQD02fHqzRxfgwoKvhBki01ujiJ0aeiX2aye/MhDirfUmgIgX6SxC3IQIsO7Z8NgVExBUShTHK+PfepF+tJ4KFvJzkE="},"order":{"serial_number":"AAAAAADCNCFWEMPSUOIDJV4PII","amount":207872,"uplink_signature":"4y/XGAEtNEsUSPXEMkqtCMkobTuCpqQKcWLXam0AxpUFl++TMNS6mDwK/tWhk9ebWVCtgW88DiUN2RGqcu1TAA=="}}}

What I do not understand is: piece was uploaded and downloaded successfully - but the order was not settled successfully. Why? It has nothing to do with the upload and download itself.

Pieces uploaded from the customer and downloaded by the customer, not satellite. Your node have no connection problems with these customers.
But orders submitted to the satellite and there is some communication issues. Maybe your firewall or ISP blocking or throttling connections to that satellite for some reason.

1 Like

Ich habe das selbe problem aber nur bei einer node . habe jetzt schon 1k fehler . port zu ap1 ist laut nmap offen auf der pi

Welches der Probleme hat Ihr node: Der node kann keine Bestellungen senden oder keine Teile empfangen oder senden?
Bitte kopieren Sie das Fehlerbeispiel aus den Protokollen.

The node dont find a one special file.

Could you please post the exact error line?