Promise never resolve or reject when submitting an invalid transaction

[mkazlauskas]

What Git revision / release tag are you using?

v6.0.0-rc4

Do you use any client SDK? If yes, which one?

TypeScript

Describe what the problem is?

When submitting an invalid transaction, websocket connection closes with { code: 1006 } Connection closed. Client is then indefinitely awaiting for some kind of response here.

What should be the expected behavior?

There are 2 issues:

1. connection shouldn't get closed
2. client should attempt to recover or reject with an error when the connection gets closed

If applicable, what are the logs from the server around the occurence of the problem?

{"severity":"Info","timestamp":"2023-10-26T10:29:16.405814196Z","thread":"823","message":{"WebSocket":{"contents":{"agency":"ServerAgency TokConfirm","event":"receive","tag":"AcceptVersion","version":"\"NodeToClientV_16\""},"tag":"WebSocketClient"}},"version":"v6.0.0 (62d21dd280a474b93ea9481c9d2a242ebe22ba63)"}
{"severity":"Info","timestamp":"2023-10-26T10:29:39.813155281Z","thread":"840","message":{"WebSocket":{"contents":{"agency":"ClientAgency TokIdle","event":"send","tag":"SubmitTx","tx":"d8185901aa84a400818258207b5c59e9ceb3cfdbc76abcf273c70fac40cf47a83e81fd4bcec86f5132b32310010182825839006b14497caa498ab472340e4be9551b9106f66173c26df827c82c62a8589d61522e295e37019428ddd3f7f2add39c6796a9b975d55ab605031a000f4240825839006b14497caa498ab472340e4be9551b9106f66173c26df827c82c62a8589d61522e295e37019428ddd3f7f2add39c6796a9b975d55ab605031b0000000253af8526021a0002a8dd048183118200581c04248787f28f9aa990bdbbb80411bb3625de3b0b5fa5562a15bb5b0600a10082825820cab519055ca2a0912560902f01a6e9c13a0807221cbd3ffdc1d239a0c3f678f658405cb096ec024ab5e79011e7bd19706690f331fe84b63c56c45c7899aad7a6772bd4a236061645160a50cb88b90d4a0e8b7a1b2e116df4aa48ee2591e7b6e63d0a8258205d859a83f3fb8de986c78c6ee9725ecf59b2b15137218b6a962615520932419158406291160fadc9682e69c0fb760ce2d7d3eb08c39e23ecea130b5841e66ac51cd74be66f2ce2b72b44e159516588e8fe7f85bcf3b9da92ee91091851fc1737e70af5f6"},"tag":"WebSocketClient"}},"version":"v6.0.0 (62d21dd280a474b93ea9481c9d2a242ebe22ba63)"}
[39a41f38:cardano.node.Mempool:Info:220] [2023-10-26 10:29:39.81 UTC] fromList [("err",Object (fromList [("badInputs",Array [String "7b5c59e9ceb3cfdbc76abcf273c70fac40cf47a83e81fd4bcec86f5132b32310#TxIx 1"]),("consumed",Object (fromList [("lovelace",Number 0.0),("policies",Object (fromList []))])),("error",String "This transaction consumed MaryValue 0 (MultiAsset (fromList [])) but produced MaryValue 9995120707 (MultiAsset (fromList []))"),("failure",Object (fromList [("credential",String "KeyHashObj (KeyHash \"04248787f28f9aa990bdbbb80411bb3625de3b0b5fa5562a15bb5b06\")"),("error",String "DRep is not registered"),("kind",String "ConwayDRepNotRegistered")])),("kind",String "ValueNotConservedUTxO"),("produced",Object (fromList [("lovelace",Number 9.995120707e9),("policies",Object (fromList []))]))])),("kind",String "TraceMempoolRejectedTx"),("mempoolSize",Object (fromList [("bytes",Number 0.0),("numTxs",Number 0.0)])),("tx",Object (fromList [("txid",String "9d0fd506")]))]
{"severity":"Error","timestamp":"2023-10-26T10:29:39.815390386Z","thread":"819","message":{"WebSocket":{"exception":"DecoderFailure (LocalTxSubmission (GenTx (HardForkBlock (': * ByronBlock (': * (ShelleyBlock (TPraos StandardCrypto) (ShelleyEra StandardCrypto)) (': * (ShelleyBlock (TPraos StandardCrypto) (AllegraEra StandardCrypto)) (': * (ShelleyBlock (TPraos StandardCrypto) (MaryEra StandardCrypto)) (': * (ShelleyBlock (TPraos StandardCrypto) (AlonzoEra StandardCrypto)) (': * (ShelleyBlock (Praos StandardCrypto) (BabbageEra StandardCrypto)) (': * (ShelleyBlock (Praos StandardCrypto) (ConwayEra StandardCrypto)) ('[] *)))))))))) (HardForkApplyTxErr (': * ByronBlock (': * (ShelleyBlock (TPraos StandardCrypto) (ShelleyEra StandardCrypto)) (': * (ShelleyBlock (TPraos StandardCrypto) (AllegraEra StandardCrypto)) (': * (ShelleyBlock (TPraos StandardCrypto) (MaryEra StandardCrypto)) (': * (ShelleyBlock (TPraos StandardCrypto) (AlonzoEra StandardCrypto)) (': * (ShelleyBlock (Praos StandardCrypto) (BabbageEra StandardCrypto)) (': * (ShelleyBlock (Praos StandardCrypto) (ConwayEra StandardCrypto)) ('[] *)))))))))) ServerAgency TokBusy) (DeserialiseFailure 15 \"Coin in Value: Expected a positive Coin. Got 0 (zero).\")","tag":"WebSocketUnknownException"}},"version":"v6.0.0 (62d21dd280a474b93ea9481c9d2a242ebe22ba63)"}
{"severity":"Info","timestamp":"2023-10-26T10:29:39.815523555Z","thread":"819","message":{"WebSocket":{"tag":"WebSocketConnectionEnded","userAgent":"User-Agent unknown"}},"version":"v6.0.0 (62d21dd280a474b93ea9481c9d2a242ebe22ba63)"}
[39a41f38:cardano.node.LocalErrorPolicy:Error:68] [2023-10-26 10:29:40.81 UTC] IP LocalAddress "/ipc/node.socket@10" ErrorPolicyUnhandledApplicationException (MuxError MuxBearerClosed "<socket: 45> closed when reading data, waiting on next header True")
[39a41f38:cardano.node.LocalErrorPolicy:Error:68] [2023-10-26 10:29:40.81 UTC] IP LocalAddress "/ipc/node.socket@11" ErrorPolicyUnhandledApplicationException (MuxError MuxBearerClosed "<socket: 46> closed when reading data, waiting on next header True")

