improve(relayer): Track transaction submission time #2093
Conversation
In order to better understand transaction submission delays, monitor and report on the time required for transaction submission to occur on each chain.
pxrl
requested review from
mrice32,
nicholaspai,
james-a-morris,
dohaki and
bmzig
as code owners
src/relayer/Relayer.ts
Outdated
| pendingTxnReceipts[chainId] = multiCallerClient.executeTxnQueue(chainId, simulate); | ||
| const txnReceipts = await pendingTxnReceipts[chainId]; | ||
| profiler.stop({ message: `Completed ${chain} transaction submission.`, txnReceipts }); |
There was a problem hiding this comment.
thoughts on logging this in the fill info log we send to the SlackTransport?
There was a problem hiding this comment.
I realised this is very close to the log message we already emit in TransactionUtils, so I relocated the change down there. It wasn't clear for me how I should modify the Profiler to support logging at level info, so for now I've just manually added the necessary fields to keep it simple, and also because I don't want to go yak shaving in the SDK just to get this in, because this is more important. wdyt?
There was a problem hiding this comment.
Here's an example from local test:
2025-02-14 13:16:16 [info]: {
"at": "TransactionClient#submit",
"message": "Completed Arbitrum One transaction submission! 🧙",
"mrkdwn": " 1. Filled v3 deposit 🚀 (<https://arbiscan.io/tx/0x9896e8bc9233e638de651f86476ba39466bd53770de6427a7ac5cd1974f55ddb|0x9..ddb>): Relayed depositId 3183273 from Base to Arbitrum One of 1.00 USDC and output 0.9881 USDC, with depositor <https://basescan.org/address/0x9A8f92a830A5cB89a3816e3D267CB7791c16b04D|0x9..04D>. Realized LP fee: 0.000%, total fee: 1.18%. Gas price used in profit calc: 0.01000 Gwei. Relayer repayment: Arbitrum One.\n",
"duration": 744,
"chain": "Arbitrum One",
"datadog": true,
"bot-identifier": "sky",
"run-identifier": "c3a8bbaa-720d-43df-bd64-8325d027e800"
}
src/relayer/Relayer.ts
Outdated
| pendingTxnReceipts[chainId] = multiCallerClient.executeTxnQueue(chainId, simulate); | ||
| const txnReceipts = await pendingTxnReceipts[chainId]; | ||
| profiler.stop({ message: `Completed ${chain} transaction submission.`, txnReceipts }); |
There was a problem hiding this comment.
another idea is this time should maybe be dependent on the # of txns in the queue or the calldata size. Thoughts on incorporating that into the log somehow?
There was a problem hiding this comment.
Yeah I did wonder about that, since we can have multiple txns here. You can see it based on the length of the txnReceipts array, but I'll probably add a specific entry for it.
| this.logger.info({ | ||
| at: "TransactionClient#submit", | ||
| message: `Completed ${chain} transaction submission! 🧙`, | ||
| mrkdwn, |
There was a problem hiding this comment.
mrkdwn should be set on each loop, rather than being appended-to.
There was a problem hiding this comment.
Maybe I'm misunderstanding this, but won't this log just be emitted for every transaction we submit? So if we have two transactions: [txn1, txn2] then this will log twice, the first log being:
completed [chain] transaction submission
... txn1 details
on the first iteration of the loop and then
completed [chain] transaction submission
... txn1 details
... txn2 details
on the second iteration? (Since we are still doing mkdwn +=)
There was a problem hiding this comment.
Exactly - this is not what we want. I left the comment to earmark the change but haven't implemented it yet 👍
In order to better understand transaction submission delays, monitor and report on the time required for transaction submission to occur on each chain.