ArdanaLabs / dUSD

5 stars 3 forks source link

Flaky `Error: (AtKey "SubmitSuccess" MissingValue)` #257

Closed Geometer1729 closed 2 years ago

Geometer1729 commented 2 years ago

Lots of tests seem to be flaky with Error: (AtKey "SubmitSuccess" MissingValue). I've received some guidance from ctl and will track anything I learn here and hopefully make a pr fixing it at some point.

Geometer1729 commented 2 years ago

This seems to be the ultimate error (white-space added for readability)

[DEBUG] 2022-07-27T17:00:53.706Z message: 
    {"type":"jsonwsp/response"
    ,"version":"1.0"
    ,"servicename":"ogmios"
    ,"methodname":"SubmitTx"
    ,"result":
        {"SubmitFail":
            [{"valueNotConserved":
                {"consumed":{"coins":0,"assets":{}}
                ,"produced":{"coins":16700858,"assets":{}}}}
                ,{"badInputs":
                    [ {"txId":"70a2cfa56fe3086b02e2a1b9b38744a44cbe4a18ca843678348b01739119d72d"
                        ,"index":0
                        }
                        ,{"txId":"70a2cfa56fe3086b02e2a1b9b38744a44cbe4a18ca843678348b01739119d72d" ,"index":1 }
                        ,{"txId":"883a51401e327320fc9fc3aed5695382fb9085736c6b80abd153f38800b25c6c" ,"index":1 }
                        ,{"txId":"9c1503e05dc495decb1a44d5d8a678a8c3343d2f5ab3e9cc3a2652a1639efde8" ,"index":1 }
                        ,{"txId":"b120ee214bb721c0a9b8417b83106069c3869f7aec53ac44a5cb4f6b7e2d94aa" ,"index":0 }
                        ,{"txId":"b120ee214bb721c0a9b8417b83106069c3869f7aec53ac44a5cb4f6b7e2d94aa","index":1}
                        ,{"txId":"d235fbbf636ab3bc7d8127f7ef2d1f079c84c66efab3f4a837376201b5f9e737","index":0}
                     ]
                    }
            ]
        }
    ,"reflection":"SubmitTx-ek76njiwl63usfns"}
Geometer1729 commented 2 years ago

May also be relevant

[TRACE] 2022-07-27T17:00:53.701Z Input Value: (Value (Coin (fromString "16700858")) (NonAdaAsset (fromFoldable [])))
   Post-balancing Tx :
[TRACE] 2022-07-27T17:00:53.701Z Output Value: (Value (Coin (fromString "16516833")) (NonAdaAsset (fromFoldable [])))
   Post-balancing Tx :
[TRACE] 2022-07-27T17:00:53.701Z Fees: (Coin (fromString "184025"))
   Post-balancing Tx :
[DEBUG] 2022-07-27T17:00:53.705Z sending: 
    {"args":
        {
                "submit":"84a6008782582070a2cfa56fe3086b02e2a1b9b38744a44cbe4a18ca843678348b01739119d72d0082582070a2cfa56fe3086b02e2a1b9b38744a44cbe4a18ca843678348b01739119d72d01825820883a51401e327320fc9fc3aed5695382fb9085736c6b80abd153f38800b25c6c018258209c1503e05dc495decb1a44d5d8a678a8c3343d2f5ab3e9cc3a2652a1639efde801825820b120ee214bb721c0a9b8417b83106069c3869f7aec53ac44a5cb4f6b7e2d4aa00825820b120ee214bb721c0a9b8417b83106069c3869f7aec53ac44a5cb4f6b7e2d94aa01825820d235fbbf636ab3bc7d8127f7ef2d1f079c84c66efab3f4a837376201b5f9e7370001838258390032c4b6fc3be50dcae2b24ffb599418ba5beacfe6afb7386f1f98492cb28a63eaf55dffdf7c69823774cf43a6f378afda89e50142a9b44dc11a0054a44b8258390032c4b6fc3be50dcae2b24ffb599418ba5beacfe6afb7386f1f98492cb28a63eaf55dffdf7c69823774cf43a6f378afda89e50142a9b44dc11a000ecc1683581d706dc2de603b85a27c1ba67be6904424c946d99d18f7fddf67bfa0e1ee1a00989680582003170a2e7597b7b7e3d84c05391d139a62b157e78786d8c082f29dcf4c111314021a0002ced90b5820246518e1f9b98a522fbd88b03611ef9201b35f2ffbb822c74da94aa0295ffad60d81825820d2625ff48a8ac076b8df0f4e90cb6444d5f68a03bab68c8db2e11a9dd48579c0000f00a30081825820957d1ef939ba7e8f4334037eef9c50c6c401c2e0b22281d0c321d4a9c3549c335840534e55d83fea3de4d47ec80a7d044278d1443989ccc899327d159b7180a2ab172f22251debca52cebed7a2e7d9c1e215d34fc3d89d9db959d5d9d8d7e908e90f049f00ff0580f5f6"
        }
        ,"methodname":"SubmitTx"
        ,"mirror":"SubmitTx-ek76njiwl63usfns"
        ,"servicename":"ogmios"
        ,"type":"jsonwsp/request"
        ,"version":"1.0"
    }
Geometer1729 commented 2 years ago

The amount produced is exactly the input so this would be consistent with the input being dropped

Geometer1729 commented 2 years ago

I got a new one:

[DEBUG] 2022-07-27T17:51:16.463Z message: 
    {"type":"jsonwsp/response"
    ,"version":"1.0"
    ,"servicename":"ogmios"
    ,"methodname":"SubmitTx"
    ,"result":
        {"SubmitFail":
            [{"badInputs":
                [
                    {"txId":"823345f8bb1d3467846cfb68fcd578a2fe2cf55d59bc3b986cc825748c153f51" ,"index":0}
                ]
             }
            ,{"missingCollateralInputs":null}
            ,{"collateralTooSmall":{"requiredCollateral":288074,"actualCollateral":0}}
            ]
        }
    ,"reflection":"SubmitTx-ek76nky2l63wl819"
    }
Geometer1729 commented 2 years ago

And this

[DEBUG] 2022-07-27T17:54:17.176Z message: 
    {"type":"jsonwsp/response"
    ,"version":"1.0"
    ,"servicename":"ogmios"
    ,"methodname":"SubmitTx"
    ,"result":
        {"SubmitFail":
            [
                {"collectErrors":
                    [
                        {"badTranslation":"Unknown transaction input (missing from UTxO set): 5f6b3594128b8515612fd97343dd0a4b7e14d19635f4f969195ce8808b06db45#0"}
                    ]
                }
            ,{"valueNotConserved":
                {"consumed":{"coins":10000000,"assets":{}}
                ,"produced":{"coins":14633516,"assets":{}}}
             }
            ,{"badInputs":
                [{"txId":"5f6b3594128b8515612fd97343dd0a4b7e14d19635f4f969195ce8808b06db45","index":0}]
                }
            ]
        }
    ,"reflection":"SubmitTx-ek76no9el63wp3h2"
    }

The error rate seems to be much higher when running more than one test at the same time.

Geometer1729 commented 2 years ago

AFAICT the root cause is likely a utxo being spent by another transaction between the balance and submit phase.