Author: spadkins
Date: Mon Nov 30 08:29:02 2009
New Revision: 13619
Modified:
p5ee/trunk/App-Context/lib/App/Context.pm
p5ee/trunk/App-Context/lib/App/Context/HTTP.pm
Log:
add support in app_profiler_log for end_cd and app_scope_id_type
Modified: p5ee/trunk/App-Context/lib/App/Context.pm
==============================================================================
--- p5ee/trunk/App-Context/lib/App/Context.pm (original)
+++ p5ee/trunk/App-Context/lib/App/Context.pm Mon Nov 30 08:29:02 2009
@@ -2814,7 +2814,7 @@
=cut
sub shutdown {
- my $self = shift;
+ my ($self, $end_cd) = @_;
my ($conf, $repdef, $repname, $instance);
my ($class, $method, $args, $argidx, $repcache);
@@ -2823,7 +2823,7 @@
my $profiler = $options->{"app.Context.profiler"};
if ($profiler) {
$self->profile_stop("main");
- $self->finish_profiler_log();
+ $self->finish_profiler_log($end_cd);
}
$self->dbgprint("Context->shutdown()")
@@ -2847,7 +2847,7 @@
sub DESTROY {
my ($self) = @_;
- $self->shutdown();
+ $self->shutdown("D");
}
#############################################################################
@@ -2902,6 +2902,11 @@
&App::sub_entry if ($App::trace);
my ($self) = @_;
+ my $profile_state = $self->{profile_state};
+ if (!$profile_state) {
+ $self->profile_start("main");
+ $profile_state = $self->{profile_state};
+ }
my $options = $self->{options};
my $app = $options->{app} || "app";
my $context_abbr = ref($self);
@@ -2910,7 +2915,6 @@
my $username = $self->user();
#my $events = $self->{events};
#my $events_str = $events ? (join("|", @$events)) : "";
- my $profile_state = $self->{profile_state};
my $time = $profile_state->{last_timeofday}[0] || time();
my $start_dttm = time2str("%Y-%m-%d %H:%M:%S", $time);
my $info = $self->get_proc_info2();
@@ -2922,11 +2926,13 @@
if ($rep) {
eval {
- $rep->insert("app_profiler_log",
- ["context", "host", "username", "app", "start_dttm",
"start_mem_mb"],
- [$context_abbr, $host, $username, $app, $start_dttm,
$start_mem_mb],
- { last_inserted_id => 1 });
- $profile_state->{profiler_log_id} = $rep->last_inserted_id();
+ if (!$profile_state->{profiler_log_id}) {
+ $rep->insert("app_profiler_log",
+ ["context", "host", "username", "app", "start_dttm",
"start_mem_mb"],
+ [$context_abbr, $host, $username, $app, $start_dttm,
$start_mem_mb],
+ { last_inserted_id => 1 });
+ $profile_state->{profiler_log_id} = $rep->last_inserted_id();
+ }
};
}
else {
@@ -2938,7 +2944,7 @@
sub update_profiler_log {
&App::sub_entry if ($App::trace);
- my ($self, $app_scope, $app_scope_id, $content_name) = @_;
+ my ($self, $app_scope, $content_name, $app_scope_id_type, $app_scope_id) =
@_;
my $options = $self->{options};
my $repname = $options->{"app.Context.profiler_repository"};
@@ -2955,10 +2961,12 @@
}
if (defined $app_scope_id) {
- $profile_state->{app_scope_id} = $app_scope_id;
+ $profile_state->{app_scope_id} = $app_scope_id;
+ $profile_state->{app_scope_id_type} = $app_scope_id_type;
}
elsif (defined $profile_state->{app_scope_id}) {
- $app_scope_id = $profile_state->{app_scope_id};
+ $app_scope_id = $profile_state->{app_scope_id};
+ $app_scope_id_type = $profile_state->{app_scope_id_type};
}
if (defined $content_name) {
@@ -2972,13 +2980,13 @@
if ($profiler_log_id) {
eval {
$rep->update("app_profiler_log", { "profiler_log_id.eq" =>
$profiler_log_id },
- ["app_scope", "app_scope_id", "content_name"],
- [$app_scope, $app_scope_id, $content_name]);
+ ["app_scope", "content_name", "app_scope_id_type",
"app_scope_id"],
+ [$app_scope, $content_name, $app_scope_id_type,
$app_scope_id]);
};
}
}
else {
- $self->log("Update: %s (%s) [%s]\n", $app_scope, $app_scope_id,
$content_name);
+ $self->log("Update: %s [%s] (%s:%s)\n", $app_scope, $content_name,
$app_scope_id_type, $app_scope_id);
}
&App::sub_exit() if ($App::trace);
@@ -2986,22 +2994,24 @@
sub finish_profiler_log {
&App::sub_entry if ($App::trace);
- my ($self) = @_;
+ my ($self, $end_cd) = @_;
+ $end_cd ||= "F"; # assume we finish using normal
processing
my $profile_state = $self->{profile_state};
my $profile_stats = $self->profile_stats();
my $profiler_log_id = $profile_state->{profiler_log_id};
my $app_scope = $profile_state->{app_scope};
- my $app_scope_id = $profile_state->{app_scope_id};
my $content_name = $profile_state->{content_name};
+ my $app_scope_id_type = $profile_state->{app_scope_id_type};
+ my $app_scope_id = $profile_state->{app_scope_id};
my $content_length = $profile_state->{content_length} || 0;
my $time = $profile_state->{last_timeofday}[0] || time();
my $end_dttm = time2str("%Y-%m-%d %H:%M:%S", $time);
my $run_main_time = $profile_stats->{main}{cumul_time} || 0; #
DONE
my $run_event_time = $profile_stats->{event}{cumul_time} || 0; #
DONE:HTTP, TBD:Context
+ my $run_db_time = $profile_stats->{db}{cumul_time} || 0; #
DONE
my $run_file_time = $profile_stats->{file}{cumul_time} || 0; #
TBD (application)
- my $run_db_time = $profile_stats->{db}{cumul_time} || 0; #
TBD
my $run_net_time = $profile_stats->{net}{cumul_time} || 0; #
TBD (application)
my $run_aux1_label = $profile_state->{aux1_label};
@@ -3011,16 +3021,16 @@
$run_aux2_time = $run_aux2_label ?
($profile_stats->{$run_aux2_label}{cumul_time} || 0) : 0;
my $run_xfer_time = $profile_stats->{xfer}{cumul_time} || 0; #
DONE
my $num_net_calls = $profile_stats->{net}{count} || 0; #
DONE
- my $num_db_calls = $profile_stats->{db}{count} || 0; #
TBD
- my $num_db_rows_read = $profile_stats->{db}{nrows_read} || 0; #
TBD
- my $num_db_rows_write = $profile_stats->{db}{nrows_write} || 0; #
TBD
+ my $num_db_calls = $profile_stats->{db}{count} || 0; #
DONE
+ my $num_db_rows_read = $profile_stats->{db}{nrows_read} || 0; #
DONE
+ my $num_db_rows_write = $profile_stats->{db}{nrows_write} || 0; #
DONE
my $info = $self->get_proc_info2();
my $pinfo = $info->{$$};
my $end_mem_mb = $pinfo->{vsize}/1048576;
my $cpu_time = ($pinfo->{cutime} + $pinfo->{cstime}) || 0;
my $run_time = $self->profile_run_time();
my $run_other_time = $run_time - ($run_event_time + $run_main_time +
$run_db_time + $run_file_time + $run_net_time + $run_xfer_time + $run_aux1_time
+ $run_aux2_time);
- $run_other_time = 0 if ($run_other_time < 0);
+ $run_other_time = 0 if ($run_other_time < 1e-6);
my $options = $self->{options};
my $repname = $options->{"app.Context.profiler_repository"};
@@ -3030,21 +3040,24 @@
if ($profiler_log_id) {
eval {
$rep->update("app_profiler_log", { "profiler_log_id.eq" =>
$profiler_log_id },
- ["app_scope", "app_scope_id", "content_name",
- "end_dttm", "end_mem_mb", "cpu_time",
- "run_time", "run_main_time", "run_event_time",
- "run_db_time", "run_file_time", "run_net_time",
- "run_aux1_time", "run_aux2_time", "run_other_time",
- "run_xfer_time", "content_length", "num_net_calls",
- "num_db_calls", "num_db_rows_read", "num_db_rows_write"],
- [$app_scope, $app_scope_id, $content_name,
- $end_dttm, $end_mem_mb, $cpu_time,
- $run_time, $run_main_time, $run_event_time,
- $run_db_time, $run_file_time, $run_net_time,
- $run_aux1_time, $run_aux2_time, $run_other_time,
- $run_xfer_time, $content_length, $num_net_calls,
- $num_db_calls, $num_db_rows_read, $num_db_rows_write]);
+ ["app_scope", "content_name",
"app_scope_id_type", "app_scope_id",
+ "end_cd", "end_dttm", "end_mem_mb",
"cpu_time",
+ "run_time", "run_main_time", "run_event_time",
+ "run_db_time", "run_file_time", "run_net_time",
+ "run_aux1_label", "run_aux2_label",
+ "run_aux1_time", "run_aux2_time", "run_other_time",
+ "run_xfer_time", "content_length", "num_net_calls",
+ "num_db_calls", "num_db_rows_read",
"num_db_rows_write"],
+ [$app_scope, $content_name, $app_scope_id_type,
$app_scope_id,
+ $end_cd, $end_dttm, $end_mem_mb,
$cpu_time,
+ $run_time, $run_main_time, $run_event_time,
+ $run_db_time, $run_file_time, $run_net_time,
+ $run_aux1_label, $run_aux2_label,
+ $run_aux1_time, $run_aux2_time, $run_other_time,
+ $run_xfer_time, $content_length, $num_net_calls,
+ $num_db_calls, $num_db_rows_read,
$num_db_rows_write]);
};
+ delete $profile_state->{profiler_log_id};
}
}
else {
Modified: p5ee/trunk/App-Context/lib/App/Context/HTTP.pm
==============================================================================
--- p5ee/trunk/App-Context/lib/App/Context/HTTP.pm (original)
+++ p5ee/trunk/App-Context/lib/App/Context/HTTP.pm Mon Nov 30 08:29:02 2009
@@ -147,7 +147,7 @@
my $options = $self->{options};
my $app = $options->{app} || "app";
my $profiler = $options->{"app.Context.profiler"};
- my ($app_scope, $app_scope_id, $content_name);
+ my ($app_scope, $app_scope_id_type, $app_scope_id, $content_name);
eval {
my $user = $self->user();
@@ -200,14 +200,15 @@
if (!$ref || $ref eq "ARRAY" || $ref eq "HASH") {
$app_scope = "results [$ref]";
if ($profiler) {
- $self->update_profiler_log($app_scope, $app_scope_id,
$service_name);
+ $self->update_profiler_log($app_scope, $service_name,
$app_scope_id_type, $app_scope_id);
}
$response->content($results);
}
elsif ($results->isa("App::Service")) {
- ($app_scope, $app_scope_id) = $results->content_description();
+ ($app_scope, $app_scope_id_type, $app_scope_id, $content_name) =
$results->content_description();
+ $content_name ||= $service_name;
if ($profiler) {
- $self->update_profiler_log($app_scope, $app_scope_id,
$service_name);
+ $self->update_profiler_log($app_scope, $content_name,
$app_scope_id_type, $app_scope_id);
}
$response->content($results->content());
$response->content_type($results->content_type());
@@ -215,7 +216,7 @@
else {
$app_scope = "$service_type($service_name).internals()";
if ($profiler) {
- $self->update_profiler_log($app_scope, $app_scope_id,
$service_name);
+ $self->update_profiler_log($app_scope, $service_name,
$app_scope_id_type, $app_scope_id);
}
$response->content($results->internals());
}
