Merge pull request #77 from pmesnier/master

log walker updates

7 files changed, 94 insertions, 26 deletions

diff --git a/TAO/utils/logWalker/GIOP_Buffer.cpp b/TAO/utils/logWalker/GIOP_Buffer.cpp
index fa199d2bfbd..10311aeb0dc 100644
--- a/TAO/utils/logWalker/GIOP_Buffer.cpp
+++ b/TAO/utils/logWalker/GIOP_Buffer.cpp
@@ -130,7 +130,8 @@ GIOP_Buffer::GIOP_Buffer(void)
     msg_size_ (0),
     num_contexts_ (0),
     header_parsed_ (false),
-    payload_start_ (0)
+    payload_start_ (0),
+    payload_size_ (0)
 {
 }
 
@@ -162,13 +163,14 @@ GIOP_Buffer::GIOP_Buffer(const char *text,
     msg_size_ (0),
     num_contexts_ (0),
     header_parsed_ (false),
-    payload_start_ (0)
+    payload_start_ (0),
+    payload_size_ (0)
 {
   const char *size_str = ACE_OS::strstr(text, size_leadin);
   if (size_str != 0)
     {
-      size_str += ACE_OS::strlen (size_leadin);
-      size_str += 3;
+      size_str += leadin_len; //ACE_OS::strlen (size_leadin);
+      //      size_str += 3;
       this->expected_size_ = ACE_OS::strtol(size_str, 0, 10);
       const char *id = ACE_OS::strchr(size_str, '[') + 1;
       this->expected_req_id_ = ACE_OS::strtol(id, 0, 10);
@@ -181,11 +183,11 @@ GIOP_Buffer::GIOP_Buffer(const char *text,
       char timebuf[30];
       ACE_OS::strncpy(timebuf, text, (time_tok - text));
       timebuf[time_tok - text] = 0;
-      char *hms = ACE_OS::strchr (timebuf,' ');
+      char *hms = ACE_OS::strchr (timebuf,':');
       if (hms != 0)
         {
           int hr, min, sec, msec;
-          ::sscanf (hms+1,"%d:%d:%d.%d", &hr, &min, &sec, &msec);
+          ::sscanf (hms-2,"%d:%d:%d.%d", &hr, &min, &sec, &msec);
           this->time_ = (hr * 3600 + min *60 + sec) * 1000 + msec;
         }
     }
@@ -210,6 +212,7 @@ GIOP_Buffer::init_buf (const char *text, size_t offset)
   this->log_offset_ = offset;
   const char * size_str = ACE_OS::strstr (text,"HEXDUMP ") + 8;
   this->buffer_size_ = ACE_OS::strtol (size_str, 0, 10);
+  this->payload_size_ = this->buffer_size_ - 12;
   size_str =  ACE_OS::strstr (text,"showing first ");
   if (size_str != 0)
     {
@@ -371,7 +374,7 @@ GIOP_Buffer::msg_size (void)
     return 0;
   if (!this->header_parsed_)
     this->header_parsed_ = this->parse_header();
-  return this->msg_size_;
+  return (size_leadin == size_leadin_1_5) ? this->payload_size_ : this->msg_size_;
 }
 
 size_t
@@ -568,6 +571,7 @@ GIOP_Buffer::reset (void)
   this->octets_ = 0;
   this->wr_pos_ = 0;
   this->buffer_size_ = 0;
+  this->payload_size_ = 0;
   this->buffer_lost_ = true;
   this->header_parsed_ = false;
   this->opname_ = 0;
@@ -580,6 +584,7 @@ GIOP_Buffer::transfer_from (GIOP_Buffer *other)
   this->octets_ = other->octets_;
   this->wr_pos_ = other->wr_pos_;
   this->buffer_size_ = other->buffer_size_;
+  this->payload_size_ = other->payload_size_;
   this->header_parsed_ = false;
   other->reset();
 }
@@ -589,13 +594,16 @@ GIOP_Buffer::swap (GIOP_Buffer *other)
 {
   char *tmp_octets = this->octets_;
   char *tmp_wr_pos = this->wr_pos_;
-  size_t tmp_size = this->buffer_size_;
+  size_t tmp_bsize = this->buffer_size_;
+  size_t tmp_psize = this->payload_size_;
 
   this->octets_ = other->octets_;
   this->wr_pos_ = other->wr_pos_;
   this->buffer_size_ = other->buffer_size_;
+  this->payload_size_ = other->payload_size_;
 
   other->octets_ = tmp_octets;
   other->wr_pos_ = tmp_wr_pos;
-  other->buffer_size_ = tmp_size;
+  other->buffer_size_ = tmp_bsize;
+  other->payload_size_= tmp_psize;
 }
diff --git a/TAO/utils/logWalker/GIOP_Buffer.h b/TAO/utils/logWalker/GIOP_Buffer.h
index 0c9f9002671..03d74e8c9be 100644
--- a/TAO/utils/logWalker/GIOP_Buffer.h
+++ b/TAO/utils/logWalker/GIOP_Buffer.h
@@ -111,6 +111,7 @@ private:
   size_t  num_contexts_;
   bool header_parsed_;
   char * payload_start_;
+  size_t payload_size_;
 };
 
 #endif // LOG_WALKER_GIOP_BUFFER_H
diff --git a/TAO/utils/logWalker/Log.cpp b/TAO/utils/logWalker/Log.cpp
index 6a5e322c5c8..a86fd2937bf 100644
--- a/TAO/utils/logWalker/Log.cpp
+++ b/TAO/utils/logWalker/Log.cpp
@@ -456,6 +456,15 @@ Log::parse_wait_on_read_i (void)
 }
 
 void
