Nonce incremented when retrying a transaction due to gas price policy

[kdziurdz]

Describe the bug

When retry policy is triggerred then new transaction is broadcasted with incremented nonce.

Configuration

It happens in Helm, prod-like configuration as well as Orchestrate suite running locally with docker-compose. Also nonce manager redis/in-memory does not take an effect. Same as setting tx idempotency key

1 Short retry policy & low tx priority

Chain configuration:

{ depth: 0, backoffDuration: '10s'}

Gas price policy

{
  priority: Priority.VeryLow,
  retryPolicy: 
    {interval: '20s', increment: 0.05, limit: 0.15}
}

2 Long chain listener backoff value & high tx priority

Chain configuration:

{ depth: 0, backoffDuration: '3m'}

Gas price policy

{
  priority: Priority.VeryHigh,
  retryPolicy: 
    {interval: '1m', increment: 0.05, limit: 0.15}
}

-->

Steps to reproduce

1. Deploy a smart contract with an idempotent function exposed, lets say setGreeter(string memory newGreeting)
2. Apply chain configuration 1 or 2
3. Create transaction invoking mentioned function with setting up retry policy accordingly to selected chain configuration.
4. Observe blockchain transactions.

Actual result

For both configurations, result is same. Namely tx-sender retries signing and sending transactions with incremented nonce.

This results in mining more than one transaction. Tx-Sender stops retrying after tx with lowest nonce gets finally mined.

Expected result

Retry policy should resend very same transaction with very same nonce with higher priority / gas price.

It would result in

• faster transaction mining
• ensuring only one tx will be mined.

Additional context

Machine Setup

• Binary version
• OS (Linux, Windows...)

Logs

Tx-Sender log:

