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