Duplicate transaction reported by execute() when transaction was actually successful.
Description
When running the transaction tool to submit large numbers of transactions we have discovered that it is possible for the sdk to report a DUPLICATE_TRANSACTION even though the transaction went through.
Steps to reproduce
It is hard to reproduce.
If you try to submit hundreds of transactions very quickly, as txn tool does, you will likely hit this issue.
You can see it pretty regularly in failed transaction tool tests - https://github.com/hashgraph/hedera-transaction-tool-demo/runs/7826801854?check_suite_focus=true#step:8:50767
Additional context
Here is a transaction tool log file with DUPLICATE_TRANSACTION messages in it -
test.debug.log
And if you look up some of the transactions that it reports as dupes you see them as successful - https://hashscan.io/#/testnet/transaction/0.0.1865-1660314600-000700000?t=1660314606.004676003
It seems likely that the sdk is thinking the transaction timed out for whatever reason, when it actually got through, then retries and gets the duplicate.
Hedera network
mainnet, testnet, previewnet, other
Version
2.16.0
Operating system
macOS
- [ ] Fix maxBackoff
this probably helps
2022-08-15 14:05:05.914 [ 731] [pool-3-thread-40] INFO com.hedera.hashgraph.client.core.helpers.TransactionCallableWorker.process(TransactionCallableWorker.java:88) - Submitting transaction [email protected] to sdk
2022-08-15 14:05:05.931 [ 731] [pool-3-thread-40] TRACE com.hedera.hashgraph.sdk.Executable.getNodeForExecute(Executable.java:411) - Using node 0.0.3 for request #1: # com.hedera.hashgraph.sdk.proto.TransactionBody
2022-08-15 14:05:07.444 [ 731] [pool-3-thread-40] TRACE com.hedera.hashgraph.sdk.Executable$GrpcRequest.verboseLog(Executable.java:688) - Node IP 138.91.142.219 Timestamp 1660590307444 Transaction Type GrpcRequest
2022-08-15 14:05:07.541 [ 731] [pool-3-thread-40] TRACE com.hedera.hashgraph.sdk.Executable.lambda$new$1(Executable.java:91) - Sent protobuf 2aa8010a3e0a110a0a08dcb1ea970610f0e617120318c90e120218031880cab5ee01220308b401721a0a180a0a0a03188f08108084af5f0a0a0a0318c90e10ff83af5f12660a640a2005b1a211a49bb1b5bbdbd5f79bc0bf4edf4133cfb4b6023cde0ca57a79e53cdb1a40a7de30e37dae29d50b26e9c312aa6fe6a3c34c6ca6020bdbfa8bd119d38da82cf47c7217c3ffd7cf7c281859b5e333e8138d0ea34dd2035a544bc2b3cf1fbe01
2022-08-15 14:05:08.514 [ 731] [pool-3-thread-40] WARN com.hedera.hashgraph.sdk.Executable$GrpcRequest.shouldRetryExceptionally(Executable.java:628) - Retrying node 0.0.3 in 63999 ms after failure during attempt #1: UNAVAILABLE: RST_STREAM closed stream. HTTP/2 error code: REFUSED_STREAM
2022-08-15 14:05:08.520 [ 731] [pool-3-thread-40] TRACE com.hedera.hashgraph.sdk.Executable$GrpcRequest.verboseLog(Executable.java:688) - Node IP 138.91.142.219 Timestamp 1660590308520 Transaction Type GrpcRequest
2022-08-15 14:05:08.522 [ 731] [pool-3-thread-40] TRACE com.hedera.hashgraph.sdk.Executable.getNodeForExecute(Executable.java:411) - Using node 0.0.3 for request #2: # com.hedera.hashgraph.sdk.proto.TransactionBody
2022-08-15 14:07:16.521 [ 731] [pool-3-thread-40] TRACE com.hedera.hashgraph.sdk.Executable$GrpcRequest.verboseLog(Executable.java:688) - Node IP 138.91.142.219 Timestamp 1660590436521 Transaction Type GrpcRequest
2022-08-15 14:07:16.524 [ 731] [pool-3-thread-40] TRACE com.hedera.hashgraph.sdk.Executable.lambda$new$1(Executable.java:91) - Sent protobuf 2aa8010a3e0a110a0a08dcb1ea970610f0e617120318c90e120218031880cab5ee01220308b401721a0a180a0a0a03188f08108084af5f0a0a0a0318c90e10ff83af5f12660a640a2005b1a211a49bb1b5bbdbd5f79bc0bf4edf4133cfb4b6023cde0ca57a79e53cdb1a40a7de30e37dae29d50b26e9c312aa6fe6a3c34c6ca6020bdbfa8bd119d38da82cf47c7217c3ffd7cf7c281859b5e333e8138d0ea34dd2035a544bc2b3cf1fbe01
2022-08-15 14:07:16.731 [ 731] [pool-3-thread-40] TRACE com.hedera.hashgraph.sdk.Executable.lambda$new$2(Executable.java:95) - Received protobuf 080b
2022-08-15 14:07:16.732 [ 731] [pool-3-thread-40] TRACE com.hedera.hashgraph.sdk.Executable$GrpcRequest.getStatus(Executable.java:652) - Received DUPLICATE_TRANSACTION response in 0.0 s from node 0.0.3 during attempt #2: # com.hedera.hashgraph.sdk.proto.TransactionResponse@83522
2022-08-15 14:07:16.732 [ 731] [pool-3-thread-40] INFO com.hedera.hashgraph.client.core.helpers.TransactionCallableWorker.process(TransactionCallableWorker.java:107) - Worker: Transaction: [email protected], failed with error.
looks like it's getting a RST_STREAM closed stream that was actually successful, then DUPLICATE_TRANSACTION on retry