"timer" script from SAMS book or equivalent?

May be can help you \timing in psql

El vie, 05-10-2007 a las 21:32 +0400, John Wells escribió:

----- "Felipe de Jesús Molina Bravo" <felipe.molina@inegi.gob.mx> wrote:

May be can help you \timing in psql

El vie, 05-10-2007 a las 21:32 +0400, John Wells escribió:

Guys,

In the book PostgreSQL (2nd ed) the author mentions a timer script

he wrote to analyze various performance bits about PostgreSQL. I've
looked everywhere and can't find it. Does anyone know where I can find
a copy, or find an equivalent tool?

I'm afraid it's not even close in functionality. Here is sample results from the "timer" tool he mentions. This is the kind of data I'm after:

$ timer "SELECT * FROM recalls"

+-------------+--------------------------------+-------------------------------+
|             |         SEQUENTIAL I/O         |        INDEXED I/O            |
|             |scans |tuples |heap_blks |cached|scans |tuples |idx_blks |cached|
|-------------+------+-------+----------+------+------+-------+---------+------+
|pg_aggregate |    0 |     0 |        1 |    0 |    1 |     1 |       2 |    0 |
|pg_am        |    1 |     1 |        1 |    0 |    0 |     0 |       0 |    0 |
|pg_amop      |    0 |     0 |        2 |   10 |   10 |    24 |       4 |   16 |
|pg_amproc    |    0 |     0 |        1 |    5 |    6 |     6 |       2 |   10 |
|pg_attribute |    0 |     0 |        8 |   14 |   21 |    65 |       6 |   57 |
|pg_cast      |    0 |     0 |        2 |    6 |   60 |     8 |       2 |  118 |
|pg_class     |    4 |   740 |        5 |   32 |   18 |    17 |       7 |   34 |
|pg_database  |    1 |     1 |        1 |    0 |    0 |     0 |       0 |    0 |
|pg_index     |    2 |   146 |        3 |   11 |    8 |    12 |       4 |   12 |
|pg_namespace |    2 |    10 |        1 |    2 |    2 |     1 |       2 |    2 |
|pg_opclass   |    0 |     0 |        2 |   11 |    5 |    73 |       4 |    6 |
|pg_operator  |    0 |     0 |        4 |    6 |   10 |    10 |       4 |   26 |
|pg_proc      |    0 |     0 |        6 |    8 |   14 |    14 |      12 |   31 |
|pg_rewrite   |    0 |     0 |        1 |    1 |    2 |     2 |       2 |    2 |
|pg_shadow    |    0 |     0 |        1 |    2 |    3 |     3 |       4 |    2 |
|pg_statistic |    0 |     0 |        3 |    5 |   33 |     8 |       2 |   64 |
|pg_trigger   |    0 |     0 |        1 |    1 |    2 |     2 |       2 |    2 |
|pg_type      |    0 |     0 |        2 |    5 |    7 |     7 |       2 |   12 |
|recalls      |    1 | 39241 |     4413 |    0 |    0 |     0 |       0 |    0 |
+-------------+------+-------+----------+------+------+-------+---------+------+
|Totals       |   11 | 40139 |     4458 |  119 |  202 |   253 |      61 |  394 |
+-------------+------+-------+----------+------+------+-------+---------+------+

Thanks,
John

----- "Owen Hartnett" <owen@clipboardinc.com> wrote:

At 11:57 PM +0400 10/5/07, John Wells wrote:

----- "Felipe de Jesús Molina Bravo" <felipe.molina@inegi.gob.mx>

wrote:

May be can help you \timing in psql

El vie, 05-10-2007 a las 21:32 +0400, John Wells escribió:

Guys,

In the book PostgreSQL (2nd ed) the author mentions a timer

script

he wrote to analyze various performance bits about PostgreSQL.

I've

looked everywhere and can't find it. Does anyone know where I can

find

a copy, or find an equivalent tool?

