From 022162774da3acb231e3f1410efed6ebaee4fd8c Mon Sep 17 00:00:00 2001 From: Phil Mesnier Date: Tue, 5 Mar 2013 21:51:05 +0000 Subject: Tue Mar 5 21:47:07 UTC 2013 Phil Mesnier --- TAO/ChangeLog | 16 +++++ TAO/utils/logWalker/GIOP_Buffer.cpp | 3 +- TAO/utils/logWalker/HostProcess.cpp | 2 +- TAO/utils/logWalker/Invocation.cpp | 32 ++++++---- TAO/utils/logWalker/Invocation.h | 2 +- TAO/utils/logWalker/Log.cpp | 115 +++++++++++++++++++++++++++--------- TAO/utils/logWalker/Log.h | 2 + TAO/utils/logWalker/PeerProcess.cpp | 6 ++ TAO/utils/logWalker/PeerProcess.h | 1 + TAO/utils/logWalker/Thread.cpp | 20 +++++-- TAO/utils/logWalker/Thread.h | 13 ++-- 11 files changed, 162 insertions(+), 50 deletions(-) (limited to 'TAO') diff --git a/TAO/ChangeLog b/TAO/ChangeLog index c156f18ec66..13a7d4e743d 100644 --- a/TAO/ChangeLog +++ b/TAO/ChangeLog @@ -1,3 +1,19 @@ +Tue Mar 5 21:47:07 UTC 2013 Phil Mesnier + + * utils/logWalker/GIOP_Buffer.cpp: + * utils/logWalker/HostProcess.cpp: + * utils/logWalker/Invocation.h: + * utils/logWalker/Invocation.cpp: + * utils/logWalker/Log.h: + * utils/logWalker/Log.cpp: + * utils/logWalker/PeerProcess.h: + * utils/logWalker/PeerProcess.cpp: + * utils/logWalker/Thread.h: + * utils/logWalker/Thread.cpp: + + Improve the parsing and readability of heavily recursive + logs. + Mon Mar 4 21:24:45 UTC 2013 Byron Harris * orbsvcs/tests/ImplRepo/RestartServer/Terminator.cpp: diff --git a/TAO/utils/logWalker/GIOP_Buffer.cpp b/TAO/utils/logWalker/GIOP_Buffer.cpp index b89baedadae..bb56112241b 100644 --- a/TAO/utils/logWalker/GIOP_Buffer.cpp +++ b/TAO/utils/logWalker/GIOP_Buffer.cpp @@ -169,7 +169,8 @@ GIOP_Buffer::GIOP_Buffer(const char *text, const char *size_str = ACE_OS::strstr(text, size_leadin); if (size_str != 0) { - size_str += 4; + size_str += 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); diff --git a/TAO/utils/logWalker/HostProcess.cpp b/TAO/utils/logWalker/HostProcess.cpp index 6f9988c163b..486911f4a8c 100644 --- a/TAO/utils/logWalker/HostProcess.cpp +++ b/TAO/utils/logWalker/HostProcess.cpp @@ -85,7 +85,7 @@ HostProcess::find_thread_for_peer (const ACE_CString &addr, Session &session) i.advance()) { i.next(thr); - PeerProcess *pp = thr->pending_peer(); + PeerProcess *pp = thr->peek_new_connection(); if (pp == 0) continue; diff --git a/TAO/utils/logWalker/Invocation.cpp b/TAO/utils/logWalker/Invocation.cpp index 2199efc1b54..0451807d875 100644 --- a/TAO/utils/logWalker/Invocation.cpp +++ b/TAO/utils/logWalker/Invocation.cpp @@ -193,14 +193,26 @@ Invocation::req_line (void) } void -Invocation::new_line (ostream &strm, int indent, bool add_nl) +Invocation::new_line (ostream &strm, int indent, int offset, bool add_nl, bool show_indent) { if (add_nl) { strm << "\n"; } - while (indent-- > 0) - strm << " "; + + if (indent > 9) + { + if (show_indent) + strm << "[indent " << indent << "] ---> "; + else + strm << " "; + } + else + { + indent += offset; + while (indent-- > 0) + strm << " "; + } } void @@ -223,7 +235,7 @@ Invocation::dump_detail (ostream &strm, } } - this->new_line (strm, indent, false); + this->new_line (strm, indent, 0, false, true); if (opname == 0 || opname[0] == 0) opname = ""; @@ -328,7 +340,7 @@ Invocation::dump_special_details (ostream &strm, int indent, const char *opname) ACE_InputCDR cdr (giop_cdr.rd_ptr(), giop_cdr.length(), giop_cdr.byte_order()); - this->new_line (strm, indent + 8, true); + this->new_line (strm, indent, 8, true, false); excep_nl = true; ACE_CDR::ULong len; if (cdr >> len) @@ -354,7 +366,7 @@ Invocation::dump_special_details (ostream &strm, int indent, const char *opname) ACE_CDR::ULong len; if (cdr >> len) { - this->new_line (strm, indent + 8, true); + this->new_line (strm, indent, 8, true, false); excep_nl = true; strm << "name (len = " << len << ") " << cdr.rd_ptr(); } @@ -373,7 +385,7 @@ Invocation::dump_special_details (ostream &strm, int indent, const char *opname) ACE_CDR::ULong count; if (cdr >> count) { - this->new_line (strm, indent + 3, true); + this->new_line (strm, indent, 3, true, false); strm << "name_seq.lengh = " << count << " "; while (count-- > 0) { @@ -421,7 +433,7 @@ Invocation::dump_special_details (ostream &strm, int indent, const char *opname) ACE_CDR::ULong len; if (cdr >> len) { - this->new_line (strm, indent + 8, true); + this->new_line (strm, indent, 8, true, false); excep_nl = true; strm << "name ( len = " << len << ") " << cdr.rd_ptr(); } @@ -448,7 +460,7 @@ Invocation::dump_special_details (ostream &strm, int indent, const char *opname) } case 2: { - this->new_line (strm, indent + 8, true); + this->new_line (strm, indent, 8, true, false); ACE_CDR::Long x; if (cdr >> x) strm << "MyID reply: " << x; @@ -459,7 +471,7 @@ Invocation::dump_special_details (ostream &strm, int indent, const char *opname) } else { - this->new_line (strm, indent + 8, excep_nl); + this->new_line (strm, indent, 8, true, false); //excep_nl, false); ACE_CDR::ULong len; if (rstat == 1 || rstat == 2) { diff --git a/TAO/utils/logWalker/Invocation.h b/TAO/utils/logWalker/Invocation.h index 0e4dacbb351..fded26d735f 100644 --- a/TAO/utils/logWalker/Invocation.h +++ b/TAO/utils/logWalker/Invocation.h @@ -81,7 +81,7 @@ public: Thread *waiter (void) const; long handle (void) const; - void new_line (ostream &strm, int indent, bool add_nl); + void new_line (ostream &strm, int indent, int offset, bool add_nl, bool show_indent); void dump_detail (ostream &strm, int indent, Dump_Mode mode, bool show_handle); void dump_special_details (ostream &strm, int indent, const char *opname); diff --git a/TAO/utils/logWalker/Log.cpp b/TAO/utils/logWalker/Log.cpp index 783b5ac63e3..bf833c76be0 100644 --- a/TAO/utils/logWalker/Log.cpp +++ b/TAO/utils/logWalker/Log.cpp @@ -267,7 +267,7 @@ Log::parse_dump_giop_msg_i (void) target = inv->octets(true); if (target == 0) { - ACE_DEBUG ((LM_DEBUG, "%d: no target octets for new recv reqeust, id = %d\n", + ACE_ERROR ((LM_ERROR, "%d: no target octets for new recv reqeust, id = %d\n", this->offset_, rid)); return; } @@ -319,7 +319,7 @@ Log::parse_dump_giop_msg_i (void) GIOP_Buffer *tgt = other_thr->giop_target(); if (target == 0) { - ACE_DEBUG ((LM_DEBUG, "%d: parse_dump_giop_msg_i, target is null, mode = %d, reqid = %d\n", + ACE_ERROR ((LM_ERROR, "%d: dump_giop_msg_i, target is null, mode = %d, reqid = %d\n", this->offset_, mode, rid)); return; } @@ -380,7 +380,7 @@ Log::parse_muxed_tms_i (void) Invocation *inv = pp->new_invocation(req_id, this->thr_); if (inv == 0) - ACE_DEBUG ((LM_DEBUG,"%d: peer %s already has invocation id %d\n", + ACE_ERROR ((LM_ERROR,"%d: peer %s already has invocation id %d\n", this->offset_, pp->id(), req_id)); this->thr_->incoming_from (pp); } @@ -403,7 +403,7 @@ Log::parse_exclusive_tms_i (void) Invocation *inv = pp->new_invocation(req_id, this->thr_); if (inv == 0) - ACE_DEBUG ((LM_DEBUG,"%d: peer %s already has invocation id %d\n", + ACE_ERROR ((LM_ERROR,"%d: peer %s already has invocation id %d\n", this->offset_, pp->id(), req_id)); this->thr_->incoming_from (pp); } @@ -443,7 +443,7 @@ Log::parse_wait_for_event_i (void) PeerProcess *pp = this->thr_->incoming(); if (pp == 0) - pp = this->thr_->pending_peer(); + pp = this->thr_->peek_new_connection(); if (pp != 0 && done) { this->thr_->exit_wait(pp, this->offset_); @@ -528,6 +528,37 @@ Log::parse_cleanup_queue_i (void) } +void +Log::parse_complete_connection_i (void) +{ + if (ACE_OS::strstr (this->info_, "failed") == 0) + return; + char *addr = ACE_OS::strrchr(this->info_,'<') +1; + char *c = ACE_OS::strchr(addr,'>'); + *c = '\0'; + // ACE_DEBUG ((LM_DEBUG, "%d, complete_connection, failed for addr %s\n", this->offset_, addr)); + + if (this->conn_waiters_.size() > 0) + { + // ACE_DEBUG ((LM_DEBUG,"%d: complete_connection: conn_waiters_.size() = %d, addr = %s\n", + // this->offset_, this->conn_waiters_.size(), addr)); + for (ACE_DLList_Iterator c_iter (this->conn_waiters_); + !c_iter.done(); + c_iter.advance()) + { + PeerProcess *waiter = 0; + c_iter.next(waiter); + if (waiter != 0 && waiter->match_server_addr (addr, session_)) + { + c_iter.remove(); + // ACE_DEBUG ((LM_DEBUG,"%d: complete_connection: purging waiter\n",this->offset_)); + delete waiter; + break; + } + } + } +} + void Log::parse_close_connection_i (void) { @@ -558,6 +589,8 @@ Log::parse_handler_open_i (bool is_ssl) PeerProcess *pp = 0; if (this->conn_waiters_.size() > 0) { + // ACE_DEBUG ((LM_DEBUG,"%d: handler_open: conn_waiters_.size() = %d, addr = %s\n", + // this->offset_, this->conn_waiters_.size(), addr)); for (ACE_DLList_Iterator c_iter (this->conn_waiters_); !c_iter.done(); c_iter.advance()) @@ -570,15 +603,19 @@ Log::parse_handler_open_i (bool is_ssl) c_iter.remove(); break; } + // else + // ACE_DEBUG ((LM_DEBUG,"%d: handler_open: no match waiter addr = %s\n", + // this->offset_, (waiter == 0 ? "" : waiter->server_addr().c_str()) )); + } } else { - pp = this->thr_->pending_peer(); + pp = this->thr_->pop_new_connection(); } if (pp == 0) { - ACE_ERROR ((LM_ERROR,"%d: no pending peer for addr %s\n", + ACE_ERROR ((LM_ERROR,"%d: handler_open: no pending peer for addr %s\n", this->offset_, addr)); return; } @@ -621,7 +658,6 @@ Log::parse_handler_open_i (bool is_ssl) pp->add_transport(trans); } trans->handle_ = handle; - this->thr_->pending_peer(0); this->hostproc_->add_peer (handle,pp); } @@ -638,7 +674,17 @@ Log::parse_begin_connection_i (void) pp->set_server_addr (addr); } this->conn_waiters_.insert_tail (pp); - this->thr_->pending_peer (pp); + this->thr_->push_new_connection (pp); + // ACE_DEBUG ((LM_DEBUG,"%d: begin_connection: pushing pp for addr %s\n", offset_,addr)); +} + +void +Log::parse_connection_handler_ctor_i (void) +{ + char *c = ACE_OS::strchr (this->info_, '[') + 1; + size_t handle = ACE_OS::strtol (c, 0, 10); + // ACE_DEBUG ((LM_DEBUG,"%d: constructed new handler for %d\n", offset_, handle)); + } void @@ -648,7 +694,7 @@ Log::parse_local_addr_i (void) char *c = ACE_OS::strchr(addr,'>'); *c = '\0'; - PeerProcess *peer = this->thr_->pending_peer(); + PeerProcess *peer = this->thr_->peek_new_connection(); if (peer == 0) { this->thr_->pending_local_addr (addr); @@ -670,22 +716,31 @@ Log::parse_local_addr_i (void) void Log::parse_connection_not_complete_i (void) { - this->thr_->pending_peer (0); + PeerProcess *pp = this->thr_->pop_new_connection (); + if (pp != 0) + { + // ACE_DEBUG ((LM_DEBUG,"%d: connection_not_complete: popping pp from %d\n", + // offset_, pp->offset())); + } + else + ACE_DEBUG ((LM_DEBUG,"%d: connection_not_complete: no pending peer\n", offset_)); } void Log::parse_open_as_server_i (void) { - this->thr_->pending_peer (new PeerProcess(this->offset_, false)); + // ACE_DEBUG ((LM_DEBUG,"%d: open_as_server: adding peer process\n", offset_)); + + this->thr_->push_new_connection (new PeerProcess(this->offset_, false)); } void Log::parse_iiop_connection_handler_ctor_i (void) { - PeerProcess *pp = this->thr_->pending_peer(); + PeerProcess *pp = this->thr_->peek_new_connection(); if (pp == 0) { - ACE_ERROR ((LM_ERROR, "%d: parse_iiop_connection_handler_ctor_i: no pending peer on thread\n", this->offset_)); + ACE_ERROR ((LM_ERROR, "%d: iiop_connection_handler_ctor_i: no pending peer on thread\n", this->offset_)); return; } @@ -699,13 +754,14 @@ Log::parse_iiop_connection_handler_ctor_i (void) void Log::parse_wait_for_connection_i (void) { - ACE_ERROR ((LM_ERROR,"%d: parse_wait_for_connection, line = %s\n", this->offset_, this->line_)); + // ACE_ERROR ((LM_ERROR,"%d: wait_for_connection, line = %s\n", this->offset_, this->info_)); if (ACE_OS::strstr (this->info_,"Connection not complete") == 0) { return; } else if (ACE_OS::strstr (this->info_,"wait done result =") == 0) { +#if 0 char *pos = ACE_OS::strchr (this->info_, '=') + 2; int result = ACE_OS::strtol (pos, 0, 10); if (result == 1) @@ -714,7 +770,7 @@ Log::parse_wait_for_connection_i (void) long handle = ACE_OS::strtol (pos, 0, 10); PeerProcess *pp = 0; - ACE_DEBUG ((LM_DEBUG, "%d: parse_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) { @@ -738,32 +794,29 @@ Log::parse_wait_for_connection_i (void) } else { - pp = this->thr_->pending_peer(); + pp = this->thr_->pop_new_connection (); Transport *t = pp->find_transport (handle); if (t == 0) { + this->thr_->push_new_connection (pp); pp = 0; } - else - { - this->thr_->pending_peer (0); - } } if (pp == 0) { - ACE_ERROR ((LM_ERROR,"%d: no pending peer for handle %s\n", + ACE_ERROR ((LM_ERROR,"%d: wait_for_connection: no pending peer for handle %s\n", this->offset_, handle)); return; } delete pp; - +#endif } } void Log::parse_post_open_i (void) { - // ACE_ERROR ((LM_ERROR,"%d: parse_post_open, line = %s\n", this->offset_, this->line_)); + // ACE_ERROR ((LM_ERROR,"%d: post_open, line = %s\n", this->offset_, this->line_)); } void @@ -772,7 +825,7 @@ Log::parse_notify_poa_helper_i (void) Invocation *inv = this->thr_->current_invocation (); if (inv == 0) { - ACE_ERROR ((LM_ERROR,"%d: parse_notify_poa_helper line = %s, no current invocation on thread\n", this->offset_, this->info_)); + ACE_ERROR ((LM_ERROR,"%d: notify_poa_helper line = %s, no current invocation on thread\n", this->offset_, this->info_)); return; } bool activate = ACE_OS::strstr (this->info_, "Activating") != 0; @@ -796,7 +849,7 @@ Log::parse_notify_object_i (void) Invocation *inv = this->thr_->current_invocation (); if (inv == 0) { - // ACE_ERROR ((LM_ERROR,"%d: parse_notify_object line = %s, no current invocation on thread\n", this->offset_, this->info_)); + // ACE_ERROR ((LM_ERROR,"%d: notify_object line = %s, no current invocation on thread\n", this->offset_, this->info_)); } char *ptr = ACE_OS::strstr (this->info_, "object:") + 7; @@ -939,10 +992,18 @@ Log::parse_line (void) { this->parse_close_connection_i(); } + else if (ACE_OS::strstr (this->info_, "complete_connection, connection to") != 0) + { + this->parse_complete_connection_i(); + } else if (ACE_OS::strstr (this->info_, "IIOP_Connector::begin_connection, to ") != 0) { this->parse_begin_connection_i(); } + else if (ACE_OS::strstr (this->info_, "::IIOP_Connection_Handler ") != 0) + { + this->parse_connection_handler_ctor_i(); + } else if (ACE_OS::strstr (this->info_, "IIOP_Connection_Handler::open, The local addr is") != 0) { this->parse_local_addr_i(); @@ -959,7 +1020,7 @@ Log::parse_line (void) { this->parse_got_existing_i(); } - else if (ACE_OS::strstr (this->info_, "Transport_Connector::wait_for_connection_competion") != 0) + else if (ACE_OS::strstr (this->info_, "Transport_Connector::wait_for_connection_completion") != 0) { this->parse_wait_for_connection_i(); } diff --git a/TAO/utils/logWalker/Log.h b/TAO/utils/logWalker/Log.h index 682f7a21bb6..57cccfb8c74 100644 --- a/TAO/utils/logWalker/Log.h +++ b/TAO/utils/logWalker/Log.h @@ -52,6 +52,7 @@ protected: bool match_target(void); void parse_handler_open_i (bool is_ssl); + void parse_connection_handler_ctor_i (void); void parse_dump_giop_msg_i (void); void parse_HEXDUMP_i (void); void parse_open_listener_i (void); @@ -62,6 +63,7 @@ protected: void parse_wait_for_event_i (void); void parse_wait_on_read_i (void); void parse_cleanup_queue_i (void); + void parse_complete_connection_i (void); void parse_close_connection_i (void); void parse_begin_connection_i (void); void parse_local_addr_i (void); diff --git a/TAO/utils/logWalker/PeerProcess.cpp b/TAO/utils/logWalker/PeerProcess.cpp index 00e51c68d77..f3c03a6b03f 100644 --- a/TAO/utils/logWalker/PeerProcess.cpp +++ b/TAO/utils/logWalker/PeerProcess.cpp @@ -110,6 +110,12 @@ PeerProcess::is_server (void) const return this->server_; } +size_t +PeerProcess::offset (void) const +{ + return this->origin_offset_; +} + void PeerProcess::ssl (bool is_ssl) { diff --git a/TAO/utils/logWalker/PeerProcess.h b/TAO/utils/logWalker/PeerProcess.h index 59ebacbcd64..f90e4004c34 100644 --- a/TAO/utils/logWalker/PeerProcess.h +++ b/TAO/utils/logWalker/PeerProcess.h @@ -55,6 +55,7 @@ public: const ACE_CString &last_client_addr (void) const; bool is_server (void) const; + size_t offset (void) const; void ssl (bool is_ssl); void add_transport (Transport *t); Transport *last_transport (void); diff --git a/TAO/utils/logWalker/Thread.cpp b/TAO/utils/logWalker/Thread.cpp index a9e2f2394cb..69850e2daf3 100644 --- a/TAO/utils/logWalker/Thread.cpp +++ b/TAO/utils/logWalker/Thread.cpp @@ -16,7 +16,7 @@ Thread::Thread (long tid, const char *alias, size_t offset) nested_ (0), pending_(), incoming_(0), - new_connection_(0), + new_connection_(), giop_target_(0), target_dup_(0), current_invocation_ (), @@ -26,15 +26,25 @@ Thread::Thread (long tid, const char *alias, size_t offset) } void -Thread::pending_peer (PeerProcess *pp) +Thread::push_new_connection (PeerProcess *pp) { - this->new_connection_ = pp; + this->new_connection_.push (pp); } PeerProcess * -Thread::pending_peer (void) const +Thread::pop_new_connection (void) { - return this->new_connection_; + PeerProcess *pp = 0; + this->new_connection_.pop (pp); + return pp; +} + +PeerProcess * +Thread::peek_new_connection (void) const +{ + PeerProcess *pp = 0; + this->new_connection_.top (pp); + return pp; } void diff --git a/TAO/utils/logWalker/Thread.h b/TAO/utils/logWalker/Thread.h index d6bf5f5d7b1..9e5da0fec12 100644 --- a/TAO/utils/logWalker/Thread.h +++ b/TAO/utils/logWalker/Thread.h @@ -13,7 +13,7 @@ #include "Invocation.h" #include "PeerProcess.h" -typedef ACE_Unbounded_Stack UpcallStack; +typedef ACE_Unbounded_Stack PeerProcessStack; typedef ACE_Unbounded_Stack InvocationStack; class Thread @@ -40,8 +40,11 @@ public: void dump_detail (ostream &strm) const; void dump_invocations (ostream &strm); void get_summary (long &sent_reqs, long &recv_reqs, size_t &sent_size, size_t &recv_size); - PeerProcess *pending_peer (void) const; - void pending_peer (PeerProcess *pp); + + void push_new_connection (PeerProcess *pp); + PeerProcess *pop_new_connection (void); + PeerProcess *peek_new_connection (void) const; + void pending_local_addr (const ACE_CString &addr); const ACE_CString& pending_local_addr (void) const; void active_handle (long handle); @@ -58,9 +61,9 @@ private: long client_encounters_; long server_encounters_; long nested_; - UpcallStack pending_; + PeerProcessStack pending_; PeerProcess *incoming_; - PeerProcess *new_connection_; + PeerProcessStack new_connection_; ACE_CString pending_local_addr_; GIOP_Buffer *giop_target_; Thread *target_dup_; -- cgit v1.2.1