Apply timelog() to TPAC record detail page

Early suggestion from results is that we either need to use unapi.bre more
smartly, or optimize it further.

Signed-off-by: Lebbeous Fogle-Weekley <lebbeous@esilibrary.com>
Signed-off-by: Dan Scott <dscott@laurentian.ca>

diff --git a/Open-ILS/src/perlmods/lib/OpenILS/WWW/EGCatLoader/Record.pm b/Open-ILS/src/perlmods/lib/OpenILS/WWW/EGCatLoader/Record.pm
index 9150480..af1c3fc 100644 (file)
--- a/Open-ILS/src/perlmods/lib/OpenILS/WWW/EGCatLoader/Record.pm
+++ b/Open-ILS/src/perlmods/lib/OpenILS/WWW/EGCatLoader/Record.pm
@@ -14,6 +14,7 @@ sub load_record {
     my $ctx = $self->ctx;
     $ctx->{page} = 'record';  
 
+    $self->timelog("load_record() began");
     my $org = $self->_get_search_lib();
     my $org_name = $ctx->{get_aou}->($org)->shortname;
     my $pref_ou = $self->_get_pref_lib();
@@ -35,8 +36,10 @@ sub load_record {
     if ($ctx->{staff_saved_search_size}) {
         $ctx->{saved_searches} = ($self->staff_load_searches)[1];
     }
+    $self->timelog("past staff saved searches");
 
     $self->fetch_related_search_info($rec_id);
+    $self->timelog("past related search info");
 
     # run copy retrieval in parallel to bib retrieval
     # XXX unapi
@@ -52,10 +55,13 @@ sub load_record {
         depth => $depth,
         pref_lib => $pref_ou
     });
+
+    $self->timelog("past get_records_and_facets()");
     $ctx->{bre_id} = $rec_data[0]->{id};
     $ctx->{marc_xml} = $rec_data[0]->{marc_xml};
 
     $ctx->{copies} = $copy_rec->gather(1);
+    $self->timelog("past store copy retrieval call");
     $ctx->{copy_limit} = $copy_limit;
     $ctx->{copy_offset} = $copy_offset;
 
@@ -64,6 +70,7 @@ sub load_record {
 
     $self->get_hold_copy_summary($rec_id, $org);
 
+    $self->timelog("past get_hold_copy_summary()");
     $self->ctx->{bib_is_dead} = OpenILS::Application::AppUtils->is_true(
         OpenILS::Utils::CStoreEditor->new->json_query({
             select => { bre => [ 'deleted' ] },
@@ -91,6 +98,8 @@ sub load_record {
         };
     }
 
+    $self->timelog("past serials holding stuff");
+
     my %expandies = (
         marchtml => sub {
             $ctx->{marchtml} = $self->mk_marc_html($rec_id);
@@ -116,6 +125,7 @@ sub load_record {
         }
     }
 
+    $self->timelog("past expandies");
     return Apache2::Const::OK;
 }
 

diff --git a/Open-ILS/src/perlmods/lib/OpenILS/WWW/EGCatLoader/Util.pm b/Open-ILS/src/perlmods/lib/OpenILS/WWW/EGCatLoader/Util.pm
index a283f41..57b8407 100644 (file)
--- a/Open-ILS/src/perlmods/lib/OpenILS/WWW/EGCatLoader/Util.pm
+++ b/Open-ILS/src/perlmods/lib/OpenILS/WWW/EGCatLoader/Util.pm
@@ -229,6 +229,8 @@ sub get_records_and_facets {
     $unapi_args->{flesh_depth} ||= 5;
 
     my @data;
+    my $outer_self = $self;
+    $self->timelog("get_records_and_facets(): about to call multisession");
     my $ses = OpenSRF::MultiSession->new(
         app => 'open-ils.cstore',
         cap => 10, # XXX config
@@ -236,11 +238,14 @@ sub get_records_and_facets {
             my($self, $req) = @_;
             my $data = $req->{response}->[0]->content;
 
+            $outer_self->timelog("get_records_and_facets(): got response content");
+
             # Protect against requests for non-existent records
             return unless $data->{'unapi.bre'};
 
             my $xml = XML::LibXML->new->parse_string($data->{'unapi.bre'})->documentElement;
 
+            $outer_self->timelog("get_records_and_facets(): parsed xml");
             # Protect against legacy invalid MARCXML that might not have a 901c
             my $bre_id;
             my $bre_id_nodes =  $xml->find('*[@tag="901"]/*[@code="c"]');
@@ -250,9 +255,12 @@ sub get_records_and_facets {
                 $logger->warn("Missing 901 subfield 'c' in " . $xml->toString());
             }
             push(@data, {id => $bre_id, marc_xml => $xml});
+            $outer_self->timelog("get_records_and_facets(): end of success handler");
         }
     );
 
+    $self->timelog("get_records_and_facets(): about to call unapi.bre via json_query (rec_ids has " . scalar(@$rec_ids));
+
     $ses->request(
         'open-ils.cstore.json_query',
          {from => [
@@ -265,6 +273,8 @@ sub get_records_and_facets {
         ]}
     ) for @$rec_ids;
 
+
+    $self->timelog("get_records_and_facets():almost ready to fetch facets");
     # collect the facet data
     my $search = OpenSRF::AppSession->create('open-ils.search');
     my $facet_req = $search->request(
@@ -273,10 +283,12 @@ sub get_records_and_facets {
 
     # gather up the unapi recs
     $ses->session_wait(1);
+    $self->timelog("get_records_and_facets():past session wait");
 
     my $facets = {};
     if ($facet_key) {
         my $tmp_facets = $facet_req->gather(1);
+        $self->timelog("get_records_and_facets(): gathered facet data");
         for my $cmf_id (keys %$tmp_facets) {
 
             # sort highest to lowest match count
@@ -291,6 +303,7 @@ sub get_records_and_facets {
                 data => \@entries
             }
         }
+        $self->timelog("get_records_and_facets(): gathered/sorted facet data");
     } else {
         $facets = undef;
     }