I'm afraid it's not even close in functionality. Here is sample
results from the "timer" tool he mentions. This is the kind of data
I'm after:

This was available on line at www.developers-library.com, but now it
looks like that has gone away. Sometimes an author keeps a web site
for code he uses to supplement a book, but I can't find one for him.
Here's the code:

Thanks to all. Having problems building it myself. I plan to reimplement in ruby if possible. Will post results.

Thanks,
John

In the book PostgreSQL (2nd ed) the author mentions a timer script he wrote to analyze various performance bits about PostgreSQL. I've looked everywhere and can't find it. Does anyone know where I can find a copy, or find an equivalent tool?

Hi John, sorry for the delay in getting back to you.

You can find the timer program at
http://www.conjectrix.com/pgbook/index.html. You want the sample
data/code for chapter 4.

-- Korry

Could someone explain to me how the connection is initialized below? I'm re-writing the script in Ruby...but this is a stumbling block for me in the way the C++ libs work. Does the library initial conn automagically? How would one emulate this in another language...would it be to run it as the postgres user and connection to template1?

Thanks,
John

int main( int argc, char * argv[] )
{
// how is this being initialized?
connection conn;

work tran1( conn, "getBegValues" );

const result & begTupleValues = getTupleValues( tran1, argc > 2 ?
argv[2] : 0 );
const result & begBlockValues = getBlockValues( tran1, argc > 2 ?
argv[2] : 0 );

const result & ignore = tran1.exec( argv[1] );

tran1.commit();

sleep( 1 );

work tran2( conn, "getEndValues" );

const result & endTupleValues = getTupleValues( tran2, argc > 2 ?
argv[2] : 0 );
const result & endBlockValues = getBlockValues( tran2, argc > 2 ?
argv[2] : 0 );

printDeltas( begTupleValues, endTupleValues, begBlockValues,
endBlockValues );

}

My Ruby version is found below. Note it requires the postgres-pr ruby driver. Also note I didn't really ruby-ize it to much...for the most part it's a one-to-one translation.

One different thing to note...this script expects you to have postgres-pr installed via rubygems. You can modify the require statements (actually just comment out the rubygems line) if you're is installed in a non-rubygems way.

Also note, this requires you to define your connection parameters in env variables, which works in my situation.

PG_TIMER_DB - name of the database
PG_TIMER_USER - name of database user
PG_TIMER_PASS - password of database user
PG_TIMER_URI - connection uri that postgres-pr understands.
Examples:
tcp://localhost:5432
unix:/tmp/.s.PGSQL.5432

Hope it helps someone else.

###################################################
require 'rubygems'
require 'postgres-pr/connection'

$tupleQuery = "SELECT relname, seq_scan,
seq_tup_read, idx_scan,
idx_tup_fetch
FROM pg_stat_all_tables"

$blockQuery = "SELECT relname, heap_blks_read,
heap_blks_hit, idx_blks_read,
idx_blks_hit
FROM pg_statio_all_tables"

$use_jdbc = false

def usage
usstr = <<-EOL
#{$0} <query>
Example: #{$0} "select * from users"

Note: the following environment variables MUST be set:
PG_TIMER_DB - name of the database
PG_TIMER_USER - name of database user
PG_TIMER_PASS - password of database user
PG_TIMER_URI - connection uri that postgres-pr understands.
Examples:
tcp://localhost:5432
unix:/tmp/.s.PGSQL.5432
EOL
puts usstr
exit()
end

$dbname = ENV['PG_TIMER_DB']
$dbuser = ENV['PG_TIMER_USER']
$dbpass = ENV['PG_TIMER_PASS']
$dburi = ENV['PG_TIMER_URI']

[$dbname, $dbuser, $dbpass, $dburi].each do |one|
one.nil? && usage()
end

class PostgresPR::Connection::Result
def get_field_at_row(field, row)
idx = @fields.collect{|f|f.name}.index field
@rows[row][idx]
end
end

