TAO/utils/logWalker/Invocation.cpp

   1 #include "Invocation.h"
   2 #include "GIOP_Buffer.h"
   3 #include "PeerProcess.h"
   4 #include "PeerObject.h"
   5 #include "Session.h"
   6 #include "HostProcess.h"
   7 #include "Thread.h"
   8
   9 #include "ace/OS_NS_string.h"
  10 #include "ace/OS_NS_stdio.h"
  11 #include "ace/Log_Msg.h"
  12
  13 Invocation::Invocation (PeerProcess *peer, Thread *thr, size_t rid)
  14   :req_octets_(0),
  15    repl_octets_(0),
  16    waiter_ (thr),
  17    notify_incidents_ (),
  18    peer_(peer),
  19    req_id_(rid),
  20    target_(0),
  21    handle_(thr->active_handle()),
  22    finish_reported_(false),
  23    req_level_ (0),
  24    repl_level_ (0)
  25 {
  26 }
  27
  28 Invocation::~Invocation ()
  29 {
  30   delete this->req_octets_;
  31   delete this->repl_octets_;
  32 }
  33
  34 bool
  35 Invocation::init (const char * text, size_t offset, Thread *thread)
  36 {
  37   if (GIOP_Buffer::size_leadin == 0)
  38     GIOP_Buffer::init_leadin (Session::tao_version());
  39   const char *size_str = ACE_OS::strstr(text, GIOP_Buffer::size_leadin);
  40   const char *id = size_str == 0 ? 0 : ACE_OS::strchr(size_str, '[');
  41   if (size_str == 0 || id == 0)
  42     {
  43       ACE_ERROR ((LM_ERROR,
  44                   "Not a request preamble line %d:\n '%s'\n",offset,
  45                   text));
  46       return false;
  47   }
  48
  49   if( ACE_OS::strstr(text,"Request") == 0)
  50     this->repl_octets_ = new GIOP_Buffer(text, offset, thread, this);
  51   else
  52     this->req_octets_  = new GIOP_Buffer(text, offset, thread, this);
  53   return true;
  54 }
  55
  56 void
  57 Invocation::add_notify_incident (const ACE_CString &text, size_t /* offset */)
  58 {
  59   this->notify_incidents_.enqueue_tail (text);
  60 }
  61
  62 bool
  63 Invocation::is_oneway() const
  64 {
  65   return this->req_octets_ == 0 ? false : this->req_octets_->is_oneway();
  66 }
  67
  68 void
  69 Invocation::set_target (const char *oid, size_t oid_len)
  70 {
  71   PeerObject *tgt = this->peer_->object_for (oid, oid_len);
  72   if (tgt == 0)
  73     return;
  74
  75   if (this->target_ == 0)
  76     {
  77       this->target_ = tgt;
  78       this->target_->add_invocation (this);
  79     }
  80 }
  81
  82 bool
  83 Invocation::message_complete ()
  84 {
  85   if (this->is_oneway())
  86     {
  87       if (this->req_octets_ == 0 || !this->req_octets_->is_full())
  88         return false;
  89     }
  90   else
  91     if (this->repl_octets_ == 0 || !this->repl_octets_->is_full())
  92       return false;
  93
  94   return true;
  95 }
  96
  97 GIOP_Buffer *
  98 Invocation::octets (bool request)
  99 {
 100   return request ? this->req_octets_ : this->repl_octets_ ;
 101 }
 102
 103 GIOP_Buffer *
 104 Invocation::give_octets (bool request)
 105 {
 106   GIOP_Buffer *result = request ? this->req_octets_ : this->repl_octets_ ;
 107
 108   if (request)
 109     this->req_octets_ = 0;
 110   else
 111     this->repl_octets_ = 0;
 112   return result;
 113 }
 114
 115 void
 116 Invocation::set_octets (bool request, GIOP_Buffer *octets)
 117 {
 118   if (request)
 119     {
 120       if (this->req_octets_ != 0)
 121         {
 122           return;
 123         }
 124       this->req_octets_ = octets;
 125     }
 126   else
 127     {
 128       if (this->repl_octets_ != 0)
 129         {
 130           return;
 131         }
 132       this->repl_octets_ = octets;
 133     }
 134   octets->owner(this);
 135 }
 136
 137 bool
 138 Invocation::sent_request () const
 139 {
 140   if (this->req_octets_)
 141     return this->req_octets_->sending();
 142   if (this->repl_octets_)
 143     return !this->repl_octets_->sending();
 144   return false;
 145 }
 146
 147 size_t
 148 Invocation::request_id () const
 149 {
 150   return this->req_octets_ == 0 ? this->req_id_ : this->req_octets_->expected_req_id();
 151 }
 152
 153 size_t
 154 Invocation::expected_size () const
 155 {
 156   if (repl_octets_ != 0)
 157     return repl_octets_->expected_size();
 158   return req_octets_->expected_size();
 159 }
 160
 161 size_t
 162 Invocation::request_bytes () const
 163 {
 164   return req_octets_ != 0 ? req_octets_->expected_size() : 0;
 165 }
 166
 167 Thread *
 168 Invocation::waiter () const
 169 {
 170   return this->waiter_;
 171 }
 172
 173 long
 174 Invocation::handle () const
 175 {
 176   return this->handle_;
 177 }
 178
 179 bool
 180 Invocation::contains (size_t line)
 181 {
 182   if (this->req_octets_ == 0 || this->is_oneway())
 183     return false;
 184   return
 185     line > this->req_octets_->log_posn() &&
 186     (this->repl_octets_ == 0 || line < this->repl_octets_->log_posn());
 187 }
 188
 189 size_t
 190 Invocation::req_line ()
 191 {
 192   return this->req_octets_ == 0 ? 0 : this->req_octets_->log_posn();
 193 }
 194
 195 size_t
 196 Invocation::repl_line ()
 197 {
 198   return this->repl_octets_ == 0 ? 0 : this->repl_octets_->log_posn();
 199 }
 200
 201 void
 202 Invocation::new_line (ostream &strm, size_t indent, int offset, bool add_nl, bool show_indent)
 203 {
 204   if (add_nl)
 205     {
 206       strm << "\n";
 207     }
 208
 209   size_t steps = indent / 20;
 210   size_t extra = indent % 20;
 211
 212   if (steps > 1)
 213     {
 214       if (show_indent)
 215         {
 216           strm << "[indent " << steps * 20 << "] --->";
 217           extra += (indent > 99) ? 5 : 4;
 218         }
 219       else
 220         {
 221           extra += 20;
 222         }
 223     }
 224   else
 225     {
 226       extra += (steps * 20);
 227     }
 228
 229   extra += offset;
 230   while (extra-- > 0)
 231     strm << " ";
 232 }
 233
 234 void
 235 Invocation::dump_rel_time (ostream &strm, const ACE_Time_Value &tv, const ACE_Time_Value& start)
 236 {
 237   ACE_Time_Value reltime = tv - start;
 238   int hours = (int)(reltime.sec()) / 3600;
 239   int min = (int)(reltime.sec() %3600) / 60;
 240   int sec = (int)(reltime.sec()) % 60;
 241   int subsec = (int)(reltime.usec()/1000);
 242
 243   char buffer[20];
 244   ACE_OS::snprintf (buffer, 20, "%d:%02d:%02d.%03d",
 245               hours, min, sec, subsec);
 246
 247   strm << buffer << ' ';
 248 }
 249
 250 void
 251 Invocation::dump_start_line (ostream &strm, size_t indent, const ACE_Time_Value& start)
 252 {
 253   if (this->req_octets_ == 0)
 254     return;
 255   this->req_level_ = indent;
 256   strm << setw(7) << this->req_octets_->log_posn() << " " << setw(0);
 257
 258   const ACE_Time_Value &tv = this->req_octets_->time();
 259   if (tv != ACE_Time_Value::zero)
 260     {
 261       dump_rel_time (strm, tv, start);
 262     }
 263
 264   const char *opname = "";
 265   const char *dir_1 = "sent to ";
 266   const char *dir_2 = " in ";
 267
 268   if (this->req_octets_ != 0)
 269     {
 270       opname = this->req_octets_->operation();
 271       if (this->req_octets_->sending())
 272         {
 273           dir_1 = "recv for ";
 274           dir_2 = " from ";
 275         }
 276     }
 277
 278   this->new_line (strm, indent, 0, false, true);
 279
 280   strm << "start request ";
 281
 282   if (opname == 0 || opname[0] == 0)
 283     opname = "<no operation>";
 284
 285   strm << dir_1;
 286   if (this->target_ == 0)
 287     strm << "<unknown object>" ;
 288   else
 289     strm << this->target_->name();
 290   strm << dir_2 << this->peer_->id() << ", req " << this->req_id_;
 291   strm << " [" << opname << "]";
 292   if (this->is_oneway())
 293     strm << " oneway";
 294   else if (this->repl_octets_ == 0)
 295     strm << " <no reply found>";
 296   strm << endl;
 297 }
 298
 299 void
 300 Invocation::dump_finish_line (ostream &strm, size_t indent, const ACE_Time_Value& start)
 301 {
 302   bool is_popped = this->repl_level_ > 0 && indent == this->req_level_;
 303
 304   if (!is_popped && (this->finish_reported_ || this->is_oneway() || this->repl_octets_ == 0))
 305     return;
 306
 307   if (!this->finish_reported_)
 308     {
 309       this->repl_level_ = indent;
 310     }
 311
 312   this->finish_reported_ = true;
 313   strm << setw(7) << this->repl_octets_->log_posn() << " " << setw(0);
 314
 315   const char *opname = "";
 316   const ACE_Time_Value &tv = this->repl_octets_->time();
 317   if (tv != ACE_Time_Value::zero)
 318     {
 319       dump_rel_time (strm, tv, start);
 320     }
 321
 322   const char *dir = "reply from ";
 323
 324   if (this->req_octets_ != 0)
 325     {
 326       opname = this->req_octets_->operation();
 327       if (this->req_octets_->sending())
 328         {
 329           dir = "reply to ";
 330         }
 331     }
 332
 333   if (opname == 0 || opname[0] == 0)
 334     {
 335       opname = "<no operation>";
 336     }
 337
 338   this->new_line (strm, indent, 0, false, true);
 339
 340   strm << dir << this->peer_->id() << ", req " << this->req_id_;
 341   strm << " [" << opname << "]";
 342   if (is_popped)
 343     {
 344       strm << " (reply received at " << this->repl_level_ << " evaluated)";
 345     }
 346   else
 347     {
 348       if (indent != this->req_level_)
 349         {
 350           strm << " (req at level " << this->req_level_ << " reply at " << indent << ")";
 351         }
 352     }
 353
 354   strm << endl;
 355 }
 356
 357 void
 358 Invocation::dump_detail (ostream &strm,
 359                          size_t indent,
 360                          Dump_Mode mode,
 361                          bool show_handle)
 362 {
 363   const char *opname = "";
 364   const char *dir_1 = "sent to ";
 365   const char *dir_2 = " in ";
 366
 367   if (this->req_octets_ != 0)
 368     {
 369       opname = this->req_octets_->operation();
 370       if (this->req_octets_->sending())
 371         {
 372           dir_1 = "recv for ";
 373           dir_2 = " from ";
 374         }
 375     }
 376
 377   this->new_line (strm, indent, 0, false, true);
 378
 379   if (opname == 0 || opname[0] == 0)
 380     opname = "<no operation>";
 381
 382   strm << dir_1;
 383   if (this->target_ == 0)
 384     strm << "<unknown object>" ;
 385   else
 386     strm << this->target_->name();
 387   if (mode == Dump_Proc || mode == Dump_Both)
 388     strm << dir_2 << this->peer_->id() << ",";
 389
 390   strm << " req " << this->req_id_;
 391   if (show_handle)
 392     strm << "(h=" << this->handle_ << ")";
 393   strm << " [" << opname << "]\t";
 394   ACE_Time_Value req_time;
 395   ACE_Time_Value rep_time;
 396   size_t delta = 0;
 397   if (!this->is_oneway() && this->req_octets_ != 0)
 398     {
 399       req_time = this->req_octets_->time();
 400       if (this->repl_octets_ != 0)
 401         {
 402           rep_time = this->repl_octets_->time();
 403           delta = this->repl_octets_->log_posn() -
 404             this->req_octets_->log_posn();
 405         }
 406     }
 407   if (req_time.msec() != 0 && rep_time.msec() != 0)
 408     strm << " took " << (rep_time.msec() - req_time.msec()) << " ms";
 409
 410   if (this->req_octets_ != 0)
 411     {
 412       strm << " Request, ";
 413       if (this->req_octets_->num_contexts() > 0)
 414         strm << "with " << this->req_octets_->num_contexts() << " contexts, ";
 415       strm << "size " << this->req_octets_->expected_size() << " ";
 416       strm << "line " << this->req_octets_->log_posn();
 417       if (mode == Dump_Thread || mode == Dump_Both)
 418         strm << " " << this->req_octets_->thread()->alias();
 419     }
 420   else
 421     strm << " <no request found>";
 422   if (this->is_oneway())
 423     strm << " oneway";
 424   else
 425     {
 426       if (this->repl_octets_ != 0)
 427         {
 428           strm << " Reply, ";
 429           if (this->repl_octets_->num_contexts() > 0)
 430             strm << "with " << this->repl_octets_->num_contexts()
 431                  << " contexts, ";
 432           strm << "size " << this->repl_octets_->expected_size() << " ";
 433           strm << "line " << this->repl_octets_->log_posn();
 434 #if defined (SHOW_THREAD_ID)
 435           strm << " " << this->repl_octets_->thread()->alias();
 436 #endif
 437           size_t rstat = this->repl_octets_->reply_status();
 438           if (rstat == 1 || rstat == 2)
 439             {
 440               strm << (rstat == 1 ? " User" : " System") << " Exception";
 441             }
 442           else if (rstat == 3)
 443             {
 444               strm << " Location Forward";
 445             }
 446         }
 447       else
 448         strm << " <no reply found>";
 449     }
 450   if (delta > 0)
 451     strm << " log span = " << delta;
 452   if (this->req_octets_ != 0 && this->req_octets_->has_octets())
 453     this->dump_special_details (strm, indent, opname);
 454   strm << endl;
 455   if (this->notify_incidents_.size() > 0)
 456     {
 457       for (NotifyIncidents::ITERATOR i = this->notify_incidents_.begin();
 458            !(i.done()); i.advance())
 459         {
 460           ACE_CString *note = 0;
 461           i.next(note);
 462           strm << "            " << *note << endl;
 463         }
 464     }
 465 }
 466
 467 void
 468 Invocation::dump_special_details (ostream &strm, size_t indent, const char *opname)
 469 {
 470   size_t rstat = 0;
 471   if (this->repl_octets_ != 0 && this->repl_octets_->has_octets())
 472     rstat = this->repl_octets_->reply_status();
 473   int opid = 0;
 474   if (ACE_OS::strcmp (opname, "_is_a") == 0)
 475     {
 476       opid = 1;
 477       ACE_InputCDR &giop_cdr = this->req_octets_->payload();
 478       ACE_InputCDR cdr (giop_cdr.rd_ptr(),
 479                         giop_cdr.length(),
 480                         giop_cdr.byte_order());
 481       this->new_line (strm, indent, 8, true, false);
 482       ACE_CDR::ULong len;
 483       if (cdr >> len)
 484         {
 485           strm << "expected type ( len = " << len << ") " << cdr.rd_ptr();
 486         }
 487       else
 488         {
 489           strm << "expected type parse failed";
 490         }
 491     }
 492   else if (ACE_OS::strcmp (opname, "_get_MyID") == 0)
 493     {
 494       opid = 2;
 495     }
 496   else if (ACE_OS::strcmp (opname, "resolve_str") == 0 ||
 497            ACE_OS::strcmp (opname, "get_object_group_ref_from_name") == 0)
 498     {
 499       opid = 3;
 500       ACE_InputCDR &giop_cdr = this->req_octets_->payload();
 501       ACE_InputCDR cdr (giop_cdr.rd_ptr(),
 502                         giop_cdr.length(),
 503                         giop_cdr.byte_order());
 504       ACE_CDR::ULong len;
 505       if (cdr >> len)
 506         {
 507           this->new_line (strm, indent, 8, true, false);
 508           strm << "name (len = " << len << ") " << cdr.rd_ptr();
 509         }
 510     }
 511   else if (ACE_OS::strcmp (opname, "resolve") == 0 ||
 512            ACE_OS::strcmp (opname, "bind") == 0 ||
 513            ACE_OS::strcmp (opname, "rebind") == 0 ||
 514            ACE_OS::strcmp (opname, "bind_new_context") == 0
 515            )
 516     {
 517       opid = 3;
 518       ACE_InputCDR &giop_cdr = this->req_octets_->payload();
 519       ACE_InputCDR cdr (giop_cdr.rd_ptr(),
 520                         giop_cdr.length(),
 521                         giop_cdr.byte_order());
 522       ACE_CDR::ULong count;
 523       if (cdr >> count)
 524         {
 525           this->new_line (strm, indent, 3, true, false);
 526           strm << "name_seq.lengh = " << count << " ";
 527           while (count-- > 0)
 528             {
 529               ACE_CDR::ULong len;
 530               if (!(cdr >> len))
 531                 break;
 532               strm << cdr.rd_ptr();
 533               if (!cdr.skip_bytes (len))
 534                 break;
 535               if (!(cdr >> len))
 536                 break;
 537               if (len > 1)
 538                 {
 539                   strm << "." << cdr.rd_ptr();
 540                 }
 541               if (!cdr.skip_bytes (len))
 542                 break;
 543               if (count > 0)
 544                 {
 545                   strm << "/";
 546                 }
 547             }
 548           if (static_cast<ACE_CDR::Long>(count) > 0)
 549             {
 550               strm << " [name truncated]";
 551             }
 552         }
 553     }
 554   else if (ACE_OS::strcmp (opname, "register_activator") == 0 ||
 555            ACE_OS::strcmp (opname, "unregister_activator") == 0 ||
 556            ACE_OS::strcmp (opname, "notify_child_death") == 0 ||
 557            ACE_OS::strcmp (opname, "start_server") == 0 ||
 558            ACE_OS::strcmp (opname, "wait_for_startup") == 0 ||
 559            ACE_OS::strcmp (opname, "activate_server") == 0 ||
 560            ACE_OS::strcmp (opname, "add_or_update_server") == 0 ||
 561            ACE_OS::strcmp (opname, "shutdown_server") == 0 ||
 562            ACE_OS::strcmp (opname, "server_is_running") == 0 ||
 563            ACE_OS::strcmp (opname, "server_is_shutting_down") == 0 ||
 564            ACE_OS::strcmp (opname, "find") == 0)
 565     {
 566       ACE_InputCDR &giop_cdr = this->req_octets_->payload();
 567       ACE_InputCDR cdr (giop_cdr.rd_ptr(),
 568                         giop_cdr.length(),
 569                         giop_cdr.byte_order());
 570       ACE_CDR::ULong len;
 571       if (cdr >> len)
 572         {
 573           this->new_line (strm, indent, 8, true, false);
 574           if (this->repl_octets_ == 0)
 575             strm << "<nrf> ";
 576           else if (ACE_OS::strcmp (opname, "server_is_running") == 0)
 577             strm << "<sir> ";
 578           else if (ACE_OS::strcmp (opname, "server_is_shutting_down") == 0)
 579             strm << "<ssd> ";
 580           strm << "name ( len = " << len << ") " << cdr.rd_ptr();
 581         }
 582     }
 583
 584   if (this->repl_octets_ == 0 || !this->repl_octets_->has_octets())
 585     return;
 586
 587   ACE_InputCDR &giop_cdr = this->repl_octets_->payload();
 588   ACE_InputCDR cdr (giop_cdr.rd_ptr(),
 589                     giop_cdr.length(),
 590                     giop_cdr.byte_order());
 591
 592   if (rstat == 0)
 593     {
 594       switch (opid)
 595         {
 596         case 1:
 597           {
 598             ACE_CDR::Boolean x;
 599             if (cdr >> ACE_InputCDR::to_boolean (x))
 600               strm << " reply: " << (x ? "yes" : "no");
 601             break;
 602           }
 603         case 2:
 604           {
 605             this->new_line (strm, indent, 8, true, false);
 606             ACE_CDR::Long x;
 607             if (cdr >> x)
 608               strm << "MyID reply: " << x;
 609             break;
 610           }
 611         default:;
 612         }
 613     }
 614   else
 615     {
 616       this->new_line (strm, indent, 8, true, false);
 617       ACE_CDR::ULong len;
 618       if (rstat == 1 || rstat == 2)
 619         {
 620           strm << "Exception ";
 621         }
 622       else
 623         {
 624           strm << "Redirect to ";
 625         }
 626       if (cdr >> len)
 627         {
 628           strm << "(len = " << len << ") " << cdr.rd_ptr();
 629         }
 630       else
 631         {
 632           strm << "unparsable";
 633         }
 634     }
 635
 636 }