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