class PureDBUtil
def initialize()
@conn = PostgresPR::Connection.new($dbname,
$dbuser,
$dbpass,
$dburi)
end
def start_tran
@conn.query("BEGIN")
end
def commit
@conn.query("COMMIT")
end
def exec(query)
@conn.query(query)
end
end

class JDBCDBUtil
def initialize(dbname=nil)
raise Exception, "not implemented"
end
end

def getTupleValues(tran, table_name=nil)
if !table_name.nil?
return tran.exec($tupleQuery + " ORDER by relname")
else
return tran.exec($tupleQuery + " WHERE relname = '#{table_name}' ")
end
end

def getBlockValues(tran, table_name)
if !table_name.nil?
return tran.exec($blockQuery + " ORDER by relname")
else
return tran.exec($blockQuery + " WHERE relname = '#{table_name}' ")
end
end

def getDelta(n, beginning, ending, col)
endVal = 0
begVal = 0
endVal = ending.get_field_at_row(col, n)
begVal = beginning.get_field_at_row(col, n)
return endVal.to_f - begVal.to_f;
end

def getColumnWidth(res, col)
max = 0
res.rows.each do |one|
if one[col].size > max
max = one[col].size
end
end
return max
end

def fill(len, c)
c * len
end

def printDeltas(begTuples, endTuples, begBlocks, endBlocks)
nameWidth = 15
str = ""
str << '+' << fill( nameWidth, '-' ) << "+-----------------------------------+----------------------------------+" << "\n";
str << '|' << fill( nameWidth, ' ' ) << "| SEQUENTIAL I/O | INDEXED I/O |" << "\n";
str << '|' << fill( nameWidth, ' ' ) << "| scans | tuples |heap_blks |cached | scans | tuples | idx_blks |cached|" << "\n";
str << '|' << fill( nameWidth, '-' ) << "+-------+--------+-----------+------+-------+--------+----------+------+" << "\n";
totSeqScans = 0
totSeqTuples = 0
totHeapBlks = 0
totHeapHits = 0
totIdxScans = 0
totIdxTuples = 0
totIdxBlks = 0
totIdxHits = 0
tableCount = 0

0.upto begTuples.rows.size-1 do |row|
seqScans = getDelta(row, begTuples, endTuples, "seq_scan")
seqTuples = getDelta(row, begTuples, endTuples, "seq_tup_read")
heapBlks = getDelta(row, begBlocks, endBlocks, "heap_blks_read")
heapHits = getDelta(row, begBlocks, endBlocks, "heap_blks_hit")
idxScans = getDelta(row, begTuples, endTuples, "idx_scan")
idxTuples = getDelta(row, begTuples, endTuples, "idx_tup_fetch")
idxBlks = getDelta(row, begBlocks, endBlocks, "idx_blks_read")
idxHits = getDelta(row, begBlocks, endBlocks, "idx_blks_hit")

if(( seqScans + seqTuples + heapBlks +
heapHits + idxScans + idxTuples +
idxBlks + idxHits ) > 0 )
str << '|' << begTuples.get_field_at_row("relname", row).ljust(nameWidth);
str << '|' << seqScans.to_s.rjust(6) << ' '
str << '|' << seqTuples.to_s.rjust(7) << ' '
str << '|' << heapBlks.to_s.rjust(10) << ' '
str << '|' << heapHits.to_s.rjust(5) << ' '
str << '|' << idxScans.to_s.rjust(6) << ' '
str << '|' << idxTuples.to_s.rjust(7) << ' '
str << '|' << idxBlks.to_s.rjust(9) << ' '
str << '|' << idxHits.to_s.rjust(5) << ' '
str << '|' << "\n"

tableCount += 1
totSeqScans += seqScans
totSeqTuples += seqTuples
totHeapBlks += heapBlks
totHeapHits += heapHits
totIdxScans += idxScans
totIdxTuples += idxTuples
totIdxBlks += idxBlks
totIdxHits += idxHits
end
end
str << '+' << fill( nameWidth, '-' ) <<
"+-------+--------+-----------+" <<
"------+-------+--------+----------+------+\n";