+Log::parse_make_idle_i (void)
+{
+  char *hpos = ACE_OS::strchr(this->info_,'[');
+  long handle = ACE_OS::strtol(hpos+1,0,10);
+  PeerProcess *pp = this->hostproc_->find_peer(handle);
+  this->thr_->exit_wait (pp, this->offset_);
+}
+
+void
 Log::parse_cleanup_queue_i (void)
 {
   char *hpos = ACE_OS::strchr(this->info_,'[');
@@ -584,7 +593,7 @@ Log::parse_handler_open_i (bool is_ssl)
   if (*c == '[')
     c++;
   long handle = ACE_OS::strtol(c,0,10);
-  PeerProcess *pp = 0;
+  PeerProcess *pp = this->thr_->peek_new_connection();
   if (this->conn_waiters_.size() > 0)
     {
       // ACE_DEBUG ((LM_DEBUG,"%d: handler_open: conn_waiters_.size() = %d, addr = %s\n",
@@ -597,13 +606,27 @@ Log::parse_handler_open_i (bool is_ssl)
           c_iter.next(waiter);
           if (waiter != 0 && waiter->match_server_addr (addr))
             {
+              if (pp != 0 && waiter != pp)
+                {
+                  // ACE_DEBUG ((LM_DEBUG,"%d: handler_open: found waiter other than for tid %d\n",
+                  //             this->offset_, thr_->id ()));
+                  continue;
+                }
+              // ACE_DEBUG ((LM_DEBUG,"%d: handler_open: found waiter addr = %s:%s\n",
+              //           this->offset_,
+              //           (waiter == 0 ? "<null>" :  waiter->server_addr().host_.c_str()),
+              //           (waiter == 0 ? "<null>" :  waiter->server_addr().port_.c_str())
+              //           ));
               pp = waiter;
               c_iter.remove();
               break;
             }
           // else
-          //   ACE_DEBUG ((LM_DEBUG,"%d: handler_open: no match waiter addr = %s\n",
-          //               this->offset_, (waiter == 0 ? "<null>" :  waiter->server_addr().c_str()) ));
+            // ACE_DEBUG ((LM_DEBUG,"%d: handler_open: no match waiter addr = %s:%s\n",
+            //             this->offset_,
+            //             (waiter == 0 ? "<null>" :  waiter->server_addr().host_.c_str()),
+            //             (waiter == 0 ? "<null>" :  waiter->server_addr().port_.c_str())
+            //             ));
         }
     }
 
