Help me with error messages

Dear friends,
Does anybody know anything about this error masseges?
I’m getting them after upgrading to 1.2.8


PLEASE HELP.

Warning not error, looks like normal full node chatter to me.

1 Like

Thank you for your time.:pray:

I’ve never seen these warnings and I’m constantly searching them for the last week.
But I’ve not updated to 1.2.8 yet.
Maybe there is now a check on how long block validation and add spendbubble takes.

1 Like

I get the same warnings at the passage of 1.2.8. in the change log it explains the addition of the new warning but I don’t understand what it consists of and how to improve to prevent it from happening

1 Like

As its so new, I think this will take time to figure out, no one has probably paid attention before.

1 Like

With 1.2.8 & 1.2.9 I getting these (and more) warnings/errors regularly. Some are repeats from earlier, some not. It’s the ERRORS and newly occurring WARNINGS I worry about mostly. { I’ve added blank lines for readability’s sake.}

To be clear, I don’t mind legitimate log entries that inform/help me correct issues, but it seems that with each release we see new entry types that nothing in the chia docs, that I can find (via Google), offers more than the fact they exist, no simple explanation of the meaning, no tips to correct/eliminate them.

Perhaps the devs want to keep such information priestly, I have no idea. It simply makes for a mess of the logs and diminished their usefulness greatly, while causing consternation amongst users. We need logging that is pertinent and useful, not frustratingly mystifying. At this point in this project, someone on the dev team should be tasked with cleaning this mess up.

How is that not an obvious requirement is beyond me. (including devs who know/use the dev tools daily) ???

End rant.

++++++++++++++++++++++++++

2021-10-01T19:38:16.374 full_node chia.full_node.mempool_manager: WARNING add_spendbundle b3c642d49ba46764be470646f1a60858521c4… took 1.00 seconds. Cost: 1054463529 (9.586% of max block cost)

2021-10-01T19:46:52.232 full_node full_node_server : ERROR Exception: Error short batch syncing, could not fetch block at height 939098, {‘host’: ‘118.XX.XX.219’, ‘port’: 16664}. Traceback (most recent call last):
File “chia\server\server.py”, line 559, in wrapped_coroutine
File “chia\full_node\full_node_api.py”, line 115, in new_peak
File “chia\full_node\full_node.py”, line 436, in new_peak
File “chia\full_node\full_node.py”, line 270, in short_sync_batch
ValueError: Error short batch syncing, could not fetch block at height 939098

2021-10-01T19:46:52.234 full_node full_node_server : ERROR Exception: Error short batch syncing, could not fetch block at height 939098 <class ‘ValueError’>, closing connection {‘host’: ‘118.XX.XX.219’, ‘port’: 16664}. Traceback (most recent call last):
File “chia\server\server.py”, line 569, in api_call
File “asyncio\tasks.py”, line 442, in wait_for
File “chia\server\server.py”, line 566, in wrapped_coroutine
File “chia\server\server.py”, line 559, in wrapped_coroutine
File “chia\full_node\full_node_api.py”, line 115, in new_peak
File “chia\full_node\full_node.py”, line 436, in new_peak
File “chia\full_node\full_node.py”, line 270, in short_sync_batch
ValueError: Error short batch syncing, could not fetch block at height 939098

2021-10-01T20:00:56.507 full_node chia.full_node.mempool_manager: WARNING add_spendbundle b0f5fcd2ec312bf443f615c973b0196b… took 1.82 seconds. Cost: 2659722890 (24.179% of max block cost)

2021-10-01T20:00:56.993 full_node chia.full_node.full_node: WARNING Block validation time: 2.27 seconds, cost: 2146642050, percent full: 19.515%

2021-10-01T20:07:09.481 full_node chia.full_node.mempool_manager: WARNING add_spendbundle 098584e3b4ad0216d087bf9361f000… took 1.43 seconds. Cost: 1526719683 (13.879% of max block cost)

ValueError: Failed to fetch block 939186 from {‘host’: ‘183.XX.XX.244’, ‘port’: 8444}, timed out

1 Like

So it appears that you get the WARNING immediately after the, “ValueError: Error short batch syncing”. I found reference to short batch syncing at Chia Github:

the end of which says, "

loppefaaret 19 days ago

Collaborator

every now and then, an error happens, it can be the peer that you have requested data from crashed, lost internet, or just plain closed down chia - you will see this on your side - as long as it is a “short sync” error - your node is relative close to being on the peak height of the chain - it will try and get the block from another peer…"

The fact that you get the WARNING is probably just indication of the fact that it did get the block from another peer after the short batch sync error and it took longer than is usual (because it got the block from a second peer).

I don’t think you have a problem.

2 Likes

I get that, but it all carries on as it should.