[rhyslbw]

Quoting from the discussion we had in private @KtorZ:

It seems that there's a problem in the deserialization of the response coming from the node. The transaction is obviously wrong, but the decoders from network libs are failing for some reason. As if the node had produced an invalid serialized response. The error message says:

This transaction consumed MaryValue 0 (MultiAsset (fromList []))

And then, Ogmios handlers crashes with a DecoderFailure:

(DeserialiseFailure 15 \"Coin in Value: Expected a positive Coin. Got 0 (zero).\")

So it appears that the node is yielding a message with a 0-coin value, which cannot be deserialized. Obviously, the first message is violating some invariants on the ledger's side.
On Ogmios' side, it's not normal to not reject the promise accordingly. I don't why it's hanging here but it is most likely that the TypeScript client is (mistakenly) ignoring the fault response from the server instead of failing the promise with it. That, we should fix.

[mirceahasegan]

I request reopening the issue. It still reproduces with Ogmios 6.0.0-rc5 and this transaction cbor:
84a40081825820b69ae3404901b22ca88bdf53520bd8129d6cc2858a0ff10de44350814dabf7c601018282583900f7fa5ddf2c3c46ed4d913812d38dd43d585adfa884938adaa7a075dd1bf1e138f2f8beabc963c94cc28ee8ed4b41744601f2edaf50b21efd1a002dc6c082583900f7fa5ddf2c3c46ed4d913812d38dd43d585adfa884938adaa7a075dd1bf1e138f2f8beabc963c94cc28ee8ed4b41744601f2edaf50b21efd1b000000025104e928021a0002a98d048183078200581c1bf1e138f2f8beabc963c94cc28ee8ed4b41744601f2edaf50b21efd1a001e8480a1008182582005c7f4f3f949d0678171ae3a01f30b836b64d037f9e27377877e4c2db1dbeed45840eec07067ba2c10d20942c058db85607e48f7d6ad987dbe1586c7c16e6114dc1307d5af1179d45143990a277583c1e2ba6b3ff17fa453de589ed5955edeace00bf5f6.

Websocket closes.

The following error can be seen in ogmios/cardano-node logs:

[4b82a689:cardano.node.Mempool:Info:164] [2023-11-09 12:33:58.47 UTC] fromList [("err",Object (fromList [("badInputs",Array [String "b69ae3404901b22ca88bdf53520bd8129d6cc2858a0ff10de44350814dabf7c6#TxIx 1"]),("consumed",Object (fromList [("lovelace",Number 0.0),("policies",Object (fromList []))])),("error",String "This transaction consumed MaryValue 0 (MultiAsset (fromList [])) but produced MaryValue 9952385397 (MultiAsset (fromList []))"),("failure",Object (fromList [("amount",Number 2000000.0),("error",String "Incorrect deposit amount"),("kind",String "IncorrectDepositDELEG")])),("kind",String "MissingVKeyWitnessesUTXOW"),("missingWitnesses",Array [String "1bf1e138f2f8beabc963c94cc28ee8ed4b41744601f2edaf50b21efd"]),("produced",Object (fromList [("lovelace",Number 9.952385397e9),("policies",Object (fromList []))]))])),("kind",String "TraceMempoolRejectedTx"),("mempoolSize",Object (fromList [("bytes",Number 0.0),("numTxs",Number 0.0)])),("tx",Object (fromList [("txid",String "811cb8e7")]))]
{"severity":"Error","timestamp":"2023-11-09T12:33:58.477929759Z","thread":"279","message":{"WebSocket":{"exception":"DecoderFailure (LocalTxSubmission (GenTx (HardForkBlock (': * ByronBlock (': * (ShelleyBlock (TPraos StandardCrypto) (ShelleyEra StandardCrypto)) (': * (ShelleyBlock (TPraos StandardCrypto) (AllegraEra StandardCrypto)) (': * (ShelleyBlock (TPraos StandardCrypto) (MaryEra StandardCrypto)) (': * (ShelleyBlock (TPraos StandardCrypto) (AlonzoEra StandardCrypto)) (': * (ShelleyBlock (Praos StandardCrypto) (BabbageEra StandardCrypto)) (': * (ShelleyBlock (Praos StandardCrypto) (ConwayEra StandardCrypto)) ('[] *)))))))))) (HardForkApplyTxErr (': * ByronBlock (': * (ShelleyBlock (TPraos StandardCrypto) (ShelleyEra StandardCrypto)) (': * (ShelleyBlock (TPraos StandardCrypto) (AllegraEra StandardCrypto)) (': * (ShelleyBlock (TPraos StandardCrypto) (MaryEra StandardCrypto)) (': * (ShelleyBlock (TPraos StandardCrypto) (AlonzoEra StandardCrypto)) (': * (ShelleyBlock (Praos StandardCrypto) (BabbageEra StandardCrypto)) (': * (ShelleyBlock (Praos StandardCrypto) (ConwayEra StandardCrypto)) ('[] *)))))))))) ServerAgency TokBusy) (DeserialiseFailure 54 \"Coin in Value: Expected a positive Coin. Got 0 (zero).\")","tag":"WebSocketUnknownException"}},"version":"v6.0.0 (c5bbfdadf32694132e676b6b6a0a6841c49aeba1)"}
{"severity":"Info","timestamp":"2023-11-09T12:33:58.478035352Z","thread":"279","message":{"WebSocket":{"tag":"WebSocketConnectionEnded","userAgent":"User-Agent unknown"}},"version":"v6.0.0 (c5bbfdadf32694132e676b6b6a0a6841c49aeba1)"}
ConnectionClosed
[4b82a689:cardano.node.LocalErrorPolicy:Error:70] [2023-11-09 12:33:59.48 UTC] IP LocalAddress "/ipc/node.socket@8" ErrorPolicyUnhandledApplicationException (MuxError MuxBearerClosed "<socket: 130> closed when reading data, waiting on next header True")
[4b82a689:cardano.node.LocalErrorPolicy:Error:70] [2023-11-09 12:33:59.48 UTC] IP LocalAddress "/ipc/node.socket@7" ErrorPolicyUnhandledApplicationException (MuxError MuxBearerClosed "<socket: 129> closed when reading data, waiting on next header True")

[KtorZ]

Yes. That is expected. And the promise on the client side should also have been rejected? This error is actually a bug from the node / ledger, so there's nothing Ogmios can really do to mitigate it. So failing is the expected behavior. Yet, that failure should bubble down to the client handlers and it wasn't the case.

[mirceahasegan]

The failure doesn't bubble down. This is my test script and run output:

➜  testSubmitter cat testSubmitter.ts
const { TransactionSubmission, createInteractionContext } = require('@cardano-ogmios/client');

(async () => {
  const context = await createInteractionContext(
    (err) => {
      console.log('error', err);
    },
    (reason) => {
      console.log('context disconnected', reason);
    },
    {
      connection: {
        host: 'localhost',
        port: 1341
      }
    }
  );
  const txClient = await TransactionSubmission.createTransactionSubmissionClient(context);
  const result = await txClient.submitTransaction(
    '84a40081825820b69ae3404901b22ca88bdf53520bd8129d6cc2858a0ff10de44350814dabf7c601018282583900f7fa5ddf2c3c46ed4d913812d38dd43d585adfa884938adaa7a075dd1bf1e138f2f8beabc963c94cc28ee8ed4b41744601f2edaf50b21efd1a002dc6c082583900f7fa5ddf2c3c46ed4d913812d38dd43d585adfa884938adaa7a075dd1bf1e138f2f8beabc963c94cc28ee8ed4b41744601f2edaf50b21efd1b000000025104e928021a0002a98d048183078200581c1bf1e138f2f8beabc963c94cc28ee8ed4b41744601f2edaf50b21efd1a001e8480a1008182582005c7f4f3f949d0678171ae3a01f30b836b64d037f9e27377877e4c2db1dbeed45840eec07067ba2c10d20942c058db85607e48f7d6ad987dbe1586c7c16e6114dc1307d5af1179d45143990a277583c1e2ba6b3ff17fa453de589ed5955edeace00bf5f6'
  ).catch(err => console.log('error in txClient.submitTransaction', err));
  console.log('Submitted:', result);
})()
  .then(() => console.log('tx sent'))
  .catch((error) => console.log('error', error));
➜  testSubmitter                     
➜  testSubmitter 
➜  testSubmitter node testSubmitter.ts
context disconnected 1006
➜  testSubmitter 

And this is the ogmios version running:

{"severity":"Info","timestamp":"2023-11-09T12:19:12.070896154Z","thread":"5","message":{"Configuration":{"networkParameters":{"networkMagic":4,"slotsPerEpoch":4320,"systemStart":"2023-06-15T00:30:00Z"}}},"version":"v6.0.0 (c5bbfdadf32694132e676b6b6a0a6841c49aeba1)"}