I asked about DBI tracing a while ago

[Ignoramus23298]

A while ago I asked a question about how do I trace what SQL queries
are being performed. I wanted to improve performance of my site
algebra.com. One of the issues was that I was using some pre-prepared
queries (with "?" marks such as

$sth = dbh->prepare( "...?,?" );

(please do not mention setting trace on on DBI, it does not do what I
need as it does not trace execution of these precompiled statements)

Anyway, I was quite frustrated since I could not know what queries my
website was performing.

I finally wrote a module that wrapped itself around DBI, so that all
function calls except some junk calls like quote() or fetchrow*, were
traced.

The way I use it is that my module that creates or reuses the DB
handle (the only way for me to get a DB handle), now has a debug
option. If debug is not set, it simply returns the dbh. It it is set,
it returns a DebugWrapper wrapped around dbh.

So... Now I know what statements my website was running, and was able
to speed it up 3 times by using better SQL and calling SQL less often.

i

######################################################### Utils
#
#
#
# Copyright: (e-mail address removed)


use strict;
use warnings;

package Algebra:ebugWrapper;
use vars qw( @ISA $VERSION @EXPORT );

use Carp qw( confess );

@ISA = qw(Exporter);
$VERSION = 2000.0821;

@EXPORT= qw(
new
);

######################################################## implementationbin/

use vars qw(
$ignore
);



sub new {
my ($type, $related, $prefix, $info) = @_;

$info = "" unless defined $info;

#print STDERR "PREFIX=$prefix, type=$type.\n";

my $this = bless { related => $related,
prefix => $prefix,
info => $info
},
$type;

return $this;
}

sub prepare {
my ($this, @args) = @_;

my $sth = $this->{related}->prepare( @args );
return undef unless $sth;

return new Algebra:ebugWrapper( $sth, "SQL", $args[0] );
}

sub AUTOLOAD {
my ($this, @args) = @_;
my $subname = $Algebra:ebugWrapper::AUTOLOAD;
$subname =~ s/^Algebra:ebugWrapper:://;
#print "this=$this. $this->{prefix}: $subname( ) \n";
if( defined $subname && $subname ne 'DESTROY' ) {
#print "subname=$subname.\n";

my $cgi = new CGI;
my $url = $cgi->url;
unless( $ignore->{$subname} ) {
my $msg = "$url Wrapper $this->{prefix}: $subname( " . join( ', ', @args ) . " ) $this->{info}";

if( $this->{info} =~ /^\s*insert\s+into\s*(.*)/ ) {
$msg = "Wrapper $this->{prefix}: $this->{info}";
}

print STDERR "$msg\n";

#print "Keys of this = " . join( ',', keys %$this ) . ".\n";
#print "RELATED=$this->{related}.\n";
}

if( wantarray ) {
my @result;
eval {
@result = $this->{related}->$subname( @args );
};
if( $@ ) {
print STDERR "Error in DebugWrapper ($this->{prefix}"."->$subname $this->{info}\n";
die $@;
}
return @result;
} else {
my $result;
eval {
$result = $this->{related}->$subname( @args );
};
if( $@ ) {
print STDERR "Error in DebugWrapper ($this->{prefix}"."->$subname $this->{info}\n";
die $@;
}
return $result;
}
}

#print "\n\n";
}

$ignore = {
fetchrow => 1,
fetchrow_hashref => 1,
fetchrow_arrayref => 1,
quote => 1,
finish => 1,
};
1;

 

[J. Gleixner]

Ignoramus23298 wrote:
[...]

Anyway, I was quite frustrated since I could not know what queries my
website was performing.

Hu.. I would just look at the database's log file.. but that's just me.

 

[Ignoramus23298]

Ignoramus23298 wrote:
[...]

Anyway, I was quite frustrated since I could not know what queries my
website was performing.

Hu.. I would just look at the database's log file.. but that's just me.

That way I did not know which HTTP query was doing what.

i

 

[Dr.Ruud]

Ignoramus23298 schreef:

So... Now I know what statements my website was running, and was able
to speed it up 3 times by using better SQL and calling SQL less often.

Can you show some (even munged) examples of those? I am sure some people
here will enjoy it and learn from it.

I once created an SQL-cache, that would return the cached result for
simple SELECT-queries, and would clear cache entries when a modifying
query was run, or when a configurable number of seconds were passed.
That really sped things up a lot, because the application was running
the same simple fetch-only queries over and over again. The application
was generated code that we couldn't touch.

 

[Ignoramus23298]

Ignoramus23298 schreef:


Can you show some (even munged) examples of those? I am sure some people
here will enjoy it and learn from it.

I think that I will just mention it, not to hide code, but to make it
clear.

1) The home page was setting up the session cookie twice (with
attendant database traffic)

2) Many pages that listed solved problems (on algebra.com, tutors
answer students' algebra questions, about 150 per day), also had
pictures and other info on tutors who submitted answers. That info was
pulled from tutor table by separate queries (so a page that displayed
50 answers, was doing 50 queries to the tutor table).

Because that query was done in separate perl modules, it was not
apparent to me that I was doing it. I replaced it with a join.

3) I had some statements such as SELECT, and then based on it either
INSERT or UPDATE. I replaced it with one INSERT ... ON DUPLICATE KEY
UPDATE statement.

4) On startup I was pulling some data for statistics. I made MySQL
make the statistics by using SELECT COUNT(*) ... GROUP BY.

5) I made sure that when I select from a lot of things, but limit the
selected quantity, I limit that in the query using MySQL LIMIT
qualifier.

I did some other things that I simply forgot.

I once created an SQL-cache, that would return the cached result for
simple SELECT-queries, and would clear cache entries when a modifying
query was run, or when a configurable number of seconds were passed.
That really sped things up a lot, because the application was running
the same simple fetch-only queries over and over again. The application
was generated code that we couldn't touch.

Sounds very nice. I also cache some things.

i