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