if( tableCount > 1 )
str << '|' << "Totals".ljust(nameWidth)
str << '|' << totSeqScans.to_s.rjust(6) << ' ';
str << '|' << totSeqTuples.to_s.rjust(7) << ' ';
str << '|' << totHeapBlks.to_s.rjust(10) << ' ';
str << '|' << totHeapHits.to_s.rjust(5) << ' ';

str << '|' << totIdxScans.to_s.rjust(6) << ' ';
str << '|' << totIdxTuples.to_s.rjust(7) << ' ';
str << '|' << totIdxBlks.to_s.rjust(9) << ' ';
str << '|' << totIdxHits.to_s.rjust(5) << ' ';
str << '|' << "\n";
str << '+' << fill( nameWidth, '-' ) <<
"+-------+--------+-----------+" <<
"------+-------+--------+----------+------+\n";
end
puts str
end

def main(args)
arg = args[0]

usage() if arg.nil?
if $use_jdbc
db_class = JDBCDBUtil
else
db_class = PureDBUtil
end
tran1 = db_class.new()
tran1.start_tran()
begTupleValues = getTupleValues(tran1, arg)
begBlockValues = getBlockValues(tran1, arg)
ignore = tran1.exec(args[0])
tran1.commit()

sleep 1

tran2 = db_class.new()
endTupleValues = getTupleValues(tran2, arg)
endBlockValues = getBlockValues(tran2, arg)

printDeltas(begTupleValues,
endTupleValues,
begBlockValues,
endBlockValues)
end

main(ARGV)

Sorry...the first version was a bit rash and left out some features...particularly filtering by table. Here's the patch to correct:

If anyone wants the corrected version, email me off list.

Thanks,
John

# diff -w pg_timer_old.rb pg_timer.rb
18a19

app = File.basename $0

20,21c21,25
< #{$0} <query>
< Example: #{$0} "select * from users"
---

#{app} <query> [tablename]
or
#{app} /path/to/file/containing/query.sql [tablename]

Example: #{app} "select * from users" "users"

54a59

78c83
< if !table_name.nil?
---

if table_name.nil?

86c91
< if !table_name.nil?
---

if table_name.nil?

194c199,211
< arg = args[0]
---

first = args[0]
query = nil
if !first.nil? and File.exists?(first)
File.open(first, "r") do |f|
query = f.read
end
else
query = first
end

table = args[1]

usage() if args.size < 1

196d212
< usage() if arg.nil?
201a218

204,206c221,223
< begTupleValues = getTupleValues(tran1, arg)
< begBlockValues = getBlockValues(tran1, arg)
< ignore = tran1.exec(args[0])
---

begTupleValues = getTupleValues(tran1, table)
begBlockValues = getBlockValues(tran1, table)
ignore = tran1.exec(query)

212,213c229,232
< endTupleValues = getTupleValues(tran2, arg)
< endBlockValues = getBlockValues(tran2, arg)
---

