Tracelistener bug: invalid UTF-8 sequence

[Pitasi]

It happened on the Iris chain in prod that a transaction couldn't be executed because of an "invalid UTF-8 sequence".

Original slack thread reporting this: https://allinbits.slack.com/archives/C02AXJ0K9F1/p1652956514666829.

Error log:

{"error": "transaction named exec error, ERROR: error in argument for $4: invalid UTF-8 sequence (SQLSTATE 22021)", "statement": "\n\t\tINSERT INTO tracelistener.balances (height, chain_name, address, amount, denom)\n\t\tVALUES (:height, :chain_name, :address, :amount, :denom)\n\t\tON CONFLICT (chain_name, address, denom)\n\t\tDO UPDATE\n\t\tSET delete_height = NULL, height = EXCLUDED.height, chain_name = EXCLUDED.chain_name, address = EXCLUDED.address, amount = EXCLUDED.amount, denom = EXCLUDED.denom\n\t\tWHERE tracelistener.balances.height < EXCLUDED.height\n\t", "type": "Write", "data": "[{{iris 0 14988570 <nil>}  0\u0000\u0000\u0000\u0000䵊o\u0000\ufffd\ufffd\ufffdxo\ufffdZ\ufffdU\ufffd%\ufffd@\ufffdb)\ufffd7]\ufffdX\ufffd\ufffd\ufffd\u001cX\ufffd̥} \u0000\u0000\u0000\u0000䵊o\u0000\ufffd\ufffd\ufffdxo\ufffdZ\ufffdU\ufffd%\ufffd@\ufffdb)\ufffd7]\ufffdX\ufffd\ufffd\ufffd\u001cX\ufffd̥}} {{iris 0 14988570 <nil>} dc6f17bbec824fff8f86587966b2047db6ab7367 0uiris uiris} {{iris 0 14988570 <nil>} f1829676db577682e944fc3493d451b67ff3e29f 295802uiris uiris} {{iris 0 14988570 <nil>} 29011f69ba31ca74d59cc9f460b840c7d0a446c1 155759820htltbcbnb htltbcbnb} {{iris 0 14988570 <nil>} ef8c49cab8ca567b21b21ead803e0ff1238c13ba 0htltbcbnb htltbcbnb} {{iris 0 14988570 <nil>} 93354845030274cd4bf1686abd60ab28ec52e1a7 169484403995540uiris uiris} {{iris 0 0 <nil>}   } {{iris 0 14988570 <nil>} 5e160259c621023afa9b6cda78db1aac564c7751 235518183uiris uiris} {{iris 0 14988570 <nil>} 29011f69ba31ca74d59cc9f460b840c7d0a446c1 95601759497uiris uiris} {{iris 0 14988570 <nil>} 97277b36fceed6d147b7d369b4874e2c0dbfbb23 33050000uiris uiris}]"}

DoD

• Capture traces from Iris: runbook (capture traces until able to reproduce the error locally)
• Isolate the trace causing the problem, add an unit test for it
• Fix the bug :) (if that string can be handled: fine, otherwise we might decide to discard denoms that are not UTF-8 strings?)

[tbruyelle]

OK it appears EmerisHQ/tracelistener#127 did not fix the issue (we realized that with Dor when I was presenting the change!).

Indeed in case of a write operation and an unmarshal error on sdk.Coin, it's not possible to insert invalid UTF-8 characters because the row contains only empty values. That said the fix is still relevant I think, because it probably avoids upsert with no rows (a common error in the logs).

We found the root cause of invalid UTF-8 characters, it's a trace representing a delete operation of a custom iris mod, that is wrongly interpreted as a bank balance trace in the TL. In a real delete bank balance trace, the value is empty, so we have a specific case to retrieve the denom from key, while we used to read it from the value for write operation. But since the trace is actually not a balance key, the key doesn't contain the denom, and so the sdk.Coin.Denom receives random bytes that are not UTF-8.

We need to discuss about a fix. I have some ideas:

• Reinforce the module selection by adding more checks than just the 0x02 prefix. Could be something like what has been done in the cw20 module [0]
• Always read the denom from the key, and no longer from the value. This merges the actual 2 different ways of reading the denom between write and delete operation. This is also a first step to handle a breaking change coming in cosmos-sdk 0.46 about balance value [1]

[0] https://github.com/EmerisHQ/tracelistener/blob/7da0f0e8c763fa81bb84c790f1cfccc638df47b0/tracelistener/processor/cw20_balance.go#L74-L77
[1] cosmos/cosmos-sdk#9832