Index: trunk/Nebulous-Server/lib/Nebulous/Server.pm
===================================================================
--- trunk/Nebulous-Server/lib/Nebulous/Server.pm	(revision 24311)
+++ trunk/Nebulous-Server/lib/Nebulous/Server.pm	(revision 24313)
@@ -53,8 +53,7 @@
     my $log = Log::Log4perl::get_logger( "Nebulous::Server" );
     $log->level($config->trace);
+    $log->debug( "entered - @_" );
 
     my $sql = Nebulous::Server::SQL->new;
-
-    $log->debug( "entered - @_" );
 
     my $self = bless {}, ref $class || $class;
@@ -74,4 +73,7 @@
     my ($self, $key) = @_;
 
+    my $log     = $self->log;
+    $log->debug( "entered - @_" );
+
     my $config  = $self->config;
 
@@ -87,4 +89,7 @@
     $db_index = unpack("h8", sha1_hex($path)) % $config->n_db;
 
+    $log->debug("index is $db_index");
+    $log->debug("leaving");
+
     return $db_index;
 }
@@ -95,4 +100,6 @@
 
     my $log     = $self->log;
+    $log->debug( "entered - @_" );
+
     my $sql     = $self->sql;
     my $config  = $self->config;
@@ -143,4 +150,6 @@
     $self->{dbs}[$db_index] = $dbh;
 
+    $log->debug("leaving");
+
     return $dbh;
 }
@@ -164,4 +173,5 @@
 
     my $dbh = $self->_db_for_index($db_index);
+
     return $dbh;
 }
