From 1b1311de68c227691fddbc2e829c44ba7a16144c Mon Sep 17 00:00:00 2001
From: erickson <erickson@dcc99617-32d9-48b4-a31d-7c20da2025e4>
Date: Thu, 21 Aug 2008 13:39:44 +0000
Subject: [PATCH] forcing cache timeout on staged search cacheing (*sigh*). 
 added some logging for timed out and 0-hit searches. removed warns and
 replaced with logger calls

git-svn-id: svn://svn.open-ils.org/ILS/trunk@10389 dcc99617-32d9-48b4-a31d-7c20da2025e4
---
 .../OpenILS/Application/Search/Authority.pm   |  9 +++------
 .../OpenILS/Application/Search/Biblio.pm      | 19 +++++++++++++++++--
 2 files changed, 20 insertions(+), 8 deletions(-)

diff --git a/Open-ILS/src/perlmods/OpenILS/Application/Search/Authority.pm b/Open-ILS/src/perlmods/OpenILS/Application/Search/Authority.pm
index fa5eac47d3..dfcbcf4371 100644
--- a/Open-ILS/src/perlmods/OpenILS/Application/Search/Authority.pm
+++ b/Open-ILS/src/perlmods/OpenILS/Application/Search/Authority.pm
@@ -154,11 +154,10 @@ sub new_crossref_authority_batch {
 		my $class = $req->[0];
 		my $term = $req->[1];
 		next unless $class and $term;
-		warn "Sending authority request for $class : $term\n";
+		$logger->info("Sending authority request for $class : $term");
 		my $fr = $session->request("open-ils.storage.authority.$class.see_from.controlled.atomic",$term, 10)->gather(1);
 		my $al = $session->request("open-ils.storage.authority.$class.see_also_from.controlled.atomic",$term, 10)->gather(1);
 
-		warn "Flattening $class : $term\n";
 		$response->{$class} = {} unless exists $response->{$class};
 		$response->{$class}->{$term} = _auth_flatten( $term, $fr, $al, 1 );
 
@@ -180,7 +179,7 @@ sub crossref_authority_batch {
 		my $class = $req->[0];
 		my $term = $req->[1];
 		next unless $class and $term;
-		warn "Sending authority request for $class : $term\n";
+		$logger->info("Sending authority request for $class : $term");
 		my $freq = $session->request("open-ils.storage.authority.$class.see_from.controlled.atomic",$term, 10);
 		my $areq = $session->request("open-ils.storage.authority.$class.see_also_from.controlled.atomic",$term, 10);
 
@@ -189,7 +188,6 @@ sub crossref_authority_batch {
 			my $trm = $lastr->[1];
 			my $fr	= $lastr->[2];
 			my $al	= $lastr->[3];
-			warn "Flattening $class : $term\n";
 			$response->{$cls} = {} unless exists $response->{$cls};
 			$response->{$cls}->{$trm} = _auth_flatten( $trm, $fr, $al, 1 );
 		}
@@ -205,7 +203,6 @@ sub crossref_authority_batch {
 		my $trm = $lastr->[1];
 		my $fr	= $lastr->[2];
 		my $al	= $lastr->[3];
-		warn "Flattening $cls : $trm\n";
 		$response->{$cls} = {} unless exists $response->{$cls};
 		$response->{$cls}->{$trm} = _auth_flatten( $trm, $fr, $al, 1);
 	}
@@ -244,7 +241,7 @@ sub crossref_authority_batch2 {
 
 		$logger->debug("authority data not found in cache.. fetching from storage");
 
-		warn "Sending authority request for $class : $term\n";
+		$logger->info("Sending authority request for $class : $term");
 		my $freq = $session->request("open-ils.storage.authority.$class.see_from.controlled.atomic",$term, 10);
 		my $areq = $session->request("open-ils.storage.authority.$class.see_also_from.controlled.atomic",$term, 10);
 		my $fr = $freq->gather(1);	
diff --git a/Open-ILS/src/perlmods/OpenILS/Application/Search/Biblio.pm b/Open-ILS/src/perlmods/OpenILS/Application/Search/Biblio.pm
index 09ebf4fe1e..ae40e14122 100644
--- a/Open-ILS/src/perlmods/OpenILS/Application/Search/Biblio.pm
+++ b/Open-ILS/src/perlmods/OpenILS/Application/Search/Biblio.pm
@@ -764,6 +764,7 @@ sub staged_search {
     $method .= '.staff' if $self->api_name =~ /staff$/;
     $method .= '.atomic';
 
+    my $search_duration;
     my $user_offset = $search_hash->{offset} || 0; # user-specified offset
     my $user_limit = $search_hash->{limit} || 10;
     $user_offset = ($user_offset >= 0) ? $user_offset : 0;
@@ -820,9 +821,23 @@ sub staged_search {
             $search_hash->{skip_check} = $page * $superpage_size;
             my $start = time;
             $results = $U->storagereq($method, %$search_hash);
-            $logger->info("staged search: DB call took ".(time - $start)." seconds");
+            $search_duration = time - $start;
+            $logger->info("staged search: DB call took $search_duration seconds");
             $summary = shift(@$results);
 
+            unless($summary) {
+                $logger->info("search timed out: duration=$search_duration: params=".
+                    OpenSRF::Utils::JSON->perl2JSON($search_hash));
+                return {count => 0};
+            }
+
+            my $hc = $summary->{estimated_hit_count} || $summary->{visible};
+            if($hc == 0) {
+                $logger->info("search returned 0 results: duration=$search_duration: params=".
+                    OpenSRF::Utils::JSON->perl2JSON($search_hash));
+                return {count => 0};
+            }
+
             # Create backwards-compatible result structures
             if($self->api_name =~ /biblio/) {
                 $results = [map {[$_->{id}]} @$results];
@@ -922,7 +937,7 @@ sub cache_staged_search_page {
     $logger->info("staged search: cached with key=$key, superpage=$page, estimated=".
         $summary->{estimated_hit_count}.", visible=".$summary->{visible});
 
-    $cache->put_cache($key, $data);
+    $cache->put_cache($key, $data, $cache_timeout);
 }
 
 sub search_cache {
-- 
2.43.2