Based on the answer provided by loppefaret, I don’t think that condition warrants an error. The node is still healthy, and potentially just one of the peers have some issues. The node is potentially still in the loop of enumerating peers for data, so until that loop is exhausted, everything is fine on the node side (that is how P2P works). It is more like informing me that some peer that I don’t know and don’t care about potentially went belly up, instead of silently moving on to the next peer as the protocol specifies.

However, once the loop is exhausted, and all peers are not accessible, that would indicate some local issues. Although, at this point the error should state that potentially it is isolated, as it cannot contact any peers, so situation is most likely serious.

Therefore, the question is whether that end of the loop error will be issued / exists, or we need to somehow infer whether the loop got exhausted. Not knowing that makes us get tired of that error, and ignore it in the future, when potentially it could indicate a real problem.

By the way, I have added a comment to that error description on github, asking to remove that error completely, as how it is being described it is just code not handling an expected condition, and basically barfing, thus spitting irrelevant info.

2 Likes

All very interesting. Hope someone gets to the bottom of it. Thanks for the explanation.

Out of curiosity, a new warming that I’ve only seen since this release, or at least I think so. The ‘add_spendbundle … took xxxx seconds. Cost: xxxx’ is what’s I’m curious about, as below:

2021-10-01T19:38:16.374 full_node chia.full_node.mempool_manager: WARNING add_spendbundle b3c642d49ba46764be470646f1a60858521c4… took 1.00 seconds. Cost: 1054463529 (9.586% of max block cost)

PS. I must have 70 of these warnings repeated one after another in my log right now with minor warnings interspersed occasionally. If only spendbundle were XCH!

Maybe one thing that we could ask Chia is to redo how they handle those logs messages. Currently, everything is kind of how it should be, before hitting end users. However, once you hit end users, there is an orthogonal dimension for those messaged, i.e., end-user level messages. Those also carry all the levels (error, warning, …), but may not be the same thing. What is really relevant to the engineer may have no value to the end user (but not vice versa). It is usually done by adding a property to those messages (e.g., eng, user, or both). Having that property is useful to filter out irrelevant issues on the client side (e.g., through config.yaml, so if needed the full logs will be there).

That sounds not only practical for clearing up the logs for users, but a damn great idea! Seems simple, add a secondary USER/ENG parameter allowing limiting entries to ones that deserve attention on our end.

1 Like

I don’t think loppefaaret’s response explains 70 errors in a row. What he described should happen now and then. If it is happening constantly it has nothing to do with dropping the occasional peer.

1 Like

Does seem a tad excessive, and I could certainly post the log, but don’t believe that helps (unless you want to see). Very much like the OPs log, except I do not have interspersed response time warnings.

What I notice is that these entries are (except for 17 other WARNINGS like “banning for 10 seconds”, and “invalid handshake” and 1 ERROR, those 70 entires are the only entries in my logs between the hours of 2021-10-01T22:04:07.937 and 2021-10-03T01:58:30.966

Since that burst, until right now I have only 10 more in my log, so it was a BURST of them, then it let up.

But for starters > what for heavens sake is " WARNING add_spendbundle b3c642d49ba46764be470646f1a60858521c4… took 1.00 seconds. Cost: 1054463529 (9.586% of max block cost)"?

Do you or anyone have any explanation for what the heck is the cause and the reason for this string of words/numbers? It is only since the latest upgrade and It looks like gibberish to me, like someone who does doubletalk, IOW say much without saying anything. Google so far is useless on answers. I do see some others are asking similar questions, but no answers.

2 Likes

I can only give my amateur analysis from reading the logs.

It appears to me, add spendbubble has to to with the mem pool, and are coins being requested to be sent.(transaction requests, so maybe also smart contract data ).

Now normally my machine will do this in a miniscule fraction of a second.

I think / assume a warning was added in latest version that monitors those times ( was iirc confirmed to have been in the list of new additions / changes ).

It seems anything over 1 sec will throw out the warning.

What impact this would have on minting a block I have no clue, I would assume you could still mint a block fine, but that transaction would not be included.

Those are interesting thoughts, esp. the over 1 sec throws a WARNING remark. But why? My farmer has 6c/12t AMD CPU and is setting here as I watch each thread’s activity, they are all basically idling, with a composite total of 3-14% in task mgr.

Most disks are USB 3.0, couple USB 2, couple SATA. Response times are between less than .5 sec and less than .25 sec, with rare moments (literally taking a second or so) showing response times > 5sec. Then w/1Gb fiber internet connection, which is pretty speedy, what can be the slowdown, if there is one. Somewhere else, someone else? Curious minds want to know.

I have literally no clue why they’re normally supetfast and sometimes not.

I’ve yet to update as trying to fix other issues and don’t want to complicate matters.

I am afraid you will have to travel to Keybase Chia Team support and post your question there. I’d bet on you having at least some answers within hours.

Good thought, had the same one. Unfortunately, currently, can’t get Keybase to start. Try to …zip So …uninstall, reinstall, zip. Google notes similar Keybase behavior. It’s a mystery.

add_spendbundle will have to wait and so continue.

1 Like