Fixes and improvements
[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   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
452   // OAM
453   OamModule &oamModule = OamModule::instantiate();
454   oamModule.count(OamModule::Counter::RequestRetransmitted);
455   oamModule.count(OamModule::Counter::RequestRetransmittedOnClientSession);
456
457   // Inform father server:
458   a_parent->eventRequestRetransmission(this, request);
459 }
460
461 void ClientSession::eventResponse(const Response& response) throw(anna::RuntimeException) {
462   // Inform father server:
463   a_parent->eventResponse(response);
464 }
465
466 void ClientSession::eventRequest(const anna::DataBlock &request) throw(anna::RuntimeException) {
467   // Inform father server:
468   a_parent->eventRequest(this, request);
469 }
470
471 void ClientSession::eventUnknownResponse(const anna::DataBlock& response) throw(anna::RuntimeException) {
472   // Inform father server:
473   a_parent->eventUnknownResponse(this, response);
474 }
475
476 void ClientSession::eventDPA(const anna::DataBlock& response) throw(anna::RuntimeException) {
477   // Inform father server:
478   a_parent->eventDPA(this, response);
479 }
480
481
482
483 //------------------------------------------------------------------------------------------
484 // Se invoca desde el diameter::comm::Receiver
485 //------------------------------------------------------------------------------------------
486 void ClientSession::receive(const anna::comm::Message& message)
487 throw(anna::RuntimeException) {
488   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "receive", ANNA_FILE_LOCATION));
489   // Activity:
490   updateIncomingActivityTime();
491   activateTimer();
492   // Command id:
493   const anna::DataBlock & db = message.getBody();
494   diameter::CommandId cid = codec::functions::getCommandId(db);
495   bool isRequest = cid.second;
496   LOGDEBUG(
497     std::string msg = "Received diameter message: ";
498     msg += anna::diameter::functions::commandIdAsPairString(cid);
499     anna::Logger::debug(msg, ANNA_FILE_LOCATION);
500
501     if( (cid == helpers::base::COMMANDID__Capabilities_Exchange_Answer) ||
502         (cid.first == helpers::base::COMMANDID__Device_Watchdog_Request.first)) {
503       try {
504         anna::diameter::codec::Message dmsg(a_engine->getBaseProtocolCodecEngine()); dmsg.decode(db); /* decode to be traced */
505       }
506       catch(anna::RuntimeException &ex) {
507         std::string msg = ex.getText();
508         msg += " | Use diameter::comm::Engine::setBaseProtocolCodecEngine() to allow internal base protocol messages full tracing";
509         anna::Logger::debug(msg, ANNA_FILE_LOCATION);
510       }
511     }
512 );
513
514   // Main counters:
515   OamModule &oamModule = OamModule::instantiate();
516   oamModule.count(isRequest ? OamModule::Counter::RequestReceived : OamModule::Counter::AnswerReceived);
517   oamModule.count(isRequest ? OamModule::Counter::RequestReceivedOnClientSession : OamModule::Counter::AnswerReceivedOnClientSession);
518   // Statistic (size)
519   a_parent->updateReceivedMessageSizeStatisticConcept(message.getSize(), cid); // only on reception (application could manage sent sizes)
520
521   if(isRequest) {
522     /////////////////////////////
523     // Here received a request //
524     /////////////////////////////
525
526     // Received CER
527     if(cid == helpers::base::COMMANDID__Capabilities_Exchange_Request) {
528       LOGWARNING(anna::Logger::warning("Received CER: unexpected message at client-side", ANNA_FILE_LOCATION));
529       return;
530     }
531     // Received DWR
532     else if(cid == helpers::base::COMMANDID__Device_Watchdog_Request) {
533 //         LOGWARNING(anna::Logger::warning("Received DWR: unexpected message at client-side", ANNA_FILE_LOCATION));
534 //         return;
535       // Non-usual but could happen:
536       oamModule.count(OamModule::Counter::DWRReceived);
537       sendDWAToServer(db /* DWR datablock received from server */);
538       return;
539     }
540     // Received DPR
541     else if(cid == helpers::base::COMMANDID__Disconnect_Peer_Request) {
542       oamModule.count(OamModule::Counter::DPRReceived);
543
544       if(a_state == State::Bound) {
545         a_dpr.setBody(db);
546         setState(State::Disconnecting);
547         LOGWARNING(anna::Logger::warning("DPR has been received from peer (diameter server)", ANNA_FILE_LOCATION));
548
549         if(getOTARequests() == 0) sendDPA();
550
551         return; // DPR won't be informed because virtual readDPA is available for this
552       }
553     }
554
555     try {
556       // application message counters
557       ApplicationMessageOamModule::instantiate().count(cid.first, -1 /* no result code */, anna::diameter::codec::functions::getApplicationId(db), ApplicationMessageOamModule::Counter::Request_Received_AsClient);
558
559       eventRequest(db);
560     } catch(anna::RuntimeException& ex) {
561       ex.trace();
562     }
563
564     return;
565   }
566
567   /////////////////////////////
568   // Here received an answer //
569   /////////////////////////////
570   bool doUnbind = false;
571   bool immediateUnbind = false;
572   int resultCode = -1;
573
574   try {
575     resultCode = helpers::base::functions::getResultCode(db);
576   } catch(anna::RuntimeException& ex) {
577     // Not always mandatory ...
578     //ex.trace();
579   }
580
581   // Received CEA
582   if(cid == helpers::base::COMMANDID__Capabilities_Exchange_Answer) {
583     oamModule.count(OamModule::Counter::CEAReceived);
584
585     if(a_state != State::WaitingBind) {
586       LOGWARNING(anna::Logger::warning("Received CEA: unexpected message at not-WaitingBind state", ANNA_FILE_LOCATION));
587       return; // we don't send its request
588 //         string msg("diameter::comm::ClientSession::receive | ");
589 //         msg += asString();
590 //         msg += " | Received CEA on not-WaitingBind state: unexpected Bind-response";
591 //         throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
592     }
593
594     if(resultCode != helpers::base::AVPVALUES__Result_Code::DIAMETER_SUCCESS) {
595       LOGWARNING(
596         std::string msg = anna::functions::asString("Received CEA with non-success Result-Code (%d). Unbinding connection.", resultCode);
597         anna::Logger::warning(msg, ANNA_FILE_LOCATION);
598       );
599       doUnbind = true;
600     } else {
601       setState(State::Bound);
602       //activateTimer(); // Ya se invoca al inicio de este metodo ::receive
603       // Inform father server (availability changes):
604       a_parent->refreshAvailability();
605       //startClock();
606     }
607   }
608   // Received DWA
609   else if(cid == helpers::base::COMMANDID__Device_Watchdog_Answer) {
610     oamModule.count(OamModule::Counter::DWAReceived);
611     setWatchdogState(WatchdogState::WaitingTimerExpiration);
612
613     if(resultCode != helpers::base::AVPVALUES__Result_Code::DIAMETER_SUCCESS)
614       LOGWARNING(
615         std::string msg = anna::functions::asString("Received DWA with non-success Result-Code (%d)... but ASSUME keep-alive is reached", resultCode);
616         anna::Logger::warning(msg, ANNA_FILE_LOCATION);
617       );
618
619     if(a_state == State::Failover) {
620       setState(State::Bound);
621       LOGDEBUG(
622         string msg("diameter::comm::ClientSession::receive | ");
623         msg += asString();
624         msg += " | Received DWA on failover state: recovering Bound state";
625         anna::Logger::debug(msg, ANNA_FILE_LOCATION);
626       );
627     }
628
629     // Keep-Alive don't manage context
630     return;
631   }
632   // Received DPA
633   else if(cid == helpers::base::COMMANDID__Disconnect_Peer_Answer) {
634     oamModule.count(OamModule::Counter::DPAReceived);
635
636     if(a_state == State::WaitingDPA) {
637       if(resultCode != helpers::base::AVPVALUES__Result_Code::DIAMETER_SUCCESS) {
638         LOGWARNING(
639           std::string msg = anna::functions::asString("Received DPA with non-success Result-Code (%d). Ignoring and recovering Bound state", resultCode);
640           anna::Logger::warning(msg, ANNA_FILE_LOCATION);
641         );
642         setState(State::Bound);
643       } else {
644         LOGWARNING(anna::Logger::warning("Received DPA With Result-Code = DIAMETER_SUCCESS. Disconnect now.", ANNA_FILE_LOCATION));
645         immediateUnbind = true;
646         doUnbind = true;
647       }
648     }
649   }
650
651   HopByHop hopByHop = codec::functions::getHopByHop(db); // context identification
652   Response* response = response_find(hopByHop);
653
654   // Out-of-context responses:
655   if(!response) {
656     // OAM
657     oamModule.count(OamModule::Counter::AnswerReceivedUnknown);
658     oamModule.count(OamModule::Counter::AnswerReceivedOnClientSessionUnknown);
659     oamModule.activateAlarm(OamModule::Alarm::AnswerReceivedOnClientSessionUnknown);
660
661     // application message counters
662     ApplicationMessageOamModule::instantiate().count(cid.first, resultCode, anna::diameter::codec::functions::getApplicationId(db), ApplicationMessageOamModule::Counter::Answer_UnknownReceived_AsClient);
663
664     eventUnknownResponse(db);
665     string msg(asString());
666     msg += anna::functions::asString(" | Response received from entity, for non registered context (HopByHop: %u)", hopByHop);
667     throw anna::RuntimeException(msg, ANNA_FILE_LOCATION);
668   }
669
670   response->setResultCode(Response::ResultCode::Success);
671   response->cancelTimer();
672   LOGDEBUG(
673     string msg("diameter::comm::ClientSession::receive | ");
674     msg += asString();
675     msg += " | Received answer";
676     msg += response->asString();
677     anna::Logger::debug(msg, ANNA_FILE_LOCATION);
678   );
679   // Statistics
680   anna::Millisecond current = (anna::Millisecond)anna::functions::millisecond();
681   anna::Millisecond request = response->getRequest()->getRequestTimestampMs();
682   anna::Millisecond timeToAnswerMs = current - request;
683   a_parent->updateProcessingTimeStatisticConcept(timeToAnswerMs, cid);
684   //LOGDEBUG
685   //(
686   //  std::string msg = "This diameter request context lasted ";
687   //  msg += anna::functions::asString(timeToAnswerMs);
688   //  msg += " milliseconds at diameter server (included network time)";
689   //  anna::Logger::debug(msg, ANNA_FILE_LOCATION);
690   //);
691   // Progress origin for tracking purposes on asyncronous boxes with both diameter interfaces (entities and clients)
692   Message * requestMessage = const_cast<Message*>(response->getRequest());
693   requestMessage->setRequestServerSessionKey(response->getRequest()->getRequestServerSessionKey()); // -1 means unkown/unset
694
695   if(cid != helpers::base::COMMANDID__Disconnect_Peer_Answer) {
696     try {
697       response->setMessage(&db);
698       // Restore received datablock
699       LOGDEBUG(
700         string msg("diameter::comm::ClientSession::receive | Restore answer to original request sequences (hop-by-hop = ");
701         msg += anna::functions::asString(response->getRequest()->getRequestHopByHop());
702         msg += ", end-to-end = ";
703         msg += anna::functions::asString(response->getRequest()->getRequestEndToEnd());
704         msg += ")";
705         anna::Logger::debug(msg, ANNA_FILE_LOCATION);
706       );
707       diameter::codec::functions::setHopByHop((anna::DataBlock&)db, response->getRequest()->getRequestHopByHop());
708       diameter::codec::functions::setEndToEnd((anna::DataBlock&)db, response->getRequest()->getRequestEndToEnd());
709
710       // application message counters
711       if(cid != helpers::base::COMMANDID__Capabilities_Exchange_Answer)
712         ApplicationMessageOamModule::instantiate().count(cid.first, resultCode, anna::diameter::codec::functions::getApplicationId(db), ApplicationMessageOamModule::Counter::Answer_Received_AsClient);
713
714       eventResponse(*response);
715     } catch(anna::RuntimeException& ex) {
716       ex.trace();
717     }
718   }
719   else { // DPA
720     // unbind is automatically performed, anyway we can inform to the application just in case some additional
721     //  procedure could be issued:
722     eventDPA(db);
723   }
724
725   response_erase(response);
726
727   // Unbind trigger
728   if(doUnbind)
729     unbind(immediateUnbind);
730 }
731
732 void ClientSession::finalize() throw() {
733   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "finalize", ANNA_FILE_LOCATION));
734   Session::finalize();
735   // Inform father server (availability changes):
736   a_parent->refreshAvailability();
737   // OAM
738   const Server *server = getParent();
739   bool multipleConnections = (server->getMaxClientSessions() > 1);
740   std::string socket = anna::functions::socketLiteralAsString(getAddress(), getPort());
741   OamModule &oamModule = OamModule::instantiate();
742
743   if(multipleConnections) {
744     oamModule.activateAlarm(OamModule::Alarm::c_LostAvailabilityOverClientSessionWithServer__s__ClientSessionId__d__, socket.c_str(), getSocketId());
745     oamModule.count(OamModule::Counter::LostAvailabilityOverClientSession);
746   } else {
747     oamModule.activateAlarm(OamModule::Alarm::c_LostAvailabilityOverClientSessionWithServer__s__, socket.c_str());
748     oamModule.count(OamModule::Counter::LostAvailabilityOverClientSession);
749   }
750 }
751
752 void ClientSession::recover() throw() {
753   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "recover", ANNA_FILE_LOCATION));
754
755   try {
756     bind();
757   } catch(anna::RuntimeException &ex) {
758     // Again:
759     anna::comm::ClientSocket * cs = const_cast<anna::comm::ClientSocket*>(a_server->getClientSocket());
760
761     if(cs) cs->requestClose();
762
763     ex.trace();
764   }
765
766   // Inform father server (availability changes):
767   a_parent->refreshAvailability();
768   // OAM
769   const Server *server = getParent();
770   bool multipleConnections = (server->getMaxClientSessions() > 1);
771   std::string socket = anna::functions::socketLiteralAsString(getAddress(), getPort());
772   OamModule &oamModule = OamModule::instantiate();
773
774   if(multipleConnections) {
775     oamModule.cancelAlarm(OamModule::Alarm::c_LostAvailabilityOverClientSessionWithServer__s__ClientSessionId__d__, socket.c_str(), getSocketId());
776     oamModule.count(OamModule::Counter::RecoveredAvailabilityOverClientSession);
777   } else {
778     oamModule.cancelAlarm(OamModule::Alarm::c_LostAvailabilityOverClientSessionWithServer__s__, socket.c_str());
779     oamModule.count(OamModule::Counter::RecoveredAvailabilityOverClientSession);
780   }
781 }
782
783 void ClientSession::sendDWAToServer(const anna::DataBlock& dwrDB)
784 throw(anna::RuntimeException) {
785   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "sendDWAToServer", ANNA_FILE_LOCATION));
786   anna::DataBlock dwa(true);
787   a_engine->readDWA(dwa, dwrDB); // Asume that DWA is valid ...
788
789   if(dwa.isEmpty())
790     throw anna::RuntimeException("This diameter agent defines an empty DWA message. Remote server never will validate this connection health", ANNA_FILE_LOCATION);
791
792   Message msgDwa;
793   msgDwa.setBody(dwa);
794   send(&msgDwa);
795 }
796
797 //-------------------------------------------------------------------------
798 // Se invoca desde diameter::comm::Timer
799 //-------------------------------------------------------------------------
800 void ClientSession::expireResponse(diameter::comm::Response* response)
801 throw() {
802   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "expireResponse", ANNA_FILE_LOCATION));
803   Session::expireResponse(response);
804   // OAM
805   OamModule &oamModule = OamModule::instantiate();
806   oamModule.count(OamModule::Counter::RequestSentExpired);
807   oamModule.count(OamModule::Counter::RequestSentOnClientSessionExpired);
808   oamModule.activateAlarm(OamModule::Alarm::RequestSentOnClientSessionExpired);
809
810   // Check father server idleness:
811   if(idle()) a_parent->childIdle();
812
813 //   if (idle()) {
814 //      LOGDEBUG(anna::Logger::debug("ClientSession is idle after an expiration...", ANNA_FILE_LOCATION));
815 //      a_parent->childIdle();
816 //   }
817 //   else {
818 //      LOGDEBUG(anna::Logger::debug("ClientSession is busy after an expiration...", ANNA_FILE_LOCATION));
819 //   }
820 }
821
822
823 std::string ClientSession::asString() const
824 throw() {
825   string result = Session::asString();
826   result += " | Parent Server: ";
827   result += anna::functions::socketLiteralAsString(getAddress(), getPort());
828   result += " | Auto-recovery: ";
829   result += (a_autoRecovery ? "yes" : "no");
830   result += " | WatchdogState: ";
831   result += asText(a_watchdogState);
832   // Diferente del timeout de ApplicationMessage:
833   result += " | Watchdog Period: ";
834   result += getTimeout().asString();
835   result += " | Hidden: ";
836   result += (hidden() ? "yes" : "no");
837
838   if(a_server) {
839     result += " | MaxConnectionDelay: ";
840     result += a_server->getMaxConnectionDelay().asString();
841   }
842
843   return result += " }";
844 }
845
846 anna::xml::Node* ClientSession::asXML(anna::xml::Node* parent) const
847 throw() {
848   anna::xml::Node* result = Session::asXML(parent);
849   parent->createChild("diameter.comm.ClientSession");
850   result->createAttribute("ParentServer", anna::functions::socketLiteralAsString(getAddress(), getPort()));
851   result->createAttribute("AutoRecovery", (a_autoRecovery ? "yes" : "no"));
852   result->createAttribute("WatchdogState", asText(a_watchdogState));
853   // Diferente del timeout de ApplicationMessage:
854   result->createAttribute("WatchdogPeriod", getTimeout().asString());
855
856   if(a_server) result->createAttribute("MaxConnectionDelay", a_server->getMaxConnectionDelay().asString());
857
858   result->createAttribute("Hidden", hidden() ? "yes" : "no");
859   return result;
860 }
861
862
863 const char* ClientSession::asText(const WatchdogState::_v watchdogState)
864 throw() {
865   static const char* text [] = { "TimerStopped", "WaitingTimerExpiration", "WaitingDWA" };
866   return text [watchdogState];
867 }
868
869
870 //------------------------------------------------------------------------------
871 //------------------------------------------------------ ClientSession::expire()
872 //------------------------------------------------------------------------------
873 void ClientSession::expire(anna::timex::Engine *timeController) throw(anna::RuntimeException) {
874   LOGMETHOD(anna::TraceMethod traceMethod(a_className, "expire (watchdog timer)", ANNA_FILE_LOCATION));
875
876   //   The client MUST NOT close the primary connection until the
877   //    primary's watchdog timer has expired at least twice without a
878   //    response (note that the watchdog is not sent a second time,
879   //    however).
880   if(a_watchdogState == WatchdogState::WaitingDWA) {
881     if(a_state == State::Failover) {
882       LOGWARNING(anna::Logger::warning("Unbinding client-session: Tw expired after first DWA missing (2*Tw elapsed)", ANNA_FILE_LOCATION));
883       unbind();
884       return; // finalize will stop the stopped timer ...
885     }
886
887     setState(State::Failover);
888     LOGWARNING(anna::Logger::warning("Going to Failover state: first DWA missing", ANNA_FILE_LOCATION));
889     activateTimer(); // another chance on failover
890     return;
891   }
892
893   // WaitingTimerExpiration arrives here:
894   const Response* sent;
895
896   try {
897     sent = send(&a_dwr);
898   } catch(anna::RuntimeException&) {
899     LOGDEBUG(anna::Logger::debug("Failed to send DWR to the server: unbinding ...", ANNA_FILE_LOCATION));
900     setState(State::Failover);
901     unbind();
902     throw;
903   }
904
905   LOGDEBUG(if(sent) anna::Logger::debug("DWR sent to the server", ANNA_FILE_LOCATION););
906
907   activateTimer();
908 }
909
910 void ClientSession::setWatchdogPeriod(const anna::Millisecond & watchdogPeriod) throw() {
911   setTimeout(watchdogPeriod);
912 }
913
914 void ClientSession::setWatchdogState(WatchdogState::_v wState) throw() {
915   LOGDEBUG(
916
917   if(wState != a_watchdogState) {
918   std::string msg("Session watchdog state change: ");
919     msg += asText(a_watchdogState);
920     msg += " -> ";
921     msg += asText(wState);
922     anna::Logger::debug(msg, ANNA_FILE_LOCATION);
923   }
924   );
925   a_watchdogState = wState;
926 }
927
928
929 void ClientSession::timerStopped() throw() {
930   LOGDEBUG(anna::Logger::debug("Watchdog timer stopped", ANNA_FILE_LOCATION));
931   setWatchdogState(WatchdogState::TimerStopped);
932 }
933
934 void ClientSession::timerStarted() throw() {
935   LOGDEBUG(anna::Logger::debug("Watchdog timer started", ANNA_FILE_LOCATION));
936
937   if(a_watchdogState == WatchdogState::WaitingDWA) return;
938
939   setWatchdogState(WatchdogState::WaitingTimerExpiration);
940 }
941
942
943 //------------------------------------------------------------------------------
944 //---------------------------------- ClientSession::updateIncomingActivityTime()
945 //------------------------------------------------------------------------------
946 void ClientSession::updateIncomingActivityTime() throw() {
947   Session::updateIncomingActivityTime();
948   a_parent->updateIncomingActivityTime();
949 }
950
951
952 //------------------------------------------------------------------------------
953 //---------------------------------- ClientSession::updateOutgoingActivityTime()
954 //------------------------------------------------------------------------------
955 void ClientSession::updateOutgoingActivityTime(void) throw() {
956   Session::updateOutgoingActivityTime();
957   a_parent->updateOutgoingActivityTime();
958 }
959
960
961
962 //------------------------------------------------------------------------------
963 //----------------------------------------------- ClientSession::countSendings()
964 //------------------------------------------------------------------------------
965 void ClientSession::countSendings(const diameter::CommandId & cid, unsigned int aid, bool ok)throw() {
966   OamModule &oamModule = OamModule::instantiate();
967   ApplicationMessageOamModule &appMsgOamModule = ApplicationMessageOamModule::instantiate();
968
969   bool isRequest = cid.second;
970
971   if(ok) {
972     // Main counters:
973     oamModule.count(isRequest ? OamModule::Counter::RequestSentOK : OamModule::Counter::AnswerSentOK);
974     oamModule.count(isRequest ? OamModule::Counter::RequestSentOnClientSessionOK : OamModule::Counter::AnswerSentOnClientSessionOK);
975
976     if(cid == helpers::base::COMMANDID__Capabilities_Exchange_Request) oamModule.count(OamModule::Counter::CERSentOK);
977     else if(cid == helpers::base::COMMANDID__Device_Watchdog_Request) oamModule.count(OamModule::Counter::DWRSentOK);
978     else if(cid == helpers::base::COMMANDID__Device_Watchdog_Answer) oamModule.count(OamModule::Counter::DWASentOK);  // not usual (dwr was received from server)
979     else if(cid == helpers::base::COMMANDID__Disconnect_Peer_Request) oamModule.count(OamModule::Counter::DPRSentOK);
980     else if(cid == helpers::base::COMMANDID__Disconnect_Peer_Answer) oamModule.count(OamModule::Counter::DPASentOK);
981     // Application messages:
982     else {
983       appMsgOamModule.count(cid.first, -1 /* no result code */, aid, isRequest ? ApplicationMessageOamModule::Counter::Request_SentOK_AsClient : ApplicationMessageOamModule::Counter::Answer_SentOK_AsClient);
984     }
985   } else {
986     // Main counters:
987     oamModule.count(isRequest ? OamModule::Counter::RequestSentNOK : OamModule::Counter::AnswerSentNOK);
988     oamModule.count(isRequest ? OamModule::Counter::RequestSentOnClientSessionNOK : OamModule::Counter::AnswerSentOnClientSessionNOK);
989
990     if(cid == helpers::base::COMMANDID__Capabilities_Exchange_Request) oamModule.count(OamModule::Counter::CERSentNOK);
991     else if(cid == helpers::base::COMMANDID__Device_Watchdog_Request) oamModule.count(OamModule::Counter::DWRSentNOK);
992     else if(cid == helpers::base::COMMANDID__Device_Watchdog_Answer) oamModule.count(OamModule::Counter::DWASentNOK);  // not usual (dwr was received from server)
993     else if(cid == helpers::base::COMMANDID__Disconnect_Peer_Request) oamModule.count(OamModule::Counter::DPRSentNOK);
994     else if(cid == helpers::base::COMMANDID__Disconnect_Peer_Answer) oamModule.count(OamModule::Counter::DPASentNOK);
995     // Application messages:
996     else {
997       appMsgOamModule.count(cid.first, -1 /* no result code */, aid, isRequest ? ApplicationMessageOamModule::Counter::Request_SentNOK_AsClient : ApplicationMessageOamModule::Counter::Answer_SentNOK_AsClient);
998     }
999   }
1000 }
1001