source/diameter.comm/ClientSession.cpp

   1 // ANNA - Anna is Not Nothingness Anymore                                                         //
   2 //                                                                                                //
   3 // (c) Copyright 2005-2015 Eduardo Ramos Testillano & Francisco Ruiz Rayo                         //
   4 //                                                                                                //
   5 // See project site at http://redmine.teslayout.com/projects/anna-suite                           //
   6 // See accompanying file LICENSE or copy at http://www.teslayout.com/projects/public/anna.LICENSE //
   7
   8
   9 #include <anna/core/functions.hpp>
  10 #include <anna/diameter/defines.hpp>
  11 #include <anna/diameter/functions.hpp>
  12 #include <anna/diameter/helpers/helpers.hpp>
  13 #include <anna/diameter/codec/functions.hpp>
  14 #include <anna/diameter/codec/Message.hpp>
  15 #include <anna/diameter/helpers/base/functions.hpp>
  16 #include <anna/time/functions.hpp>
  17
  18 #include <anna/diameter.comm/ClientSession.hpp>
  19 #include <anna/diameter.comm/Engine.hpp>
  20 #include <anna/diameter.comm/Entity.hpp>
  21 #include <anna/diameter.comm/Server.hpp>
  22 #include <anna/diameter.comm/Response.hpp>
  23 #include <anna/diameter.comm/Message.hpp>
  24 #include <anna/diameter.comm/OamModule.hpp>
  25 #include <anna/diameter.comm/ApplicationMessageOamModule.hpp>
  26 #include <anna/diameter.comm/TimerManager.hpp>
  27 #include <anna/diameter.comm/Timer.hpp>
  28 #include <anna/diameter.comm/ClientSessionReceiver.hpp>
  29 #include <anna/diameter.comm/ReceiverFactoryImpl.hpp>
  30
  31 #include <anna/comm/ClientSocket.hpp>
  32 #include <anna/app/functions.hpp>
  33 #include <anna/core/functions.hpp>
  34 #include <anna/core/DataBlock.hpp>
  35 #include <anna/core/tracing/Logger.hpp>
  36 #include <anna/core/tracing/TraceMethod.hpp>
  37 #include <anna/xml/Node.hpp>
  38 #include <anna/timex/Engine.hpp>
  39
  40 // Standard
  41 #include <stdlib.h> // rand()
  42 #include <time.h>
  43
  44
  45
  46 using namespace std;
  47 using namespace anna::diameter;
  48 using namespace anna::diameter::comm;
  49
  50 //static
  51 const anna::Millisecond ClientSession::DefaultWatchdogPeriod(30000); // Watchdog messages timeout
  52
  53
  54 ClientSession::ClientSession() : Session("diameter::comm::ClientSession", "Diameter Keep-Alive Timer"),
  55   a_receiverFactory(this),
  56   a_cer(ClassCode::Bind),
  57   a_dwr(ClassCode::ApplicationMessage) // realmente no es necesario, los Message son por defecto de aplicacion
  58 { initialize(); }
  59
  60
  61 void ClientSession::initialize() throw() {
  62   Session::initialize();
  63   a_autoRecovery = true;
  64   a_parent = NULL;
  65   a_server = NULL;
  66   a_watchdogState = WatchdogState::TimerStopped;
  67   a_hidden = false;
  68 }
  69
  70 //ClientSession::~ClientSession() {;}
  71
  72
  73 const std::string& ClientSession::getAddress() const throw() {
  74   return a_parent->getAddress();
  75 }
  76
  77 int ClientSession::getPort() const throw() {
  78   return a_parent->getPort();
  79 }
  80
  81
  82 void ClientSession::setState(State::_v state) throw() {
  83   Session::setState(state);
  84   // Inform father server (availability changes):
  85   bool changes = a_parent->refreshAvailability();
  86 }
  87
  88 void ClientSession::bind() throw(anna::RuntimeException) {
  89   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "bind", ANNA_FILE_LOCATION));
  90
  91   if(a_state != State::Closed)
  92     return;
  93
  94   LOGDEBUG(
  95     string msg("diameter::comm::ClientSession::bind | ");
  96     msg += asString();
  97     anna::Logger::debug(msg, ANNA_FILE_LOCATION);
  98   );
  99
 100   // Connection:
 101   if(!a_server)
 102     throw anna::RuntimeException("Server is not yet created", ANNA_FILE_LOCATION);
 103
 104   bool serverAvailable = a_server->isAvailable();
 105   LOGDEBUG(
 106
 107     if(serverAvailable) anna::Logger::debug("Server AVAILABLE", ANNA_FILE_LOCATION);
 108     else anna::Logger::debug("Server NOT AVAILABLE. Connecting ...", ANNA_FILE_LOCATION);
 109     );
 110
 111   if(!serverAvailable) {
 112     a_server->connect();
 113     return;
 114   }
 115
 116   // Some operations could be done before sending CER, for example non-standard Origin-Host manipulation for
 117   // Tekelec PCRF
 118   a_engine->bindingClientSession(this);
 119
 120   // OAM Lo comento, porque no se contabilizan los reintentos y por lo tanto no son muy �tiles.
 121 //  OamModule &oamModule = OamModule::instantiate();
 122 //  oamModule.count(a_server->isAvailable() ? OamModule::Counter::TCPConnectOK:OamModule::Counter::TCPConnectNOK);
 123   // Application bind
 124   if(send(&a_cer))
 125     LOGDEBUG(anna::Logger::debug("CER sent to the server", ANNA_FILE_LOCATION));
 126 }
 127
 128
 129 void ClientSession::setCERandDWR(const anna::DataBlock & cer, const anna::DataBlock & dwr) throw(anna::RuntimeException) {
 130   if(codec::functions::getCommandId(cer) != helpers::base::COMMANDID__Capabilities_Exchange_Request) {
 131     throw anna::RuntimeException("The message provided as 'CER' is not a Capabilities-Exchange-Request", ANNA_FILE_LOCATION);
 132   }
 133
 134   if(codec::functions::getCommandId(dwr) != helpers::base::COMMANDID__Device_Watchdog_Request) {
 135     throw anna::RuntimeException("The message provided as 'DWR' is not a Device-Watchdog-Request", ANNA_FILE_LOCATION);
 136   }
 137
 138   // La verificacion ya se hace implicitamente antes
 139   //   if ((a_cer.isEmpty()) || (a_dwr.isEmpty())) {
 140   //      LOGDEBUG (anna::Logger::debug ("Must define valid CER and DWR messages before use bind !", ANNA_FILE_LOCATION));
 141   //      return;
 142   //   }
 143   a_cer.setBody(cer);
 144   a_dwr.setBody(dwr);
 145 }
 146
 147
 148 const Response* ClientSession::send(const Message* message) throw(anna::RuntimeException) {
 149   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "send", ANNA_FILE_LOCATION));
 150
 151   if(!message)
 152     throw anna::RuntimeException("Cannot send a NULL message", ANNA_FILE_LOCATION);
 153
 154   // Command id:
 155   bool isRequest;
 156   diameter::CommandId cid = message->getCommandId(isRequest);
 157   diameter::ApplicationId aid = message->getApplicationId();
 158
 159   LOGDEBUG(
 160     std::string msg = "Sending diameter message: ";
 161     msg += anna::diameter::functions::commandIdAsPairString(cid);
 162     anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 163   );
 164
 165   if(hidden()) {
 166     if((cid.first != helpers::base::COMMANDID__Capabilities_Exchange_Request.first)  /* not CER/CEA */
 167         && (cid.first != helpers::base::COMMANDID__Device_Watchdog_Request.first) /* not DWR/DWA */
 168         && (cid.first != helpers::base::COMMANDID__Disconnect_Peer_Request.first)) { /* not DPR/DPA */
 169       LOGDEBUG(
 170         std::string msg(asString());
 171         msg += " | Client-session hidden for application messages delivery";
 172         anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 173       );
 174       return NULL;
 175     }
 176   }
 177
 178   // Checkings:
 179   if((a_state == State::Closed) && (cid != helpers::base::COMMANDID__Capabilities_Exchange_Request)) {
 180     string msg(asString());
 181     msg += " | ClientSession::bind is not initiated";
 182     throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
 183   }
 184
 185   if(a_state == State::WaitingBind) {
 186     string msg(asString());
 187     msg += " | Still waiting for bind ack (CEA)";
 188     throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
 189   }
 190
 191   if(a_state == State::Failover) {
 192     string msg(asString());
 193     msg += " | Disabled sent on failover state";
 194     throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
 195   }
 196
 197   if(a_state == State::Closing) {
 198     string msg(asString());
 199     msg += " | Disabled sent on closing state";
 200     throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
 201   }
 202
 203   // Check states:
 204   if(cid == helpers::base::COMMANDID__Capabilities_Exchange_Request) {
 205     if(a_state != State::Closed) {
 206       string msg(asString());
 207       msg += " | Discarding CER on not closed state";
 208       throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
 209     }
 210   } else if(cid ==  helpers::base::COMMANDID__Device_Watchdog_Request) {
 211     if(a_state == State::WaitingDPA) {
 212       string msg(asString());
 213       msg += " | DWR is not sent on 'WaitingDPA' state";
 214       //throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
 215       LOGDEBUG(anna::Logger::debug(msg, ANNA_FILE_LOCATION));
 216       return NULL;
 217     }
 218
 219     if(a_state == State::Disconnecting) {
 220       string msg(asString());
 221       msg += " | DWR is not sent on 'Disconnecting' state";
 222       //throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
 223       LOGDEBUG(anna::Logger::debug(msg, ANNA_FILE_LOCATION));
 224       return NULL;
 225     }
 226
 227     if(a_state == State::Closing) {
 228       string msg(asString());
 229       msg += " | DWR is not sent on 'Closing' state";
 230       //throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
 231       LOGDEBUG(anna::Logger::debug(msg, ANNA_FILE_LOCATION));
 232       return NULL;
 233     }
 234   } else if(cid ==  helpers::base::COMMANDID__Disconnect_Peer_Request) {
 235     if(a_state == State::WaitingDPA) {
 236       string msg(asString());
 237       msg += " | Still waiting for DPR ack (DPA)";
 238       throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
 239     }
 240
 241     if(a_state == State::Disconnecting) {
 242       string msg(asString());
 243       msg += " | Client disconnection has already been initiated";
 244       throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
 245     }
 246   } else {
 247     if((a_state == State::WaitingDPA) || (a_state == State::Disconnecting)) {
 248       if(cid != helpers::base::COMMANDID__Disconnect_Peer_Answer) {
 249         LOGDEBUG(
 250           string msg("diameter::comm::ClientSession::send | ");
 251           msg += asString();
 252           msg += " | Sents (request or answer) blocked to diameter server (disconnection in progress). Discarding ...";
 253           anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 254         );
 255         return NULL;
 256       }
 257     }
 258   }
 259
 260   // Trace send operation:
 261   LOGDEBUG(
 262     string msg("diameter::comm::ClientSession::send | ");
 263     msg += asString();
 264     msg += " | ";
 265     msg += message->asString();
 266     anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 267   );
 268   bool fixed = false; // answers cannot be fixed
 269   Message * message_nc = const_cast<Message*>(message);
 270
 271   if(isRequest) {
 272     if(/* entity */getParent()->getParent()->isDeprecated()) {
 273       string msg(asString());
 274       msg += " | Parent entity is deprecated. Request send blocked.";
 275       throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
 276     }
 277
 278     // Fixing indicator:
 279     fixed = message_nc->fixRequestSequence(a_nextHopByHop, a_nextEndToEnd);
 280     message_nc->updateRequestTimestampMs(); // statistics purposes (processing time for request type)
 281   }
 282
 283   // Send message
 284   try {
 285     message->send(*this);
 286
 287     // Next hop by hop & end to end identifiers:
 288     if(isRequest) generateNextSequences();
 289
 290     //   Transaction state
 291     //         The Diameter protocol requires that agents maintain transaction
 292     //         state, which is used for failover purposes.  Transaction state
 293     //         implies that upon forwarding a request, the Hop-by-Hop identifier
 294     //         is saved; the field is replaced with a locally unique identifier,
 295     //         which is restored to its original value when the corresponding
 296     //         answer is received.  The request's state is released upon receipt
 297     //         of the answer.  A stateless agent is one that only maintains
 298     //         transaction state.
 299     //
 300     updateOutgoingActivityTime();
 301     // OAM
 302     countSendings(cid, aid, true /* send ok */);
 303     // Trace non-application messages:
 304     LOGDEBUG(
 305
 306       if((cid == helpers::base::COMMANDID__Capabilities_Exchange_Request) ||
 307          (cid == helpers::base::COMMANDID__Device_Watchdog_Request) ||
 308     (cid == helpers::base::COMMANDID__Disconnect_Peer_Request)) {
 309     anna::Logger::debug("Sent DataBlock to XML representation:", ANNA_FILE_LOCATION);
 310       try { anna::diameter::codec::Message msg; msg.decode(message->getBody()); /* decode to be traced */ } catch(anna::RuntimeException&) {;}
 311     }
 312     );
 313
 314     // Restore sequences:
 315     if(fixed) message_nc->restoreSequencesAfterFix();  // restore to application sequences after fix
 316   } catch(anna::RuntimeException&) {
 317     if(fixed) message_nc->restoreSequencesAfterFix();  // restore to application sequences after fix
 318
 319     // OAM
 320     countSendings(cid, aid, false /* send no ok */);
 321     throw;
 322   }
 323
 324   // Renew states:
 325   if(cid ==  helpers::base::COMMANDID__Capabilities_Exchange_Request) {
 326     setState(State::WaitingBind);
 327   } else if(cid ==  helpers::base::COMMANDID__Disconnect_Peer_Request) {
 328     LOGWARNING(anna::Logger::warning("DPR has been sent to the peer (diameter server)", ANNA_FILE_LOCATION));
 329     setState(State::WaitingDPA);
 330   }
 331
 332 //   else {
 333 //      // No changes
 334 //   }
 335
 336   // Answers are not temporized:
 337   if(!isRequest) return NULL;
 338
 339   // Neither DWR:
 340   if(cid == helpers::base::COMMANDID__Device_Watchdog_Request) {
 341     setWatchdogState(WatchdogState::WaitingDWA);
 342     return NULL;
 343   }
 344
 345   // Request will have context responses:
 346   Response* result(NULL);
 347   result = Response::instance(message->getClassCode(), a_nextHopByHop - 1 /* current request sent to server */);
 348   result->setRequest(message);
 349   response_add(result);
 350   return result;
 351 }
 352
 353 bool ClientSession::unbind(bool forceDisconnect)
 354 throw(anna::RuntimeException) {
 355   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "unbind", ANNA_FILE_LOCATION));
 356
 357   if(a_state == State::Closed)
 358     return false;
 359
 360   // Client socket:
 361   anna::comm::ClientSocket * cs = const_cast<anna::comm::ClientSocket*>(a_server->getClientSocket());
 362 //   LOGDEBUG(
 363 //      string msg("Server to be unbound | ");
 364 //      msg += a_server->asString();
 365 //      anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 366 //   );
 367
 368   if(forceDisconnect) {
 369     LOGDEBUG(anna::Logger::debug("Immediate disconnection (forceDisconnect)", ANNA_FILE_LOCATION));
 370
 371     if(cs) cs->requestClose();  // this will invoke finalize()
 372
 373     return true;
 374   }
 375
 376   if(a_state == State::Disconnecting) {
 377     LOGDEBUG(
 378       string msg("diameter::comm::ClientSession::unbind | ");
 379       msg += asString();
 380       msg += " | Disconnection already in progress !";
 381       anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 382     );
 383     return false;
 384   }
 385
 386   if(a_state == State::Failover) {
 387     LOGDEBUG(
 388       string msg("diameter::comm::ClientSession::unbind | ");
 389       msg += asString();
 390       msg += " | Unbind on failover state. Disconnect now.";
 391       anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 392     );
 393
 394     if(cs) cs->requestClose();  // this will invoke finalize()
 395
 396     return true;
 397   }
 398
 399   if(a_state == State::WaitingBind) {
 400     LOGDEBUG(
 401       string msg("diameter::comm::ClientSession::unbind | ");
 402       msg += asString();
 403       msg += " | Unbind on WaitingBind state. Disconnect now.";
 404       anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 405     );
 406
 407     if(cs) cs->requestClose();  // this will invoke finalize()
 408
 409     return true;
 410   }
 411
 412   if(a_onDisconnect == OnDisconnect::IgnorePendings) {
 413     LOGDEBUG(anna::Logger::debug("Immediate disconnection (IgnorePendings)", ANNA_FILE_LOCATION));
 414
 415     if(cs) cs->requestClose();  // this will invoke finalize()
 416
 417     return true;
 418   }
 419
 420   if(getOTARequests() == 0) {  // No pendings
 421     LOGDEBUG(anna::Logger::debug("No pending answers. Perform client-session close.", ANNA_FILE_LOCATION));
 422
 423     if(cs) cs->requestClose();  // this will invoke finalize()
 424
 425     return true;
 426   }
 427
 428   if(a_state == State::Closing) {
 429     LOGDEBUG(
 430       string msg("diameter::comm::ClientSession::unbind | ");
 431       msg += asString();
 432       msg += " | Closing already in progress (waiting pendings) !";
 433       anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 434     );
 435   }
 436
 437   return false;
 438 }
 439
 440 void ClientSession::eventPeerShutdown() throw() {
 441   // Inform father server:
 442   a_parent->eventPeerShutdown(this);
 443 }
 444
 445 void ClientSession::eventResponse(const Response& response) throw(anna::RuntimeException) {
 446   // Inform father server:
 447   a_parent->eventResponse(response);
 448 }
 449
 450 void ClientSession::eventRequest(const anna::DataBlock &request) throw(anna::RuntimeException) {
 451   // Inform father server:
 452   a_parent->eventRequest(this, request);
 453 }
 454
 455 void ClientSession::eventUnknownResponse(const anna::DataBlock& response) throw(anna::RuntimeException) {
 456   // Inform father server:
 457   a_parent->eventUnknownResponse(this, response);
 458 }
 459
 460 void ClientSession::eventDPA(const anna::DataBlock& response) throw(anna::RuntimeException) {
 461   // Inform father server:
 462   a_parent->eventDPA(this, response);
 463 }
 464
 465
 466
 467 //------------------------------------------------------------------------------------------
 468 // Se invoca desde el diameter::comm::Receiver
 469 //------------------------------------------------------------------------------------------
 470 void ClientSession::receive(const anna::comm::Message& message)
 471 throw(anna::RuntimeException) {
 472   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "receive", ANNA_FILE_LOCATION));
 473   // Activity:
 474   updateIncomingActivityTime();
 475   activateTimer();
 476   // Command id:
 477   const anna::DataBlock & db = message.getBody();
 478   diameter::CommandId cid = codec::functions::getCommandId(db);
 479   bool isRequest = cid.second;
 480   LOGDEBUG(
 481     std::string msg = "Received diameter message: ";
 482     msg += anna::diameter::functions::commandIdAsPairString(cid);
 483     anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 484
 485     if((cid == helpers::base::COMMANDID__Capabilities_Exchange_Answer) || (cid.first == helpers::base::COMMANDID__Device_Watchdog_Request.first))
 486   try { anna::diameter::codec::Message dmsg; dmsg.decode(db); /* decode to be traced */ } catch(anna::RuntimeException&) {;}
 487 );
 488   // Main counters:
 489   OamModule &oamModule = OamModule::instantiate();
 490   oamModule.count(isRequest ? OamModule::Counter::RequestReceived : OamModule::Counter::AnswerReceived);
 491   oamModule.count(isRequest ? OamModule::Counter::RequestReceivedOnClientSession : OamModule::Counter::AnswerReceivedOnClientSession);
 492   // Statistic (size)
 493   a_parent->updateReceivedMessageSizeStatisticConcept(message.getSize()); // only on reception (application could manage sent sizes)
 494
 495   if(isRequest) {
 496     /////////////////////////////
 497     // Here received a request //
 498     /////////////////////////////
 499
 500     // Received CER
 501     if(cid == helpers::base::COMMANDID__Capabilities_Exchange_Request) {
 502       LOGWARNING(anna::Logger::warning("Received CER: unexpected message at client-side", ANNA_FILE_LOCATION));
 503       return;
 504     }
 505     // Received DWR
 506     else if(cid == helpers::base::COMMANDID__Device_Watchdog_Request) {
 507 //         LOGWARNING(anna::Logger::warning("Received DWR: unexpected message at client-side", ANNA_FILE_LOCATION));
 508 //         return;
 509       // Non-usual but could happen:
 510       oamModule.count(OamModule::Counter::DWRReceived);
 511       sendDWAToServer(db /* DWR datablock received from server */);
 512       return;
 513     }
 514     // Received DPR
 515     else if(cid == helpers::base::COMMANDID__Disconnect_Peer_Request) {
 516       oamModule.count(OamModule::Counter::DPRReceived);
 517
 518       if(a_state == State::Bound) {
 519         a_dpr.setBody(db);
 520         setState(State::Disconnecting);
 521         LOGWARNING(anna::Logger::warning("DPR has been received from peer (diameter server)", ANNA_FILE_LOCATION));
 522
 523         if(getOTARequests() == 0) sendDPA();
 524
 525         return; // DPR won't be informed because virtual readDPA is available for this
 526       }
 527     }
 528
 529     try {
 530       // application message counters
 531       ApplicationMessageOamModule::instantiate().count(cid.first, anna::diameter::codec::functions::getApplicationId(db), ApplicationMessageOamModule::Counter::Request_Received_AsClient);
 532
 533       eventRequest(db);
 534     } catch(anna::RuntimeException& ex) {
 535       ex.trace();
 536     }
 537
 538     return;
 539   }
 540
 541   /////////////////////////////
 542   // Here received an answer //
 543   /////////////////////////////
 544   bool doUnbind = false;
 545   bool immediateUnbind = false;
 546   int resultCode = 0;
 547
 548   try {
 549     resultCode = helpers::base::functions::getResultCode(db);
 550   } catch(anna::RuntimeException& ex) {
 551     ex.trace();
 552   }
 553
 554   // Received CEA
 555   if(cid == helpers::base::COMMANDID__Capabilities_Exchange_Answer) {
 556     oamModule.count(OamModule::Counter::CEAReceived);
 557
 558     if(a_state != State::WaitingBind) {
 559       LOGWARNING(anna::Logger::warning("Received CEA: unexpected message at not-WaitingBind state", ANNA_FILE_LOCATION));
 560       return; // we don't send its request
 561 //         string msg("diameter::comm::ClientSession::receive | ");
 562 //         msg += asString();
 563 //         msg += " | Received CEA on not-WaitingBind state: unexpected Bind-response";
 564 //         throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
 565     }
 566
 567     if(resultCode != helpers::base::AVPVALUES__Result_Code::DIAMETER_SUCCESS) {
 568       LOGWARNING(
 569         std::string msg = anna::functions::asString("Received CEA with non-success Result-Code (%d). Unbinding connection.", resultCode);
 570         anna::Logger::warning(msg, ANNA_FILE_LOCATION);
 571       );
 572       doUnbind = true;
 573     } else {
 574       setState(State::Bound);
 575       //activateTimer(); // Ya se invoca al inicio de este metodo ::receive
 576       // Inform father server (availability changes):
 577       bool changes = a_parent->refreshAvailability();
 578       //startClock();
 579     }
 580   }
 581   // Received DWA
 582   else if(cid == helpers::base::COMMANDID__Device_Watchdog_Answer) {
 583     oamModule.count(OamModule::Counter::DWAReceived);
 584     setWatchdogState(WatchdogState::WaitingTimerExpiration);
 585
 586     if(resultCode != helpers::base::AVPVALUES__Result_Code::DIAMETER_SUCCESS)
 587       LOGWARNING(
 588         std::string msg = anna::functions::asString("Received DWA with non-success Result-Code (%d)... but ASSUME keep-alive is reached", resultCode);
 589         anna::Logger::warning(msg, ANNA_FILE_LOCATION);
 590       );
 591
 592     if(a_state == State::Failover) {
 593       setState(State::Bound);
 594       LOGDEBUG(
 595         string msg("diameter::comm::ClientSession::receive | ");
 596         msg += asString();
 597         msg += " | Received DWA on failover state: recovering Bound state";
 598         anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 599       );
 600     }
 601
 602     // Keep-Alive don't manage context
 603     return;
 604   }
 605   // Received DPA
 606   else if(cid == helpers::base::COMMANDID__Disconnect_Peer_Answer) {
 607     oamModule.count(OamModule::Counter::DPAReceived);
 608
 609     if(a_state == State::WaitingDPA) {
 610       if(resultCode != helpers::base::AVPVALUES__Result_Code::DIAMETER_SUCCESS) {
 611         LOGWARNING(
 612           std::string msg = anna::functions::asString("Received DPA with non-success Result-Code (%d). Ignoring and recovering Bound state", resultCode);
 613           anna::Logger::warning(msg, ANNA_FILE_LOCATION);
 614         );
 615         setState(State::Bound);
 616       } else {
 617         LOGWARNING(anna::Logger::warning("Received DPA With Result-Code = DIAMETER_SUCCESS. Disconnect now.", ANNA_FILE_LOCATION));
 618         immediateUnbind = true;
 619         doUnbind = true;
 620       }
 621     }
 622   }
 623
 624   HopByHop hopByHop = codec::functions::getHopByHop(db); // context identification
 625   Response* response = response_find(hopByHop);
 626
 627   // Out-of-context responses:
 628   if(!response) {
 629     // OAM
 630     oamModule.count(OamModule::Counter::AnswerReceivedUnknown);
 631     oamModule.count(OamModule::Counter::AnswerReceivedOnClientSessionUnknown);
 632     oamModule.activateAlarm(OamModule::Alarm::AnswerReceivedOnClientSessionUnknown);
 633
 634     // application message counters
 635     ApplicationMessageOamModule::instantiate().count(cid.first, anna::diameter::codec::functions::getApplicationId(db), ApplicationMessageOamModule::Counter::Answer_UnknownReceived_AsClient);
 636
 637     eventUnknownResponse(db);
 638     string msg(asString());
 639     msg += anna::functions::asString(" | Response received from entity, for non registered context (HopByHop: %u)", hopByHop);
 640     throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
 641   }
 642
 643   response->setResultCode(Response::ResultCode::Success);
 644   response->cancelTimer();
 645   LOGDEBUG(
 646     string msg("diameter::comm::ClientSession::receive | ");
 647     msg += asString();
 648     msg += " | Received answer";
 649     msg += response->asString();
 650     anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 651   );
 652   // Statistics
 653   anna::Millisecond current = (anna::Millisecond)anna::functions::millisecond();
 654   anna::Millisecond request = response->getRequest()->getRequestTimestampMs();
 655   anna::Millisecond timeToAnswerMs = current - request;
 656   a_parent->updateProcessingTimeStatisticConcept(timeToAnswerMs);
 657   LOGDEBUG
 658   (
 659     std::string msg = "This diameter request context lasted ";
 660     msg += anna::functions::asString(timeToAnswerMs);
 661     msg += " milliseconds at diameter server (included network time)";
 662     anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 663   );
 664   // Progress origin for tracking purposes on asyncronous boxes with both diameter interfaces (entities and clients)
 665   Message * requestMessage = const_cast<Message*>(response->getRequest());
 666   requestMessage->setRequestServerSessionKey(response->getRequest()->getRequestServerSessionKey()); // -1 means unkown/unset
 667
 668   if(cid != helpers::base::COMMANDID__Disconnect_Peer_Answer) {
 669     try {
 670       response->setMessage(&db);
 671       // Restore received datablock
 672       LOGDEBUG(
 673         string msg("diameter::comm::ClientSession::receive | Restore answer to original request sequences (hop-by-hop = ");
 674         msg += anna::functions::asString(response->getRequest()->getRequestHopByHop());
 675         msg += ", end-to-end = ";
 676         msg += anna::functions::asString(response->getRequest()->getRequestEndToEnd());
 677         msg += ")";
 678         anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 679       );
 680       diameter::codec::functions::setHopByHop((anna::DataBlock&)db, response->getRequest()->getRequestHopByHop());
 681       diameter::codec::functions::setEndToEnd((anna::DataBlock&)db, response->getRequest()->getRequestEndToEnd());
 682
 683       // application message counters
 684       if(cid != helpers::base::COMMANDID__Capabilities_Exchange_Answer)
 685         ApplicationMessageOamModule::instantiate().count(cid.first, anna::diameter::codec::functions::getApplicationId(db), ApplicationMessageOamModule::Counter::Answer_Received_AsClient);
 686
 687       eventResponse(*response);
 688     } catch(anna::RuntimeException& ex) {
 689       ex.trace();
 690     }
 691   }
 692   else { // DPA
 693     // unbind is automatically performed, anyway we can inform to the application just in case some additional
 694     //  procedure could be issued:
 695     eventDPA(db);
 696   }
 697
 698   response_erase(response);
 699
 700   // Unbind trigger
 701   if(doUnbind)
 702     unbind(immediateUnbind);
 703 }
 704
 705 void ClientSession::finalize() throw() {
 706   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "finalize", ANNA_FILE_LOCATION));
 707   Session::finalize();
 708   // Check deprecated entity:
 709   const Entity *entity = getParent() /* server */ ->getParent() /* entity */;
 710   // Inform father server (availability changes):
 711   bool changes = a_parent->refreshAvailability();
 712   // OAM
 713   const Server *server = getParent();
 714   bool multipleConnections = (server->getMaxClientSessions() > 1);
 715   std::string socket = anna::functions::socketLiteralAsString(getAddress(), getPort());
 716   OamModule &oamModule = OamModule::instantiate();
 717
 718   if(multipleConnections) {
 719     oamModule.activateAlarm(OamModule::Alarm::c_LostAvailabilityOverClientSessionWithServer__s__ClientSessionId__d__, socket.c_str(), getSocketId());
 720     oamModule.count(OamModule::Counter::LostAvailabilityOverClientSession);
 721   } else {
 722     oamModule.activateAlarm(OamModule::Alarm::c_LostAvailabilityOverClientSessionWithServer__s__, socket.c_str());
 723     oamModule.count(OamModule::Counter::LostAvailabilityOverClientSession);
 724   }
 725 }
 726
 727 void ClientSession::recover() throw() {
 728   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "recover", ANNA_FILE_LOCATION));
 729
 730   try {
 731     bind();
 732   } catch(anna::RuntimeException &ex) {
 733     // Again:
 734     anna::comm::ClientSocket * cs = const_cast<anna::comm::ClientSocket*>(a_server->getClientSocket());
 735
 736     if(cs) cs->requestClose();
 737
 738     ex.trace();
 739   }
 740
 741   // Inform father server (availability changes):
 742   bool changes = a_parent->refreshAvailability();
 743   // OAM
 744   const Server *server = getParent();
 745   bool multipleConnections = (server->getMaxClientSessions() > 1);
 746   std::string socket = anna::functions::socketLiteralAsString(getAddress(), getPort());
 747   OamModule &oamModule = OamModule::instantiate();
 748
 749   if(multipleConnections) {
 750     oamModule.cancelAlarm(OamModule::Alarm::c_LostAvailabilityOverClientSessionWithServer__s__ClientSessionId__d__, socket.c_str(), getSocketId());
 751     oamModule.count(OamModule::Counter::RecoveredAvailabilityOverClientSession);
 752   } else {
 753     oamModule.cancelAlarm(OamModule::Alarm::c_LostAvailabilityOverClientSessionWithServer__s__, socket.c_str());
 754     oamModule.count(OamModule::Counter::RecoveredAvailabilityOverClientSession);
 755   }
 756 }
 757
 758 void ClientSession::sendDWAToServer(const anna::DataBlock& dwrDB)
 759 throw(anna::RuntimeException) {
 760   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "sendDWAToServer", ANNA_FILE_LOCATION));
 761   anna::DataBlock dwa(true);
 762   a_engine->readDWA(dwa, dwrDB); // Asume that DWA is valid ...
 763
 764   if(dwa.isEmpty())
 765     throw anna::RuntimeException("This diameter agent defines an empty DWA message. Remote server never will validate this connection health", ANNA_FILE_LOCATION);
 766
 767   Message msgDwa;
 768   msgDwa.setBody(dwa);
 769   send(&msgDwa);
 770 }
 771
 772 //-------------------------------------------------------------------------
 773 // Se invoca desde diameter::comm::Timer
 774 //-------------------------------------------------------------------------
 775 void ClientSession::expireResponse(diameter::comm::Response* response)
 776 throw() {
 777   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "expireResponse", ANNA_FILE_LOCATION));
 778   Session::expireResponse(response);
 779   // OAM
 780   OamModule &oamModule = OamModule::instantiate();
 781   oamModule.count(OamModule::Counter::RequestSentExpired);
 782   oamModule.count(OamModule::Counter::RequestSentOnClientSessionExpired);
 783   oamModule.activateAlarm(OamModule::Alarm::RequestSentOnClientSessionExpired);
 784
 785   // Check father server idleness:
 786   if(idle()) a_parent->childIdle();
 787
 788 //   if (idle()) {
 789 //      LOGDEBUG(anna::Logger::debug("ClientSession is idle after an expiration...", ANNA_FILE_LOCATION));
 790 //      a_parent->childIdle();
 791 //   }
 792 //   else {
 793 //      LOGDEBUG(anna::Logger::debug("ClientSession is busy after an expiration...", ANNA_FILE_LOCATION));
 794 //   }
 795 }
 796
 797
 798 std::string ClientSession::asString() const
 799 throw() {
 800   string result = Session::asString();
 801   result += " | Parent Server: ";
 802   result += anna::functions::socketLiteralAsString(getAddress(), getPort());
 803   result += " | Auto-recovery: ";
 804   result += (a_autoRecovery ? "yes" : "no");
 805   result += " | WatchdogState: ";
 806   result += asText(a_watchdogState);
 807   // Diferente del timeout de ApplicationMessage:
 808   result += " | Watchdog Period: ";
 809   result += getTimeout().asString();
 810   result += " | Hidden: ";
 811   result += (hidden() ? "yes" : "no");
 812
 813   if(a_server) {
 814     result += " | MaxConnectionDelay: ";
 815     result += a_server->getMaxConnectionDelay().asString();
 816   }
 817
 818   return result += " }";
 819 }
 820
 821 anna::xml::Node* ClientSession::asXML(anna::xml::Node* parent) const
 822 throw() {
 823   anna::xml::Node* result = Session::asXML(parent);
 824   parent->createChild("diameter.comm.ClientSession");
 825   result->createAttribute("ParentServer", anna::functions::socketLiteralAsString(getAddress(), getPort()));
 826   result->createAttribute("AutoRecovery", (a_autoRecovery ? "yes" : "no"));
 827   result->createAttribute("WatchdogState", asText(a_watchdogState));
 828   // Diferente del timeout de ApplicationMessage:
 829   result->createAttribute("WatchdogPeriod", getTimeout().asString());
 830
 831   if(a_server) result->createAttribute("MaxConnectionDelay", a_server->getMaxConnectionDelay().asString());
 832
 833   result->createAttribute("Hidden", hidden() ? "yes" : "no");
 834   return result;
 835 }
 836
 837
 838 const char* ClientSession::asText(const WatchdogState::_v watchdogState)
 839 throw() {
 840   static const char* text [] = { "TimerStopped", "WaitingTimerExpiration", "WaitingDWA" };
 841   return text [watchdogState];
 842 }
 843
 844
 845 //------------------------------------------------------------------------------
 846 //------------------------------------------------------ ClientSession::expire()
 847 //------------------------------------------------------------------------------
 848 void ClientSession::expire(anna::timex::Engine *timeController) throw(anna::RuntimeException) {
 849   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "expire (watchdog timer)", ANNA_FILE_LOCATION));
 850
 851   //   The client MUST NOT close the primary connection until the
 852   //    primary's watchdog timer has expired at least twice without a
 853   //    response (note that the watchdog is not sent a second time,
 854   //    however).
 855   if(a_watchdogState == WatchdogState::WaitingDWA) {
 856     if(a_state == State::Failover) {
 857       LOGWARNING(anna::Logger::warning("Unbinding client-session: Tw expired after first DWA missing (2*Tw elapsed)", ANNA_FILE_LOCATION));
 858       unbind();
 859       return; // finalize will stop the stopped timer ...
 860     }
 861
 862     setState(State::Failover);
 863     LOGWARNING(anna::Logger::warning("Going to Failover state: first DWA missing", ANNA_FILE_LOCATION));
 864     activateTimer(); // another chance on failover
 865     return;
 866   }
 867
 868   // WaitingTimerExpiration arrives here:
 869   const Response* sent;
 870
 871   try {
 872     sent = send(&a_dwr);
 873   } catch(anna::RuntimeException&) {
 874     LOGDEBUG(anna::Logger::debug("Failed to send DWR to the server: unbinding ...", ANNA_FILE_LOCATION));
 875     setState(State::Failover);
 876     unbind();
 877     throw;
 878   }
 879
 880   LOGDEBUG(if(sent) anna::Logger::debug("DWR sent to the server", ANNA_FILE_LOCATION););
 881
 882   activateTimer();
 883 }
 884
 885 void ClientSession::setWatchdogPeriod(const anna::Millisecond & watchdogPeriod) throw() {
 886   setTimeout(watchdogPeriod);
 887 }
 888
 889 void ClientSession::setWatchdogState(WatchdogState::_v wState) throw() {
 890   LOGDEBUG(
 891
 892   if(wState != a_watchdogState) {
 893   std::string msg("Session watchdog state change: ");
 894     msg += asText(a_watchdogState);
 895     msg += " -> ";
 896     msg += asText(wState);
 897     anna::Logger::debug(msg, ANNA_FILE_LOCATION);
 898   }
 899   );
 900   a_watchdogState = wState;
 901 }
 902
 903
 904 void ClientSession::timerStopped() throw() {
 905   LOGDEBUG(anna::Logger::debug("Watchdog timer stopped", ANNA_FILE_LOCATION));
 906   setWatchdogState(WatchdogState::TimerStopped);
 907 }
 908
 909 void ClientSession::timerStarted() throw() {
 910   LOGDEBUG(anna::Logger::debug("Watchdog timer started", ANNA_FILE_LOCATION));
 911
 912   if(a_watchdogState == WatchdogState::WaitingDWA) return;
 913
 914   setWatchdogState(WatchdogState::WaitingTimerExpiration);
 915 }
 916
 917
 918 //------------------------------------------------------------------------------
 919 //---------------------------------- ClientSession::updateIncomingActivityTime()
 920 //------------------------------------------------------------------------------
 921 void ClientSession::updateIncomingActivityTime() throw() {
 922   Session::updateIncomingActivityTime();
 923   a_parent->updateIncomingActivityTime();
 924 }
 925
 926
 927 //------------------------------------------------------------------------------
 928 //---------------------------------- ClientSession::updateOutgoingActivityTime()
 929 //------------------------------------------------------------------------------
 930 void ClientSession::updateOutgoingActivityTime(void) throw() {
 931   Session::updateOutgoingActivityTime();
 932   a_parent->updateOutgoingActivityTime();
 933 }
 934
 935
 936
 937 //------------------------------------------------------------------------------
 938 //----------------------------------------------- ClientSession::countSendings()
 939 //------------------------------------------------------------------------------
 940 void ClientSession::countSendings(const diameter::CommandId & cid, unsigned int aid, bool ok)throw() {
 941   OamModule &oamModule = OamModule::instantiate();
 942   ApplicationMessageOamModule &appMsgOamModule = ApplicationMessageOamModule::instantiate();
 943
 944   bool isRequest = cid.second;
 945
 946   if(ok) {
 947     // Main counters:
 948     oamModule.count(isRequest ? OamModule::Counter::RequestSentOK : OamModule::Counter::AnswerSentOK);
 949     oamModule.count(isRequest ? OamModule::Counter::RequestSentOnClientSessionOK : OamModule::Counter::AnswerSentOnClientSessionOK);
 950
 951     if(cid == helpers::base::COMMANDID__Capabilities_Exchange_Request) oamModule.count(OamModule::Counter::CERSentOK);
 952     else if(cid == helpers::base::COMMANDID__Device_Watchdog_Request) oamModule.count(OamModule::Counter::DWRSentOK);
 953     else if(cid == helpers::base::COMMANDID__Device_Watchdog_Answer) oamModule.count(OamModule::Counter::DWASentOK);  // not usual (dwr was received from server)
 954     else if(cid == helpers::base::COMMANDID__Disconnect_Peer_Request) oamModule.count(OamModule::Counter::DPRSentOK);
 955     else if(cid == helpers::base::COMMANDID__Disconnect_Peer_Answer) oamModule.count(OamModule::Counter::DPASentOK);
 956     // Application messages:
 957     else {
 958       appMsgOamModule.count(cid.first, aid, isRequest ? ApplicationMessageOamModule::Counter::Request_SentOK_AsClient : ApplicationMessageOamModule::Counter::Answer_SentOK_AsClient);
 959     }
 960   } else {
 961     // Main counters:
 962     oamModule.count(isRequest ? OamModule::Counter::RequestSentNOK : OamModule::Counter::AnswerSentNOK);
 963     oamModule.count(isRequest ? OamModule::Counter::RequestSentOnClientSessionNOK : OamModule::Counter::AnswerSentOnClientSessionNOK);
 964
 965     if(cid == helpers::base::COMMANDID__Capabilities_Exchange_Request) oamModule.count(OamModule::Counter::CERSentNOK);
 966     else if(cid == helpers::base::COMMANDID__Device_Watchdog_Request) oamModule.count(OamModule::Counter::DWRSentNOK);
 967     else if(cid == helpers::base::COMMANDID__Device_Watchdog_Answer) oamModule.count(OamModule::Counter::DWASentNOK);  // not usual (dwr was received from server)
 968     else if(cid == helpers::base::COMMANDID__Disconnect_Peer_Request) oamModule.count(OamModule::Counter::DPRSentNOK);
 969     else if(cid == helpers::base::COMMANDID__Disconnect_Peer_Answer) oamModule.count(OamModule::Counter::DPASentNOK);
 970     // Application messages:
 971     else {
 972       appMsgOamModule.count(cid.first, aid, isRequest ? ApplicationMessageOamModule::Counter::Request_SentNOK_AsClient : ApplicationMessageOamModule::Counter::Answer_SentNOK_AsClient);
 973     }
 974   }
 975 }
 976