Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

E mined block failed verification #9496

Open
Jayd603 opened this issue Oct 1, 2024 · 32 comments
Open

E mined block failed verification #9496

Jayd603 opened this issue Oct 1, 2024 · 32 comments

Comments

@Jayd603
Copy link

Jayd603 commented Oct 1, 2024

Ran this public node for years, has the latest version, restricted-rpc is enabled and CPU use doesn't show monerod mining at all. ..yet logs are flooded with these:
2024-09-23 17:51:00.906 E mined block failed verification

First i've seen it, I appear to be on the latest block and handling connections ok anyway.

@selsta
Copy link
Collaborator

selsta commented Oct 1, 2024

When was the last time you saw this message?

@Jayd603
Copy link
Author

Jayd603 commented Oct 1, 2024

They are still happening. Started a few days ago.

2024-10-01 14:10:23.869 E Transaction not found in pool
2024-10-01 14:10:50.004 E mined block failed verification
2024-10-01 14:11:07.976 E Transaction not found in pool
2024-10-01 14:11:47.544 E mined block failed verification

@Jayd603
Copy link
Author

Jayd603 commented Oct 1, 2024

I restarted the container, immediately the same error started showing.

@selsta
Copy link
Collaborator

selsta commented Oct 1, 2024

Even a restricted RPC allows users to submit a mined block. Can you try if you get this message with no external RPC at all?

@Jayd603
Copy link
Author

Jayd603 commented Oct 1, 2024

Oh, I didn't know that. possibly just someone trying to submit bad blocks over and over?

@selsta
Copy link
Collaborator

selsta commented Oct 1, 2024

Possible, yes. But not sure why.

@nahuhh
Copy link

nahuhh commented Oct 3, 2024

Do you run with --public-node?

@thilool
Copy link

thilool commented Oct 4, 2024

I see the same issue on my node starting at 2014-09-30 at 20:00
I don't run the explicit command --public-node but I have of course restricted-rpc

@Jayd603
Copy link
Author

Jayd603 commented Oct 4, 2024

I do run with public-node.

@thilool
Copy link

thilool commented Oct 4, 2024

is there a way to see the IP of the sender which spams my node and add it to a block list?

@selsta
Copy link
Collaborator

selsta commented Oct 4, 2024

It might show up with log level 2

@thilool
Copy link

thilool commented Oct 4, 2024

with log-level=2 I see this errors:
2024-10-04 19:33:34.586 E Exception in boosted_tcp_server<t_protocol_handler>::handle_accept: set_option: Bad file descriptor
2024-10-04 19:33:34.586 E Some problems at accept: Success, connections_count = 2

and this:
2024-10-04 19:34:58.073 E Error in boosted_tcp_server<t_protocol_handler>::handle_accept: asio.misc:1
2024-10-04 19:34:58.073 E Some problems at accept: Already open, connections_count = 2

showing up regularly

@selsta
Copy link
Collaborator

selsta commented Oct 4, 2024

Doesn't seem related to me based on the error message.

@nahuhh
Copy link

nahuhh commented Oct 4, 2024

is there a way to see the IP of the sender which spams my node and add it to a block list?

You should see (on loglevel 1) the ip which is contacting rpc endpoints

@thilool
Copy link

thilool commented Oct 4, 2024

