Commit 68a0a08e authored by Andreas Kusalananda Kähäri's avatar Andreas Kusalananda Kähäri
Browse files

Make it easier to enable the timing code. Just comment out the

'__END__'...
parent 16e58a4f
......@@ -75,156 +75,164 @@ sub sql {
return $dbc_sql_hash{$self};
}
sub DESTROY {
my ($self) = @_;
my $dbc = $self->dbc;
$self->dbc(undef);
my $sql = $self->sql;
$self->sql(undef);
# Re-bless into DBI::st so that superclass destroy method is called if
# it exists (it does not exist in all DBI versions).
bless( $self, 'DBI::st' );
# The count for the number of kids is decremented only after this
# function is complete. Disconnect if there is 1 kid (this one)
# remaining.
if ( $dbc
&& $dbc->disconnect_when_inactive()
&& $dbc->connected
&& ( $dbc->db_handle->{Kids} == 1 ) )
{
if ( $dbc->disconnect_if_idle() ) {
warn("Problem disconnect $self around sql = $sql\n");
}
}
} ## end sub DESTROY
1;
# Comment out this "__END__" for printing out handy debug information
# (every query if you want).
__END__
# To stop caching messing up your timings, try doing the following on
# any adapter:
#
# uncomment this for printing out handy debug information
# (every query if you want)
# $slice_adaptor->dbc()->db_handle()->do("SET SESSION query_cache_type = OFF");
#
# To start logging:
# Bio::EnsEMBL::DBSQL::StatementHandle->sql_timing_start();
#
# to stop caching messing up your timings try doing thefoloowing on any adapter:-
# To display the results:
# Bio::EnsEMBL::DBSQL::StatementHandle->sql_timing_print(1);
#
# my $sth = $slice_adaptor->dbc->db_handle->prepare("SET SESSION query_cache_type = OFF");
# $sth->execute || die "set session failed\n";
#
# To pause logging:
# Bio::EnsEMBL::DBSQL::StatementHandle->sql_timimg_pause();
#
## call Bio::EnsEMBL::DBSQL::StatementHandle->sql_timing_start(); to start log
## call Bio::EnsEMBL::DBSQL::StatementHandle->sql_timing_print(1); to print the results
## and set $dump to 0
## leave $dump = 1 for continuous log
# uncomment from here-------------------
#my @bind_args=();
#my $dump = 0;
#my %total_time;
#my %min_time;
#my %max_time;
#my %number_of_times;
#my %first_time;
#my $grand_total;
#sub sql_timing_start{
# %total_time = ();
# %number_of_times = ();
# %min_time = ();
# %max_time = ();
# %first_time = ();
# $grand_total = 0;
# $dump = 1;
#}
#sub sql_timimg_pause{
# $dump=0;
#}
#sub sql_timing_resume{
# $dump =1;
#}
#sub sql_timing_print{
# my $self = shift;
# my $level = shift;
# my $fh = shift;
# my $grand_total=0;
# if(!defined($fh)){
# $fh = \*STDERR;
# }
# print ref($fh)."\n";
# foreach my $key (keys %total_time){
# if(defined($level) and $level){
# print $fh $key."\n";
# print $fh "total\t \tnum\tfirst \t\tavg\t \t[min ,max ]\n";
# printf $fh "%6f\t%d\t%6f\t%6f\t[%6f, %6f]\n\n",
# $total_time{$key},
# $number_of_times{$key},
# $first_time{$key},
# ($total_time{$key}/$number_of_times{$key}),
# $min_time{$key},
# $max_time{$key};
# }
# $grand_total += $total_time{$key};
# }
# printf $fh "\ntotal time %6f\n\n", $grand_total;
#}
#sub bind_param{
# my ($self,@args) = @_;
# $bind_args[$args[0]-1] = $args[1];
# $self->SUPER::bind_param(@args);
#}
#sub execute {
# my ($self,@args) = @_;
# if(!$dump){ # skip dumping
# return $self->SUPER::execute(@args);
# }
# my $sql = $self->sql();
# my @chrs = split(//, $sql);
# my $j = 0;
# for(my $i =0; $i < @chrs; $i++) {
# $chrs[$i] = $bind_args[$j++] if($chrs[$i] eq '?' && defined($bind_args[$j]));
# }
# my $str = join('', @chrs);
## uncomment this line if you want to see sql in order.
## print STDERR "\n\nSQL:\n$str\n\n";
# my $time = time;
# my $res = $self->SUPER::execute(@args);
# $time = time - $time;
# if(defined($total_time{$sql})){
# $total_time{$sql} += $time;
# $number_of_times{$sql}++;
# if($min_time{$sql} > $time){
# $min_time{$sql} = $time;
# }
# if($max_time{$sql} < $time){
# $max_time{$sql} = $time;
# }
# }
# else{
# $first_time{$sql} = $time;
# $max_time{$sql} = $time;
# $min_time{$sql} = $time;
# $total_time{$sql} = $time;
# $number_of_times{$sql} = 1;
# }
# return $res;
#}
# End uncomment
# To resume logging after pause:
# Bio::EnsEMBL::DBSQL::StatementHandle->sql_timimg_resume();
use Time::HiRes qw(time);
my @bind_args = ();
my $dump = 0;
my %total_time;
my %min_time;
my %max_time;
my %number_of_times;
my %first_time;
my $grand_total;
sub sql_timing_start {
%total_time = ();
%number_of_times = ();
%min_time = ();
%max_time = ();
%first_time = ();
$dump = 1;
}
sub sql_timimg_pause { $dump = 0 }
sub sql_timing_resume { $dump = 1 }
sub DESTROY {
my ($obj) = @_;
sub sql_timing_print {
my ( $self, $level, $fh ) = @_;
my $dbc = $obj->dbc;
$obj->dbc(undef);
my $sql = $obj->sql;
$obj->sql(undef);
my $grand_total = 0;
# rebless into DBI::st so that superclass destroy method is called
# if it exists (it does not exist in all DBI versions)
bless($obj, 'DBI::st');
if ( !defined($fh) ) {
$fh = \*STDERR;
}
# The count for the number of kids is decremented only after this
# function is complete. Disconnect if there is 1 kid (this one) remaining.
if($dbc && $dbc->disconnect_when_inactive() &&
$dbc->connected && ($dbc->db_handle->{Kids} == 1))
{
if($dbc->disconnect_if_idle()) {
warn("Problem disconnect $obj around sql = $sql\n");
}
print( ref($fh), "\n" );
foreach my $key ( keys %total_time ) {
$grand_total += $total_time{$key};
if ( !( defined($level) and $level ) ) { next }
print( $fh $key, "\n" );
print( $fh
"total\t \tnum\tfirst \t\tavg\t \t[min ,max ]\n" );
printf( $fh "%6f\t%d\t%6f\t%6f\t[%6f, %6f]\n\n",
$total_time{$key},
$number_of_times{$key},
$first_time{$key},
( $total_time{$key}/$number_of_times{$key} ),
$min_time{$key},
$max_time{$key} );
}
printf( $fh "\ntotal time %6f\n\n", $grand_total );
} ## end sub sql_timing_print
sub bind_param {
my ( $self, @args ) = @_;
$bind_args[ $args[0] - 1 ] = $args[1];
$self->SUPER::bind_param(@args);
}
sub execute {
my ( $self, @args ) = @_;
if ( !$dump ) { # skip dumping
return $self->SUPER::execute(@args);
}
my $sql = $self->sql();
my @chrs = split( //, $sql );
my $j = 0;
for ( my $i = 0 ; $i < @chrs ; $i++ ) {
$chrs[$i] = $bind_args[ $j++ ]
if ( $chrs[$i] eq '?' && defined( $bind_args[$j] ) );
}
my $str = join( '', @chrs );
# uncomment this line if you want to see sql in order.
# print STDERR "\n\nSQL:\n$str\n\n";
my $time = time();
my $res = $self->SUPER::execute(@args);
$time = time() - $time;
if ( defined( $total_time{$sql} ) ) {
$total_time{$sql} += $time;
$number_of_times{$sql}++;
if ( $min_time{$sql} > $time ) {
$min_time{$sql} = $time;
}
if ( $max_time{$sql} < $time ) {
$max_time{$sql} = $time;
}
} else {
$first_time{$sql} = $time;
$max_time{$sql} = $time;
$min_time{$sql} = $time;
$total_time{$sql} = $time;
$number_of_times{$sql} = 1;
}
return $res;
} ## end sub execute
1;
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment