pev
pev copied to clipboard
Actual Duration Loops Need to Divide by Workers + 1
The actual duration is one of the most useful things about Pev, thank you!!! But for 9.6+, the logic of this line needs to be modified: https://github.com/AlexTatiyants/pev/blob/master/app/services/plan-service.ts#L184
// since time is reported for an invidual loop, actual duration must be adjusted by number of loops
node[this.ACTUAL_DURATION_PROP] = node[this.ACTUAL_DURATION_PROP] * node[this.ACTUAL_LOOPS_PROP];
node[this.ACTUAL_LOOPS_PROP]
needs to be divided by the number of workers + 1, apparently. For example plan in a dummy db I have setup:
[{ "Node Type": "Seq Scan",
"Parent Relationship": "Outer",
"Parallel Aware": true,
"Relation Name": "loans",
"Schema": "public",
"Alias": "l",
"Startup Cost": 0.00,
"Total Cost": 97793.50,
"Plan Rows": 1,
"Plan Width": 29,
"Actual Startup Time": 287.685,
"Actual Total Time": 360.335,
"Actual Rows": 0,
"Actual Loops": 5,
"Output": ["l.loan_id", "l.customer_id", "l.loan_type_id", "l.is_issued", "l.created_at", "l.updated_at"],
"Filter": "(l.loan_id = 100)",
"Rows Removed by Filter": 2060000,
"Shared Hit Blocks": 224,
"Shared Read Blocks": 65382,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0,
"Workers": [
{
"Worker Number": 0,
"Actual Startup Time": 359.434,
"Actual Total Time": 359.434,
"Actual Rows": 0,
"Actual Loops": 1,
"Shared Hit Blocks": 46,
"Shared Read Blocks": 13050,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0
},
{
"Worker Number": 1,
"Actual Startup Time": 359.646,
"Actual Total Time": 359.646,
"Actual Rows": 0,
"Actual Loops": 1,
"Shared Hit Blocks": 44,
"Shared Read Blocks": 13227,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0
},
{
"Worker Number": 2,
"Actual Startup Time": 359.646,
"Actual Total Time": 359.646,
"Actual Rows": 0,
"Actual Loops": 1,
"Shared Hit Blocks": 45,
"Shared Read Blocks": 12859,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0
},
{
"Worker Number": 3,
"Actual Startup Time": 359.658,
"Actual Total Time": 359.658,
"Actual Rows": 0,
"Actual Loops": 1,
"Shared Hit Blocks": 42,
"Shared Read Blocks": 12875,
"Shared Dirtied Blocks": 0,
"Shared Written Blocks": 0,
"Local Hit Blocks": 0,
"Local Read Blocks": 0,
"Local Dirtied Blocks": 0,
"Local Written Blocks": 0,
"Temp Read Blocks": 0,
"Temp Written Blocks": 0
}
]
}]
Right now, actual total time of this node is 360.335, but because it shows 5 loops, it is multiplying this by 5.