@@ -170,4 +180,7 @@
 {
     my $self = shift;
+
+    my $log = $self->log;
+    $log->debug( "entered - @_" );
 
     my ($key, $vol_name) = validate_pos(@_,
@@ -188,5 +201,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -199,6 +211,4 @@
 
     my $db  = $self->db($key);
-
-    $log->debug( "entered - @_" );
 
     # the key's volume can't be validiated on input for this method so we have
@@ -307,4 +317,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug( "entered - @_" );
+
     my %p = validate(@_,
         {
@@ -328,9 +341,6 @@
     my $key = $p{key};
 
-    my $log = $self->log;
     my $sql = $self->sql;
     my $db  = $self->db($key);
-
-    $log->debug( "entered - @_" );
 
     # no path means '/', which has a dir_id & parent_id of 1
@@ -428,4 +438,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug("entered - @_");
+
     my ($key, $newkey) = validate_pos(@_,
         {
@@ -444,5 +457,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -458,6 +470,4 @@
 
     my $db  = $self->db($key);
-
-    $log->debug("entered - @_");
 
     # XXX this may require database migration in the future
@@ -504,4 +514,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug("entered - @_");
+
     my ($key1, $key2) = validate_pos(@_,
         {
@@ -519,5 +532,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -539,6 +551,4 @@
     my $dbh2 = $self->_db_for_index($dbidx2);
     die "different db handles for the same db?" unless ($dbh1 == $dbh2);
-
-    $log->debug("entered - @_");
 
     # order of operations for the swap with a single db is:
@@ -631,4 +641,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug("entered - @_");
+
     my ($key, $vol_name) = validate_pos(@_,
         {
@@ -652,5 +665,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -671,6 +683,4 @@
 
     my $db  = $self->db($key);
-
-    $log->debug("entered - @_");
 
     if (defined $vol_name
@@ -785,4 +795,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug( "entered - @_" );
+
     my ( $key, $type ) = validate_pos( @_,
         {
@@ -800,5 +813,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -810,6 +822,4 @@
 
     my $db  = $self->db($key);
-
-    $log->debug( "entered - @_" );
 
     my $so_id;
@@ -899,4 +909,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug( "entered - @_" );
+
     my ( $key, $type ) = validate_pos( @_,
         {
@@ -914,5 +927,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -924,6 +936,4 @@
 
     my $db  = $self->db($key);
-
-    $log->debug( "entered - @_" );
 
     my $so_id;
@@ -1016,4 +1026,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug("entered - @_");
+
     my ($key, $name, $value, $flags) = validate_pos(@_,
         {
@@ -1041,5 +1054,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -1051,6 +1063,4 @@
 
     my $db  = $self->db($key);
-
-    $log->debug("entered - @_");
 
 TRANS: while (1) {
@@ -1107,4 +1117,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug("entered - @_");
+
     my ($key, $name) = validate_pos(@_,
         {
@@ -1123,5 +1136,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -1133,6 +1145,4 @@
 
     my $db  = $self->db($key);
-
-    $log->debug("entered - @_");
 
     my $value;
@@ -1171,4 +1181,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug("entered - @_");
+
     my ($key) = validate_pos(@_,
         {
@@ -1180,5 +1193,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -1190,6 +1202,4 @@
 
     my $db  = $self->db($key);
-
-    $log->debug("entered - @_");
 
     my @xattrs;
@@ -1215,4 +1225,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug("entered - @_");
+
     my ($key, $name) = validate_pos(@_,
         {
@@ -1231,5 +1244,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -1241,6 +1253,4 @@
 
     my $db  = $self->db($key);
-
-    $log->debug("entered - @_");
 
 TRANS: while (1) {
@@ -1286,4 +1296,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug( "entered - @_" );
+
     my ($pattern) = validate_pos( @_,
         {
@@ -1293,5 +1306,4 @@
     );
 
-    my $log = $self->log;
 
     eval {
@@ -1299,6 +1311,4 @@
     };
     $log->logdie("$@") if $@;
-
-    $log->debug( "entered - @_" );
 
     unless (defined $pattern) {
@@ -1325,12 +1335,14 @@
 
     my $self    = shift;
+
+    my $log = $self->log;
+    $log->debug( "entered - @_" );
+
     my $index   = shift;
     my $key     = shift;
 
-    my $log = $self->log;
     my $sql = $self->sql;
     my $db  = $self->_db_for_index($index);
 
-    $log->debug( "entered - @_" );
 
     # first check to see if the key is an exact match
@@ -1390,4 +1402,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug("entered - @_");
+
     my ($key, $vol_name) = validate_pos(@_,
         {
@@ -1410,5 +1425,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -1421,6 +1435,4 @@
 
     my $db  = $self->db($key);
-
-    $log->debug("entered - @_");
 
     # the key's volume can't be validiated on input for this method so we have
@@ -1487,4 +1499,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug( "entered - @_" );
+
     my ($key, $uri) = validate_pos( @_,
         {
@@ -1499,5 +1514,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -1509,6 +1523,4 @@
 
     my $db  = $self->db($key);
-
-    $log->debug( "entered - @_" );
 
 TRANS: while (1) {
@@ -1591,4 +1603,7 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug("entered - @_");
+
     my ( $key ) = validate_pos( @_,
         {
@@ -1600,5 +1615,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -1610,6 +1624,4 @@
 
     my $db  = $self->db($key);
-
-    $log->debug("entered - @_");
 
     my $stat;
@@ -1640,11 +1652,11 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug("entered - @_");
+
     validate_pos(@_); 
 
-    my $log = $self->log;
     my $sql = $self->sql;
     my $db  = $self->_db_for_index(0); # XXX fix as above
-
-    $log->debug("entered - @_");
 
     my $stats;
@@ -1671,4 +1683,7 @@
 {
     my $self = shift;
+
+    my $log = $self->log;
+    $log->debug("entered - @_");
 
     my ($key, $mode) = validate_pos( @_, 
@@ -1690,5 +1705,4 @@
     );
 
-    my $log = $self->log;
     my $sql = $self->sql;
 
@@ -1700,6 +1714,4 @@
 
     my $db  = $self->db($key);
-
-    $log->debug("entered - @_");
 
     # find all instances of this object
@@ -1744,13 +1756,13 @@
     my $self = shift;
 
-    my ($key, $name, $soft_volume) = @_;
-
-    my $log = $self->log;
-    my $sql = $self->sql;
-    my $db  = $self->db($key);
-
+    my $log = $self->log;
     no warnings qw( uninitialized );
     $log->debug( "entered - @_" );
     use warnings;
+
+    my ($key, $name, $soft_volume) = @_;
+
+    my $sql = $self->sql;
+    my $db  = $self->db($key);
 
     my ($vol_id, $vol_host, $vol_path, $xattr);
@@ -1809,13 +1821,13 @@
     my $self = shift;
 
-    my $key = shift;
-
-    my $log = $self->log;
-    my $sql = $self->sql;
-    my $db  = $self->db($key);
-
+    my $log = $self->log;
     no warnings qw( uninitialized );
     $log->debug( "entered - @_" );
     use warnings;
+
+    my $key = shift;
+
+    my $sql = $self->sql;
+    my $db  = $self->db($key);
 
     my ($vol_id, $vol_host, $vol_path, $xattr);
@@ -1856,4 +1868,6 @@
 
     my $log = $self->log;
+    $log->debug( "entered - @_" );
+
     my $sql = $self->sql;
 
@@ -1879,7 +1893,12 @@
 
     if (defined $ext_id) {
+        $log->debug( "key is valid" );
+        $log->debug( "leaving" );
         return 1;
     } 
 
+    $log->debug( "key not found" );
+    $log->debug( "leaving" );
+
     return;
 }
@@ -1891,4 +1910,6 @@
 
     my $log = $self->log;
+    $log->debug( "entered - @_" );
+
     my $sql = $self->sql;
 
@@ -1905,4 +1926,6 @@
     # handle "any" volume
     if ($vol_name eq 'any') {
+        $log->debug( "found volume name $vol_name" );
+        $log->debug( "leaving" );
         return 1;
     }
@@ -1919,7 +1942,12 @@
 
     if (defined $vol_id and defined $vol_path) {
+        $log->debug( "found volume name $vol_name" );
+        $log->debug( "leaving" );
         return 1;
     } 
 
+    $log->debug( "volume name $vol_name not found" );
+    $log->debug( "leaving" );
+
     return;
 }
@@ -1930,7 +1958,9 @@
     my $self = shift;
 
+    my $log = $self->log;
+    $log->debug( "entered - @_" );
+
     my ($key, $so_id, $ins_id, $vol_path, $xattr) =  @_;
 
-    my $log = $self->log;
     my $sql = $self->sql;
     my $db  = $self->db($key);
@@ -1974,4 +2004,7 @@
 {
     my $self = shift;
+
+    my $log = $self->log;
+    $log->debug( "entered - @_" );
 
     my ($path) = @_;
