Hi,
I am engaged in a master degree project and i need the answer to the following
question:
How much time the EXECUTOR of PostgreSQL spent during a determined time
interval?
My Scenario is like this:
PostgreSQL 7.4 with the following parameters:
- log_duration = true
- log_pid = true
- log_statement = true
- log_timestamp = true
- log_parser_stats = true
- log_planner_stats = true
- log_executor_stats = true
- stats_start_colector = true
- stats_command_string = true
- stats_block_level = true
Using the BenchmarkSQL Software, I submit random transaction (simluating the
TPC-C benchmark) during a time interval (say 30-45 seconds)
PostgreSQL then generate statistics for each phase which an SQL Command is
executed (PARSER, REWRITE, PLANNER, EXECUTOR), like the log section below:
2007-09-27 15:07:25 [9269] LOG: sentença: SELECT c_discount, c_last, c_credit,
w_tax FROM customer, warehouse WHERE w_id = $1 AND w_id = c_w_id AND c_d_id
= $2 AND c_id = $3
2007-09-27 15:07:25 [9269] LOG: PARSER STATISTICS
DETALHE: ! system usage stats:
! 0.73 elapsed 0.00 user 0.00 system sec
! [0.000999 user 0.001999 sys total]
! 0/0 [0/0] filesystem blocks in/out
! 0/26 [0/490] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
! 0/0 [2/1] voluntary/involuntary context switches
! buffer usage stats:
! Shared blocks: 0 read, 0 written, buffer hit
rate = 0.00%
! Local blocks: 0 read, 0 written, buffer hit
rate = 0.00%
! Direct blocks: 0 read, 0 written
2007-09-27 15:07:25 [9269] LOG: PARSE ANALYSIS STATISTICS
DETALHE: ! system usage stats:
! 0.001513 elapsed 0.001000 user 0.001000 system sec
! [0.001999 user 0.002999 sys total]
! 0/0 [0/0] filesystem blocks in/out
! 0/149 [0/640] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
! 0/0 [2/1] voluntary/involuntary context switches
! buffer usage stats:
! Shared blocks: 40 read, 0 written, buffer hit
rate = 75.00%
! Local blocks: 0 read, 0 written, buffer hit
rate = 0.00%
! Direct blocks: 0 read, 0 written
2007-09-27 15:07:25 [9269] LOG: REWRITER STATISTICS
DETALHE: ! system usage stats:
! 0.16 elapsed 0.00 user 0.00 system sec
! [0.001999 user 0.002999 sys total]
! 0/0 [0/0] filesystem blocks in/out
! 0/2 [0/644] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
! 0/0 [2/1] voluntary/involuntary context switches
! buffer usage stats:
! Shared blocks: 0 read, 0 written, buffer hit
rate = 0.00%
! Local blocks: 0 read, 0 written, buffer hit
rate = 0.00%
! Direct blocks: 0 read, 0 written
2007-09-27 15:07:25 [9269] LOG: PLANNER STATISTICS
DETALHE: ! system usage stats:
! 0.001496 elapsed 0.001000 user 0.00 system sec
! [0.002999 user 0.002999 sys total]
! 0/0 [0/0] filesystem blocks in/out
! 0/109 [0/754] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
! 0/1 [2/2] voluntary/involuntary context switches
! buffer usage stats:
! Shared blocks: 26 read, 0 written, buffer hit
rate = 81.56%
! Local blocks: 0 read, 0 written, buffer hit
rate = 0.00%
! Direct blocks: 0 read, 0 written
2007-09-27 15:07:25 [9269] LOG: EXECUTOR STATISTICS
DETALHE: ! system usage stats:
! 0.022129 elapsed 0.00 user 0.002000 system sec
! [0.002999 user 0.005999 sys total]
! 0/0 [0/0] filesystem blocks in/out
! 0/186 [0/966] page faults/reclaims, 0 [0] swaps
! 0 [0] signals rcvd, 0/0 [0/0] messages rcvd/sent
! 2/0 [4/2] voluntary/involuntary context switches
! buffer usage stats:
! Shared blocks: 94 read, 0 written, buffer hit
rate = 0.00%
! Local blocks: 0 read, 0 written, buffer hit
rate = 0.00%
! Direct blocks: 0 read, 0 written
Trying to answer my initial question, I do something like this:
1. Through the Commands TIMESTAMP, I calculate the total time interval where
all the commands had been executed. (END TIMESTAMP - BEGIN TIMESTAMP)
2. Then I sum all the 'elapsed' fields of all EXECUTOR Sections of all commands
executed. This, in thesis, give me the amount of time that the