The version sent yesterday was creating a LOT of unnecessary objects when running queries with large result sets. I tweaked the postpres-pr classes (via Ruby's very nice open class mechanism). The updated version is below...it took queries running 10+ minutes down to around 20 seconds.

Thanks,
John

---------------------
require 'rubygems'
require 'postgres-pr/connection'
require 'postgres-pr/message'

$tupleQuery = "SELECT relname, seq_scan,
seq_tup_read, idx_scan,
idx_tup_fetch
FROM pg_stat_all_tables"

$blockQuery = "SELECT relname, heap_blks_read,
heap_blks_hit, idx_blks_read,
idx_blks_hit
FROM pg_statio_all_tables"

$use_jdbc = false

def usage
app = File.basename $0
usstr = <<-EOL
#{app} <query> [tablename]
or
#{app} /path/to/file/containing/query.sql [tablename]

Example: #{app} "select * from users" "users"

Note: the following environment variables MUST be set:
PG_TIMER_DB - name of the database
PG_TIMER_USER - name of database user
PG_TIMER_PASS - password of database user
PG_TIMER_URI - connection uri that postgres-pr understands.
Examples:
tcp://localhost:5432
unix:/tmp/.s.PGSQL.5432
EOL
puts usstr
exit
end

class PostgresPR::Connection::Result
def get_field_at_row(field, row)
idx = @fields.collect{|f|f.name}.index field
@rows[row][idx]
end
end

class PostgresPR::Connection
def query_no_results(sql)
puts "Running query in background. Waiting..."
@conn << PostgresPR::Query.dump(sql)
loop do
msg = PostgresPR::Message.read_without_buffer(@conn)
case msg
when PostgresPR::ReadyForQuery
break
end
end
end
end

class PostgresPR::Message
def self.read_without_buffer(stream, startup=false)
type = stream.readbytes(1).unpack('C').first unless startup
length = stream.readbytes(4).unpack('N').first # FIXME: length should be signed, not unsigned
if type==?Z
buffer = Buffer.of_size(startup ? length : 1+length)
buffer.write_byte(type) unless startup
buffer.write_int32_network(length)
buffer.copy_from_stream(stream, length-4)
(startup ? StartupMessage : MsgTypeMap[type]).create(buffer)
else
stream.read(length - 4)
return nil
end
end
end

class PureDBUtil
def initialize()

@conn = PostgresPR::Connection.new($dbname,
$dbuser,
$dbpass,
$dburi)
end
def start_tran
@conn.query("BEGIN")
end
def commit(results=true)
if results
@conn.query("COMMIT")
else
@conn.query_no_results("COMMIT")
end
end
def exec(query, results=true)
if results
@conn.query(query)
else
@conn.query_no_results(query)
end
end
end

class JDBCDBUtil
def initialize(dbname=nil)
raise Exception, "not implemented"
end
end

def getTupleValues(tran, table_name=nil)
if table_name.nil?
return tran.exec($tupleQuery + " ORDER by relname")
else
return tran.exec($tupleQuery + " WHERE relname = '#{table_name}' ")
end
end

def getBlockValues(tran, table_name)
if table_name.nil?
return tran.exec($blockQuery + " ORDER by relname")
else
return tran.exec($blockQuery + " WHERE relname = '#{table_name}' ")
end
end

def getDelta(n, beginning, ending, col)
endVal = 0
begVal = 0
endVal = ending.get_field_at_row(col, n)
begVal = beginning.get_field_at_row(col, n)
return endVal.to_f - begVal.to_f;
end

def gcw(res, col)
max = 0
0.upto res.rows.size-1 do |n|
fld_size = res.get_field_at_row(col, n).size
if fld_size > max
max = fld_size
end
end
return max
end

def fill(len, c)
c * len
end

def printDeltas(begTuples, endTuples, begBlocks, endBlocks)
nameWidth = gcw(begTuples, "relname")
str = ""
str << '+' << fill( nameWidth, '-' ) << "+-----------------------------------+----------------------------------+" << "\n";
str << '|' << fill( nameWidth, ' ' ) << "| SEQUENTIAL I/O | INDEXED I/O |" << "\n";
str << '|' << fill( nameWidth, ' ' ) << "| scans | tuples |heap_blks |cached| scans | tuples | idx_blks |cached|" << "\n";
str << '|' << fill( nameWidth, '-' ) << "+-------+--------+-----------+------+-------+--------+----------+------+" << "\n";
totSeqScans = 0
totSeqTuples = 0
totHeapBlks = 0
totHeapHits = 0
totIdxScans = 0
totIdxTuples = 0
totIdxBlks = 0
totIdxHits = 0
tableCount = 0

0.upto begTuples.rows.size-1 do |row|
seqScans = getDelta(row, begTuples, endTuples, "seq_scan")
seqTuples = getDelta(row, begTuples, endTuples, "seq_tup_read")
heapBlks = getDelta(row, begBlocks, endBlocks, "heap_blks_read")
heapHits = getDelta(row, begBlocks, endBlocks, "heap_blks_hit")
idxScans = getDelta(row, begTuples, endTuples, "idx_scan")
idxTuples = getDelta(row, begTuples, endTuples, "idx_tup_fetch")
idxBlks = getDelta(row, begBlocks, endBlocks, "idx_blks_read")
idxHits = getDelta(row, begBlocks, endBlocks, "idx_blks_hit")

if(( seqScans + seqTuples + heapBlks +
heapHits + idxScans + idxTuples +
idxBlks + idxHits ) > 0 )
str << '|' << begTuples.get_field_at_row("relname", row).ljust(nameWidth);
str << '|' << seqScans.to_s.rjust(6) << ' '
str << '|' << seqTuples.to_s.rjust(7) << ' '
str << '|' << heapBlks.to_s.rjust(10) << ' '
str << '|' << heapHits.to_s.rjust(5) << ' '
str << '|' << idxScans.to_s.rjust(6) << ' '
str << '|' << idxTuples.to_s.rjust(7) << ' '
str << '|' << idxBlks.to_s.rjust(9) << ' '
str << '|' << idxHits.to_s.rjust(5) << ' '
str << '|' << "\n"

tableCount += 1
totSeqScans += seqScans
totSeqTuples += seqTuples
totHeapBlks += heapBlks
totHeapHits += heapHits
totIdxScans += idxScans
totIdxTuples += idxTuples
totIdxBlks += idxBlks
totIdxHits += idxHits
end
end
str << '+' << fill( nameWidth, '-' ) <<
"+-------+--------+-----------+" <<
"------+-------+--------+----------+------+\n";

if( tableCount > 1 )
str << '|' << "Totals".ljust(nameWidth)
str << '|' << totSeqScans.to_s.rjust(6) << ' ';
str << '|' << totSeqTuples.to_s.rjust(7) << ' ';
str << '|' << totHeapBlks.to_s.rjust(10) << ' ';
str << '|' << totHeapHits.to_s.rjust(5) << ' ';

str << '|' << totIdxScans.to_s.rjust(6) << ' ';
str << '|' << totIdxTuples.to_s.rjust(7) << ' ';
str << '|' << totIdxBlks.to_s.rjust(9) << ' ';
str << '|' << totIdxHits.to_s.rjust(5) << ' ';
str << '|' << "\n";
str << '+' << fill( nameWidth, '-' ) <<
"+-------+--------+-----------+" <<
"------+-------+--------+----------+------+\n";
end
puts str
end

def main(args)
$dbname = ENV['PG_TIMER_DB']
$dbuser = ENV['PG_TIMER_USER']
$dbpass = ENV['PG_TIMER_PASS']
$dburi = ENV['PG_TIMER_URI']
[$dbname, $dbuser, $dbpass, $dburi].each do |one|
one.nil? && usage()
end

first = args[0]
query = nil
if !first.nil? and File.exists?(first)
File.open(first, "r") do |f|
query = f.read
end
else
query = first
end

table = args[1]

usage() if args.size < 1

if $use_jdbc
db_class = JDBCDBUtil
else
db_class = PureDBUtil
end

tran1 = db_class.new()
tran1.start_tran()
begTupleValues = getTupleValues(tran1, table)
begBlockValues = getBlockValues(tran1, table)
tran1.exec(query,false)
tran1.commit(false)

sleep 1

tran2 = db_class.new()
tran2.start_tran()
endTupleValues = getTupleValues(tran2, table)
endBlockValues = getBlockValues(tran2, table)
tran2.commit()

printDeltas(begTupleValues,
endTupleValues,
begBlockValues,
endBlockValues)
end

main(ARGV)