Additional statediff metrics and logging. #304

telackey · 2023-01-12T01:17:56Z

telackey commented

2023-01-12 01:17:56 +00:00

Adds counters and logging for the number of statediff API requests, number of statediffs underway, etc.

We had some fine-grained performance stats related to the indexing of an individual block, which looked like this:

DEBUG[01-12|00:30:41.459] indexer stats for statediff at 79 with hash 0x58ce2c20918b83963bd29cbe2da7a6a4871fa702e7ec762e93012f956152d99b:
time spent waiting for free postgres tx: 1.083651ms:
header processing time: 240.693µs
uncle processing time: 395ns
tx and receipt processing time: 7.131475ms
state, storage, and code storage processing time: 4.819091ms
postgres transaction commit duration: 199.498776ms
 TOTAL PROCESSING DURATION: 217.751966ms

But we lacked a more general information like the number of statediffs performed so far, how many were executing at this moment, and so forth.

Output of the new code looks like:

DEBUG[01-12|00:25:11.148] writeStateDiff BEGIN [underway=1, succeeded=40, failed=0, total_time=47600ms] hash=0x76d921b092b2e6e7d525417263e20e7ec324fdfa26c4eb3a80e32df608ed0a41 number=30
...
DEBUG[01-12|00:25:11.431] writeStateDiff END (duration=282ms, err=false) [underway=0, succeeded=41, failed=0, total_time=47882ms] hash=0x76d921b092b2e6e7d525417263e20e7ec324fdfa26c4eb3a80e32df608ed0a41 number=30

And:

DEBUG[01-12|00:25:06.968] statediff API END (duration=373ms, err=false) [underway=0, requests=12] writeStateDiffAt=1

Adds counters and logging for the number of statediff API requests, number of statediffs underway, etc. We had some fine-grained performance stats related to the indexing of an individual block, which looked like this: ``` DEBUG[01-12|00:30:41.459] indexer stats for statediff at 79 with hash 0x58ce2c20918b83963bd29cbe2da7a6a4871fa702e7ec762e93012f956152d99b: time spent waiting for free postgres tx: 1.083651ms: header processing time: 240.693µs uncle processing time: 395ns tx and receipt processing time: 7.131475ms state, storage, and code storage processing time: 4.819091ms postgres transaction commit duration: 199.498776ms TOTAL PROCESSING DURATION: 217.751966ms ``` But we lacked a more general information like the number of statediffs performed so far, how many were executing at this moment, and so forth. Output of the new code looks like: ``` DEBUG[01-12|00:25:11.148] writeStateDiff BEGIN [underway=1, succeeded=40, failed=0, total_time=47600ms] hash=0x76d921b092b2e6e7d525417263e20e7ec324fdfa26c4eb3a80e32df608ed0a41 number=30 ... DEBUG[01-12|00:25:11.431] writeStateDiff END (duration=282ms, err=false) [underway=0, succeeded=41, failed=0, total_time=47882ms] hash=0x76d921b092b2e6e7d525417263e20e7ec324fdfa26c4eb3a80e32df608ed0a41 number=30 ``` And: ``` DEBUG[01-12|00:25:06.968] statediff API END (duration=373ms, err=false) [underway=0, requests=12] writeStateDiffAt=1 ```

❤️ 1

dboreham reviewed 2023-01-12 01:17:56 +00:00

i-norden reviewed 2023-01-12 01:17:56 +00:00

Sign in to join this conversation.

No reviewers

No Milestone

No project

No Assignees

3 Participants

Notifications

Due Date

The due date is invalid or out of range. Please use the format 'yyyy-mm-dd'.

No due date set.

Dependencies

No dependencies set.

Reference: cerc-io/go-ethereum#304