time="2023-04-03T18:51:50Z" level=debug msg="(broker.sarama.producer): client/metadata fetching metadata for all topics from broker kafka:29092\n"
time="2023-04-03T18:51:55Z" level=debug msg="(service.kafka-consumer): message consumed" consumer=c-0 envelope_id=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 timestamp="2023-04-03 18:51:55.069 +0000 UTC"
time="2023-04-03T18:51:55Z" level=debug msg="(use-cases.send-eth-tx): processing ethereum transaction job" consumer=c-0 job=ebe731a6-98c4-434b-8614-287d00cd7dc8 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:51:55Z" level=debug msg="(use-cases.craft-transaction): crafted dynamic fees" base=8 consumer=c-0 job=ebe731a6-98c4-434b-8614-287d00cd7dc8 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= tip=500000000
time="2023-04-03T18:51:55Z" level=debug msg="(use-cases.craft-transaction): crafted gas estimation" consumer=c-0 job=ebe731a6-98c4-434b-8614-287d00cd7dc8 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= value=0xc000e02740
time="2023-04-03T18:51:55Z" level=debug msg="(nonce-manager): calibrating nonce" consumer=c-0 job=ebe731a6-98c4-434b-8614-287d00cd7dc8 owner_id= pending_nonce=31 schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:51:55Z" level=debug msg="(use-cases.craft-transaction): crafted transaction nonce" consumer=c-0 job=ebe731a6-98c4-434b-8614-287d00cd7dc8 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= value=0xc000948878
time="2023-04-03T18:51:55Z" level=debug msg="(use-cases.sign-eth-transaction): ethereum transaction signed successfully" consumer=c-0 job=ebe731a6-98c4-434b-8614-287d00cd7dc8 one_time_key=false owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= tx_hash=0x1060ab4dcd46098917173725b32bd25c9ce082044a7f9c35061c61a965f9aee9
time="2023-04-03T18:51:55Z" level=debug msg="(use-cases.send-eth-tx): job status was updated successfully" consumer=c-0 job=ebe731a6-98c4-434b-8614-287d00cd7dc8 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 status=PENDING tenant_id=
time="2023-04-03T18:51:56Z" level=debug msg="(nonce-manager): increment account nonce value" consumer=c-0 job=ebe731a6-98c4-434b-8614-287d00cd7dc8 last_sent=31 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:51:56Z" level=info msg="(use-cases.send-eth-tx): ethereum transaction job was sent successfully" consumer=c-0 job=ebe731a6-98c4-434b-8614-287d00cd7dc8 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:51:56Z" level=debug msg="(service.kafka-consumer): job message has been processed" consumer=c-0 job=ebe731a6-98c4-434b-8614-287d00cd7dc8 schedule=9d55928c-3d33-4f9e-a99b-30a9eff9dc03
time="2023-04-03T18:52:17Z" level=debug msg="(service.kafka-consumer): message consumed" consumer=c-0 envelope_id=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 timestamp="2023-04-03 18:52:17.428 +0000 UTC"
time="2023-04-03T18:52:17Z" level=debug msg="(use-cases.send-eth-tx): processing ethereum transaction job" consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:52:17Z" level=debug msg="(use-cases.craft-transaction): crafted dynamic fees" base=7 consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= tip=525000000
time="2023-04-03T18:52:17Z" level=debug msg="(use-cases.craft-transaction): crafted gas estimation" consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= value=0xc000dd0380
time="2023-04-03T18:52:17Z" level=debug msg="(use-cases.sign-eth-transaction): ethereum transaction signed successfully" consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 one_time_key=false owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= tx_hash=0x6600dce6bae549de363116427f4129bd3749f775614b59d621ceabd14b6c249a
time="2023-04-03T18:52:17Z" level=debug msg="(use-cases.send-eth-tx): job status was updated successfully" consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 status=PENDING tenant_id=
time="2023-04-03T18:52:18Z" level=error msg="(use-cases.send-eth-tx): cannot send raw ethereum transaction" consumer=c-0 error="BE001@ethclient.rpc: code: -32000 - message: nonce too low" job=77685c13-f863-436e-8cff-4829167a47b7 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:52:18Z" level=warning msg="(nonce-manager): chain responded with invalid nonce error" consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:52:18Z" level=debug msg="(service.kafka-consumer): job status was updated successfully" consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 schedule=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 status=RECOVERING
time="2023-04-03T18:52:18Z" level=warning msg="(service.kafka-consumer): error processing job, retrying in [625.056818ms]..." consumer=c-0 error="01300@use-cases.send-eth-tx: BE001@ethclient.rpc: code: -32000 - message: nonce too low" job=77685c13-f863-436e-8cff-4829167a47b7 schedule=9d55928c-3d33-4f9e-a99b-30a9eff9dc03
time="2023-04-03T18:52:18Z" level=debug msg="(use-cases.send-eth-tx): processing ethereum transaction job" consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:52:18Z" level=debug msg="(use-cases.craft-transaction): crafted transaction nonce" consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= value=0xc000e02178
time="2023-04-03T18:52:18Z" level=debug msg="(use-cases.sign-eth-transaction): ethereum transaction signed successfully" consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 one_time_key=false owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= tx_hash=0x66a22a0b6ced32e397ca4264ba437609fb54448d38ae882e647bccb309a2a80f
time="2023-04-03T18:52:18Z" level=debug msg="(use-cases.send-eth-tx): job status was updated successfully" consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 status=PENDING tenant_id=
time="2023-04-03T18:52:19Z" level=debug msg="(nonce-manager): increment account nonce value" consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 last_sent=32 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:52:19Z" level=info msg="(use-cases.send-eth-tx): ethereum transaction job was sent successfully" consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:52:19Z" level=debug msg="(service.kafka-consumer): job message has been processed" consumer=c-0 job=77685c13-f863-436e-8cff-4829167a47b7 schedule=9d55928c-3d33-4f9e-a99b-30a9eff9dc03
time="2023-04-03T18:52:37Z" level=debug msg="(service.kafka-consumer): message consumed" consumer=c-0 envelope_id=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 timestamp="2023-04-03 18:52:37.432 +0000 UTC"
time="2023-04-03T18:52:37Z" level=debug msg="(use-cases.send-eth-tx): processing ethereum transaction job" consumer=c-0 job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:52:37Z" level=debug msg="(use-cases.craft-transaction): crafted dynamic fees" base=8 consumer=c-0 job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= tip=550000000
time="2023-04-03T18:52:37Z" level=debug msg="(use-cases.craft-transaction): crafted gas estimation" consumer=c-0 job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= value=0xc000949d50
time="2023-04-03T18:52:37Z" level=debug msg="(use-cases.sign-eth-transaction): ethereum transaction signed successfully" consumer=c-0 job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e one_time_key=false owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= tx_hash=0x5fdef128cf2c95e180c2a7f8f2256c17716e38345eaa37148f52ed59d4b68813
time="2023-04-03T18:52:37Z" level=debug msg="(use-cases.send-eth-tx): job status was updated successfully" consumer=c-0 job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 status=PENDING tenant_id=
time="2023-04-03T18:52:38Z" level=error msg="(use-cases.send-eth-tx): cannot send raw ethereum transaction" consumer=c-0 error="BE001@ethclient.rpc: code: -32000 - message: nonce too low" job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:52:38Z" level=warning msg="(nonce-manager): chain responded with invalid nonce error" consumer=c-0 job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:52:38Z" level=debug msg="(service.kafka-consumer): job status was updated successfully" consumer=c-0 job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e schedule=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 status=RECOVERING
time="2023-04-03T18:52:38Z" level=warning msg="(service.kafka-consumer): error processing job, retrying in [556.007134ms]..." consumer=c-0 error="01300@use-cases.send-eth-tx: BE001@ethclient.rpc: code: -32000 - message: nonce too low" job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e schedule=9d55928c-3d33-4f9e-a99b-30a9eff9dc03
time="2023-04-03T18:52:38Z" level=debug msg="(use-cases.send-eth-tx): processing ethereum transaction job" consumer=c-0 job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:52:38Z" level=debug msg="(use-cases.craft-transaction): crafted transaction nonce" consumer=c-0 job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= value=0xc000e62148
time="2023-04-03T18:52:38Z" level=debug msg="(use-cases.sign-eth-transaction): ethereum transaction signed successfully" consumer=c-0 job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e one_time_key=false owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id= tx_hash=0xf3fbb8bec8d663030522ea48897f0972ac111ef86c49c2301d4ab3bcaf921e70
time="2023-04-03T18:52:38Z" level=debug msg="(use-cases.send-eth-tx): job status was updated successfully" consumer=c-0 job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 status=PENDING tenant_id=
time="2023-04-03T18:52:38Z" level=debug msg="(nonce-manager): increment account nonce value" consumer=c-0 job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e last_sent=33 owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=
time="2023-04-03T18:52:38Z" level=info msg="(use-cases.send-eth-tx): ethereum transaction job was sent successfully" consumer=c-0 job=ab849cb0-4cfd-44b7-b35c-6db5b0f5a82e owner_id= schedule_uuid=9d55928c-3d33-4f9e-a99b-30a9eff9dc03 tenant_id=

Screenshots

Etherscan

Jobs. Actually, all of jobs were mined.