@@ -625,6 +648,9 @@ Log::parse_handler_open_i (bool is_ssl)
   const ACE_CString &local_addr = this->thr_->pending_local_addr();
   if (local_addr.length() > 0 )
     {
+      // ACE_DEBUG ((LM_DEBUG,"%d: handler_open: local addr = %s, pp is server = %d\n",
+      //             this->offset_, local_addr.c_str(), pp->is_server() ));
+
       if (pp->is_server())
         {
           Transport *t = new Transport (local_addr.c_str(), true, this->offset_);
@@ -637,6 +663,10 @@ Log::parse_handler_open_i (bool is_ssl)
         }
       this->thr_->pending_local_addr ("");
     }
+  // else
+  //   ACE_DEBUG ((LM_DEBUG,"%d: handler_open: tid %d, local addr = empty\n",
+  //               this->offset_, this->thr_->id () ));
+
 
   Transport *trans = 0;
   if (pp->is_server())
@@ -650,7 +680,7 @@ Log::parse_handler_open_i (bool is_ssl)
                       this->offset_, this->origin_.c_str()));
           return;
         }
-      //      trans->client_endpoint_ = addr;
+
     }
   else
     {
@@ -675,7 +705,8 @@ Log::parse_begin_connection_i (void)
     }
   this->conn_waiters_.insert_tail (pp);
   this->thr_->push_new_connection (pp);
-  // ACE_DEBUG ((LM_DEBUG,"%d: begin_connection: pushing pp for addr %s\n", offset_,addr));
+  // ACE_DEBUG ((LM_DEBUG,"%d: begin_connection: tid %d pushing pp for addr %s\n",
+  //             offset_,thr_->id (), addr));
 }
 
 void
@@ -697,12 +728,16 @@ Log::parse_local_addr_i (void)
   PeerProcess *peer = this->thr_->peek_new_connection();
   if (peer == 0)
     {
+      // ACE_DEBUG ((LM_DEBUG, "%d: local_addr: thr %d, pending = %s\n",
+      //             offset_, thr_->id(), addr));
       this->thr_->pending_local_addr (addr);
       return;
     }
 
   if (peer->is_server())
     {
+      // ACE_DEBUG ((LM_DEBUG, "%d: local_addr: thr %d, peer is server addr = %s\n",
+      //             offset_, thr_->id(), addr));
       Transport *t = new Transport (addr, true, this->offset_);
       peer->add_transport (t);
       this->hostproc_->add_client_endpoint (t->client_endpoint_);
@@ -723,7 +758,7 @@ Log::parse_connection_not_complete_i (void)
       //             offset_, pp->offset()));
     }
   else
-    ACE_DEBUG ((LM_DEBUG,"%d: connection_not_complete: no pending peer\n", offset_));
+    ACE_ERROR ((LM_ERROR,"%d: connection_not_complete: no pending peer\n", offset_));
 }
 
 void
@@ -770,7 +805,10 @@ Log::parse_wait_for_connection_i (void)
       long handle = ACE_OS::strtol (pos, 0, 10);
       PeerProcess *pp = 0;
 