this is more detail:
2024-10-04 19:36:17.007 D [178.25.224.210:11815 OUT] LEVIN_PACKET_RECEIVED. [len=3782, flags1, r?=?, cmd = 2002, v=1
2024-10-04 19:36:17.007 I [178.25.224.210:11815 OUT] 3782 bytes received for category command-2002 initiated by peer
2024-10-04 19:36:17.007 I [178.25.224.210:11815 OUT] Received NOTIFY_NEW_TRANSACTIONS (2 txes)
2024-10-04 19:36:17.008 I Including transaction <1ea20076555b95c2924aa092d40cd2e31e4526d61e66c9a5ef12830643ced308>
2024-10-04 19:36:17.008 I Including transaction <2674a3a3abf15b5fa6e6ba35101ed5f8f1e7e7f1a89bacd2d279bf21229bf2ef>
2024-10-04 19:36:17.008 D tx <1ea20076555b95c2924aa092d40cd2e31e4526d61e66c9a5ef12830643ced308>already have transaction in tx_pool
2024-10-04 19:36:17.009 D tx <2674a3a3abf15b5fa6e6ba35101ed5f8f1e7e7f1a89bacd2d279bf21229bf2ef>already have transaction in tx_pool
2024-10-04 19:36:17.141 D handle_accept
2024-10-04 19:36:17.142 E Error in boosted_tcp_server<t_protocol_handler>::handle_accept: asio.misc:1
2024-10-04 19:36:17.142 E Some problems at accept: Already open, connections_count = 2

looks like somebody tried to send 2 tx which are not accepted

@thilool
Copy link

thilool commented Oct 4, 2024

again more detail about the other error:
2024-10-04 19:36:19.508 I [113.196.177.100:29671 OUT] 1559 bytes sent for category command-2002 initiated by us
2024-10-04 19:36:19.508 D [113.196.177.100:29671 OUT] LEVIN_PACKET_SENT. [len=1559, flags1, r?=?, cmd = 2002, ver=1
2024-10-04 19:36:19.508 I [185.250.243.159:18082 OUT] 1559 bytes sent for category command-2002 initiated by us
2024-10-04 19:36:19.508 D [185.250.243.159:18082 OUT] LEVIN_PACKET_SENT. [len=1559, flags1, r?=?, cmd = 2002, ver=1
2024-10-04 19:36:19.508 I [184.75.221.43:18191 OUT] 1559 bytes sent for category command-2002 initiated by us
2024-10-04 19:36:19.508 D [184.75.221.43:18191 OUT] LEVIN_PACKET_SENT. [len=1559, flags1, r?=?, cmd = 2002, ver=1
2024-10-04 19:36:19.546 D handle_accept
2024-10-04 19:36:19.546 E Error in boosted_tcp_server<t_protocol_handler>::handle_accept: asio.misc:1
2024-10-04 19:36:19.547 E Some problems at accept: Already open, connections_count = 2

@nahuhh
Copy link

nahuhh commented Oct 4, 2024

I dont see the same mined block failed verification log. your issue seems unrelated @thilool

@thilool
Copy link

thilool commented Oct 4, 2024

it does not show up in the level 2 log.
here a snipped with level 1:

024-10-04 22:12:46.650 I HTTP [194.233.152.128] POST /json_rpc
2024-10-04 22:12:46.651 I [194.233.152.128:26017 INC] Calling RPC method submitblock
2024-10-04 22:12:46.666 I [162.218.65.83:18085 OUT] 57025 bytes received for category command-2002 initiated by peer
2024-10-04 22:12:46.666 I [162.218.65.83:18085 OUT] Received NOTIFY_NEW_TRANSACTIONS (22 txes)
2024-10-04 22:12:46.667 I Including transaction <8a8f4c331557d98e8e05f950edbab177873603a0024504d0cb8b9a86db513a8a>
2024-10-04 22:12:46.667 I Including transaction <424ed8763145ffc6dc1bb9e83c83b5d35e36fbcd9395c42fe93f6175cd5b43ca>
2024-10-04 22:12:46.667 I Including transaction
2024-10-04 22:12:46.668 I Including transaction
2024-10-04 22:12:46.668 I Including transaction <1c5a8d3011041d0aba7afbf37178f552071d6dd80eeceef4f6906d0fd79a490c>
2024-10-04 22:12:46.668 I Including transaction <1cb3c2e5790c5ab7efdd53077fd83aff02f8d0940f2dee4423a1c338caa30e2c>
2024-10-04 22:12:46.669 I Including transaction <266c27026033347057d73e86d450fa43cec61d2e1fdaa2c7a733dd09f6779b30>
2024-10-04 22:12:46.669 I Including transaction
2024-10-04 22:12:46.670 I Including transaction
2024-10-04 22:12:46.670 I Including transaction
2024-10-04 22:12:46.670 I Including transaction
2024-10-04 22:12:46.671 I Including transaction
2024-10-04 22:12:46.671 I Including transaction <2448b230cdc110904cb06656667a6ec437af1e621084a2e7159200c2825d4c6d>
2024-10-04 22:12:46.672 I Including transaction <666417baacbd626e0ef897151ee4465b734cd46a4a5caf2c17148dd2f1e584b9>
2024-10-04 22:12:46.674 I Including transaction <52aadc3c739f39c095b8d17eac7207c710a432051307784af5f44effd38619eb>
2024-10-04 22:12:46.674 I Including transaction <0c32c21bed5be4fc1d365c3e1c702b456fdf33b289ac4a0e2fd0c6a0f291f2ce>
2024-10-04 22:12:46.674 I Including transaction
2024-10-04 22:12:46.675 I Including transaction
2024-10-04 22:12:46.675 I Including transaction <82f0e854e6a721b3b35222775bd049dc3f2c5c78f48fdbbdc5de59e8998e4076>
2024-10-04 22:12:46.676 I Including transaction <03af9ea6634023907dd84146ac6c1b6e5a6043127619d3ca0e959a8f147b2f61>
2024-10-04 22:12:46.676 I Including transaction <83d46365bad4e695fa2249a2addf7bbe64452b9103abbdb7f40c6602bc0efe84>
2024-10-04 22:12:46.677 I Including transaction
2024-10-04 22:12:46.688 E Block with id: <5051a2feb0afb1bbd86a28a9d54cffe191ec5cb4d8c25fdd768a29b746235562>
2024-10-04 22:12:46.688 E does not have enough proof of work: at height 3251967, unexpected difficulty: 346407873584
2024-10-04 22:12:46.689 E mined block failed verification

@thilool
Copy link

thilool commented Oct 4, 2024

here another one:
2024-10-04 22:14:11.904 W [ OUT] back ping connect failed to 136.60.3.95:18080
2024-10-04 22:14:12.000 I [162.218.65.219:11095 INC] 227 bytes received for category command-1001 initiated by peer
2024-10-04 22:14:12.001 I [162.218.65.219:11095 INC] 10 bytes sent for category command-1007 initiated by us
2024-10-04 22:14:12.002 I [162.218.65.219:11095 INC] 15520 bytes sent for category command-1001 initiated by us
2024-10-04 22:14:12.129 I HTTP [175.176.28.62] POST /json_rpc
2024-10-04 22:14:12.129 I [175.176.28.62:46116 INC] Calling RPC method getblocktemplate
2024-10-04 22:14:12.209 I HTTP [194.233.152.128] POST /json_rpc
2024-10-04 22:14:12.209 I [194.233.152.128:26045 INC] Calling RPC method submitblock
2024-10-04 22:14:12.241 I HTTP [160.178.181.182] GET /getheight
2024-10-04 22:14:12.242 I [160.178.181.182:50518 INC] calling /getheight
2024-10-04 22:14:12.243 E Block with id:
2024-10-04 22:14:12.243 E does not have enough proof of work: at height 3251968, unexpected difficulty: 346066290034
2024-10-04 22:14:12.243 E mined block failed verification

btw I am running p2pool as well may this has something to do with it?

@thilool
Copy link

thilool commented Oct 4, 2024

these error are always in between:

2024-10-04 22:15:05.178 I Including transaction <96583190dda605d5b45597fd445a283c3f1c284bc5cf7bfc38a98cc2054970ac>
2024-10-04 22:15:05.190 I HTTP [197.254.96.246] POST /json_rpc
2024-10-04 22:15:05.190 I [197.254.96.246:59506 INC] Calling RPC method submitblock
2024-10-04 22:15:05.190 E Transaction not found in pool

maybe this is some hint what is going on there.
At the same time the hashrate of my server drops about 1000Hs

@thilool
Copy link

thilool commented Oct 4, 2024

I stopped p2pool to check but the errors still show up:
2024-10-04 22:21:12.179 I HTTP [194.233.152.128] POST /json_rpc
2024-10-04 22:21:12.179 I [193.142.4.107:37683 INC] 10 bytes received for category command-1003 initiated by peer
2024-10-04 22:21:12.179 I [194.233.152.128:25665 INC] Calling RPC method submitblock
2024-10-04 22:21:12.179 I [193.142.4.107:37683 INC] 38 bytes sent for category command-1003 initiated by us
2024-10-04 22:21:12.185 W [ OUT] back ping connect failed to 162.218.65.219:18080
2024-10-04 22:21:12.202 E Block with id:
2024-10-04 22:21:12.202 E does not have enough proof of work: <2d3fcce41c200893435694cf1551f8c925eaebbfa6ebde1a984cb3addb370000> at height 3251971, unexpected difficulty: 346109226234
2024-10-04 22:21:12.202 E mined block failed verification

The IP 162.218.65.219:18080 seems to always show up right before the error

@nahuhh
Copy link

nahuhh commented Oct 5, 2024

If youre not using --public-node, youve likely posted your node's address publicly on a website like monero.fail.

you have a 194* ip using your RPC port and submitting bad blocks. You also have malicious node peers.

restart you nlde and add enable-dns-blocklist=1 and stop providing public rpc to strangers

@thilool
Copy link

thilool commented Oct 5, 2024

enable-dns-blocklist is always on on my node so this did not prevent the issue.
actually you where right. I posted the host, thinking I do something good... well lesson learned.
I changed my RPC port to something totally different out of spec just for my personal use from now on.

@nahuhh
Copy link

nahuhh commented Oct 5, 2024

162.218.65.219:18080

this node should have been blocked by the dns blocklist

@thisIsNotTheFoxUrLookingFor

monero | 2024-10-06 05:01:05.741 E Transaction not found in pool
monero | 2024-10-06 05:01:19.325 E mined block failed verification
monero | 2024-10-06 05:01:41.136 E mined block failed verification
monero | 2024-10-06 05:02:23.711 E mined block failed verification
monero | 2024-10-06 05:02:26.886 E Transaction not found in pool
monero | Oct 06 05:02:55.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
monero | 2024-10-06 05:03:04.664 E mined block failed verification
monero | Oct 06 05:03:07.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
monero | Oct 06 05:03:18.000 [notice] Closed 1 streams for service [scrubbed].onion for reason resolve failed. Fetch status: No more HSDir available to query.
monero | 2024-10-06 05:03:24.116 E mined block failed verification
monero | 2024-10-06 05:03:27.785 E mined block failed verification
monero | 2024-10-06 05:03:29.742 E mined block failed verification
monero | 2024-10-06 05:03:48.033 E mined block failed verification

@nahuhh
Copy link

nahuhh commented Oct 6, 2024

@thisIsNotTheFoxUrLookingFor
Copy link

thisIsNotTheFoxUrLookingFor commented Oct 6, 2024

162.218.65.219:18080

I have DNS blocklist set in my conf @nahuhh

I guess restart monerod will force new DNS query for blocklist

Shouldn't a peer be banned after submitting x bad blocks?

Just realised as they are pushing to RPC they are not a peer, I think DNS blocklist is going to ban P2P peers and this might be why it don't work in this case

@thisIsNotTheFoxUrLookingFor

At the same time the hashrate of my server drops about 1000Hs

Yah they are trying to DOS us by forcing constant block and TX verification I guess?

@nahuhh
Copy link

nahuhh commented Oct 6, 2024

162.218.65.219:18080

I have DNS blocklist set in my conf @nahuhh

The above ip is if a spy node peer. They arent the ones submitting the blocks

dns blocklist only works for p2p peers. The bad blocks are being submit via RPC.

I guess restart monerod will force new DNS query for blocklist

Shouldn't a peer be banned after submitting x bad blocks?

Those arent peers submitting bad blocks.

do you have disable-rpc-ban enabled?

please see my previous comment - disable public-node and stop providing a remote node for strangers.

@thisIsNotTheFoxUrLookingFor

The above ip is if a spy node peer. They arent the ones submitting the blocks

They should spy through Tor lol that is dumb of them

@thisIsNotTheFoxUrLookingFor

disable public-node and stop providing a remote node for strangers.

Probably they want this lol, I have the resources to absorb what they are doing so meh I can keep public RPC up

@Boog900
Copy link
Contributor

Boog900 commented Oct 6, 2024

I have been trying to think about what these nodes are trying to do, although just a general DOS attack would be a valid reason I find it weird how an entity like linking lion would want to do that.

Obviously I am not 100% certain but they could be trying to exploit a timing difference when handling a block to see if a node has a stem pool transaction. When we receive a block from RPC, we try to build the full block, including all the txs using our tx-pool:

block_complete_entry get_block_complete_entry(block& b, tx_memory_pool &pool)
{
block_complete_entry bce;
bce.block = cryptonote::block_to_blob(b);
bce.block_weight = 0; // we can leave it to 0, those txes aren't pruned
for (const auto &tx_hash: b.tx_hashes)
{
cryptonote::blobdata txblob;
CHECK_AND_ASSERT_THROW_MES(pool.get_transaction(tx_hash, txblob, relay_category::all), "Transaction not found in pool");
bce.txs.push_back({txblob, crypto::null_hash});
}
return bce;
}

As you can see we are using relay_category::all which means we are also pulling stem txs.

I did some rough tests submitting blocks to my own node with and without some unknown txs, when an unknown tx is included the response is around 50-100x faster.

I think an easy way to fix this would be to not look at the whole pool for restricted RPC.

FWIW this doesn't explain the other P2P messages/RPC requests that were happening around the same time. It would be good to get more log data if anyone has any.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

6 participants