-      ACE_DEBUG ((LM_DEBUG, "%d: wait_for_connection: wait done, result = %d, purging handle = %d\n", this->offset_, result, handle));
+      // ACE_DEBUG ((LM_DEBUG,
+      //             "%d: wait_for_connection: wait done, result = %d, "
+      //             "purging handle = %d\n",
+      //             this->offset_, result, handle));
 
       if (this->conn_waiters_.size() > 0)
         {
@@ -984,6 +1022,10 @@ Log::parse_line (void)
     {
       this->parse_wait_on_read_i();
     }
+  else if (ACE_OS::strstr (this->info_, "::make_idle") != 0)
+    {
+      this->parse_make_idle_i();
+    }
   else if (ACE_OS::strstr (this->info_, "::cleanup_queue, byte_count") != 0)
     {
       this->parse_cleanup_queue_i();
diff --git a/TAO/utils/logWalker/Log.h b/TAO/utils/logWalker/Log.h
index c7c44d501c5..bd5fafe48f0 100644
--- a/TAO/utils/logWalker/Log.h
+++ b/TAO/utils/logWalker/Log.h
@@ -61,6 +61,7 @@ protected:
   void parse_process_parsed_msgs_i (void);
   void parse_wait_for_event_i (void);
   void parse_wait_on_read_i (void);
+  void parse_make_idle_i (void);
   void parse_cleanup_queue_i (void);
   void parse_complete_connection_i (void);
   void parse_close_connection_i (void);
diff --git a/TAO/utils/logWalker/PeerProcess.cpp b/TAO/utils/logWalker/PeerProcess.cpp
index 999a5974563..f405d40d51d 100644
--- a/TAO/utils/logWalker/PeerProcess.cpp
+++ b/TAO/utils/logWalker/PeerProcess.cpp
@@ -38,7 +38,7 @@ Endpoint::assign (const char *addr, EndpointRole role)
   this->addr_ = addr;
   this->role_ = role;
   size_t p = addr_.rfind (':');
-  this->port_ = addr_.substring(p);
+  this->port_ = addr_.substring(p+1);
   this->host_ = addr_.substring(0,p);
 
   this->is_localhost_ = this->host_ == "localhost" ||
@@ -105,13 +105,18 @@ PeerProcess::nextIdent(bool is_server)
 }
 
 PeerProcess::PeerProcess (size_t offset, bool is_server)
-  : owner_ (0),
+  : ident_ (0),
+    origin_ (0),
+    owner_ (0),
     remote_ (0),
-    server_ep_(),
+    server_ep_ (),
+    transports_ (),
+    last_transport_ (0),
     is_server_role_(is_server),
     ssl_(false),
     origin_offset_ (offset),
     objects_ (),
+    invocations_ (),
     object_by_index_ ()
 {
   this->ident_ = PeerProcess::nextIdent(is_server);
diff --git a/TAO/utils/logWalker/Session.cpp b/TAO/utils/logWalker/Session.cpp
index 0d1a7549f3c..a1e63fd2ea6 100644
--- a/TAO/utils/logWalker/Session.cpp
+++ b/TAO/utils/logWalker/Session.cpp
@@ -7,7 +7,7 @@
 #include "ace/OS_NS_sys_stat.h"
 
 long
-Session::tao_version_ = 200;
+Session::tao_version_ = 220;
 
 AltAddresses
 Session::alt_addrs_;
@@ -43,6 +43,8 @@ Session::set_tao_version (ACE_TCHAR *str)
     tao_version_ = 180;
   else if (ACE_OS::strncmp (str, ACE_TEXT("2.0"), 3) == 0)
     tao_version_ = 200;
+  else if (ACE_OS::strncmp (str, ACE_TEXT("2.2"), 3) == 0)
+    tao_version_ = 220;
   else
     return false;
   return true;
diff --git a/TAO/utils/logWalker/Thread.cpp b/TAO/utils/logWalker/Thread.cpp
index 9149e3e3568..c66d73b10d7 100644
--- a/TAO/utils/logWalker/Thread.cpp
+++ b/TAO/utils/logWalker/Thread.cpp
@@ -89,8 +89,16 @@ Thread::exit_wait (PeerProcess *pp, size_t linenum)
                   "Line %d, Ending an invocation to peer %s, but most recent started"
                   " is to peer %s\n", linenum, pp->id(), old->id()));
       //      this->pending_.push(old);
-  if (this->pending_.pop(old) == -1)
-    return;
+      if (this->pending_.pop(old) == -1)
+        return;
+    }
+  if (this->pending_.top (old) == 0)
+    {
+      this->active_handle (old->last_transport ()->handle_);
+    }
+  else
+    {
+      this->active_handle (0);
     }
 }
 
@@ -225,10 +233,11 @@ void
 Thread::dump_detail (ostream &strm)
 {
   strm << "   " << this->alias_ << " tid = 0x" << hex << this->id_
-       << "\tfirst line " << dec << this->first_line_ << "\t"
-       << this->server_encounters_ << " requests sent "
-       << this->client_encounters_ << " requests received";
-  if (this->count_nesting () > 0)
+       << " (" << dec << this->id_
+       << ")\tfirst line " << this->first_line_ << " \t"
+       << this->client_encounters_ << " requests sent "
+       << this->server_encounters_ << " requests received";
+  if (this->count_nesting () > 0 && this->max_depth_ > 0)
     strm <<", with " << this->nested_ << " nested upcalls, max depth "
          << this->max_depth_;
   strm << endl;