ims_charging: fixed bug causing dialog cb function to be called more than once

- removed possible race condition in dialog cb
- improved the way locking was performed

modules/ims_charging/README

@@ -75,8 +75,11 @@ Carlos Ruiz Diaz
               6.9. Failed final CCRs (failed_final_ccrs)
               6.10. CCRs average response time (ccr_avg_response_time)
               6.11. CCRs responses time (ccr_responses_time)
-              6.12. Billed seconds (billed_secs)
-              6.13. Killed calls (killed_calls)
+              6.12. CCRs requests, which ended with a timeout
+                      (ccr_timeouts)
+
+              6.13. Billed seconds (billed_secs)
+              6.14. Killed calls (killed_calls)
 
    List of Examples
 
@@ -155,8 +158,9 @@ Chapter 1. Admin Guide
         6.9. Failed final CCRs (failed_final_ccrs)
         6.10. CCRs average response time (ccr_avg_response_time)
         6.11. CCRs responses time (ccr_responses_time)
-        6.12. Billed seconds (billed_secs)
-        6.13. Killed calls (killed_calls)
+        6.12. CCRs requests, which ended with a timeout (ccr_timeouts)
+        6.13. Billed seconds (billed_secs)
+        6.14. Killed calls (killed_calls)
 
 1. Overview
 
@@ -340,8 +344,9 @@ Chapter 1. Admin Guide
    Default value is 4096.
 
    Example 1.1.  hash_sizeparameter usage
-... modparam("ims_charging", "hash_size", 1024)
-        ...
+...
+modparam("ims_charging", "hash_size", 1024)
+...
 
 4.2.  interim_update_credits(int)
 
@@ -352,8 +357,9 @@ Chapter 1. Admin Guide
    Default value is 30.
 
    Example 1.2.  interim_update_creditsparameter usage
-... modparam("ims_charging",
-        "interim_update_credits", 600) ...
+...
+modparam("ims_charging", "interim_update_credits", 600)
+...
 
 4.3.  timer_buffer(int)
 
@@ -363,8 +369,9 @@ Chapter 1. Admin Guide
    Default value is 8.
 
    Example 1.3.  timer_bufferparameter usage
-... modparam("ims_charging", "timer_buffer", 10)
-        ...
+...
+modparam("ims_charging", "timer_buffer", 10)
+...
 
 4.4.  ro_forced_peer(string)
 
@@ -374,8 +381,9 @@ Chapter 1. Admin Guide
    Default value is ''.
 
    Example 1.4.  ro_forced_peerparameter usage
-... modparam("ims_charging", "ro_forced_peer",
-        "ocs.ims.smilecoms.com") ...
+...
+modparam("ims_charging", "ro_forced_peer", "ocs.ims.smilecoms.com")
+...
 
 4.5.  ro_auth_expiry(integer)
 
@@ -385,8 +393,9 @@ Chapter 1. Admin Guide
    Default value is 7200.
 
    Example 1.5.  ro_auth_expiryparameter usage
-... modparam("ims_charging", "ro_auth_expiry", 14400)
-        ...
+...
+modparam("ims_charging", "ro_auth_expiry", 14400)
+...
 
 4.6.  ro_auth_expiry(integer)
 
@@ -396,8 +405,9 @@ Chapter 1. Admin Guide
    Default value is 7200.
 
    Example 1.6.  ro_auth_expiryparameter usage
-... modparam("ims_charging", "ro_auth_expiry", 14400)
-        ...
+...
+modparam("ims_charging", "ro_auth_expiry", 14400)
+...
 
 4.7.  cdp_event_latency(integer)
 
@@ -407,8 +417,9 @@ Chapter 1. Admin Guide
    Default value is 1.
 
    Example 1.7.  cdp_event_latencyparameter usage
-... modparam("ims_charging", "cdp_event_latency", 1)
-        ...
+...
+modparam("ims_charging", "cdp_event_latency", 1)
+...
 
 4.8.  cdp_event_threshold(integer)
 
@@ -420,8 +431,9 @@ Chapter 1. Admin Guide
    Default value is 500.
 
    Example 1.8.  cdp_event_thresholdparameter usage
-... modparam("ims_charging", "cdp_event_threshold",
-        500) ...
+...
+modparam("ims_charging", "cdp_event_threshold", 500)
+...
 
 4.9.  cdp_event_latency_log(integer)
 
@@ -432,8 +444,9 @@ Chapter 1. Admin Guide
    Default value is 0.
 
    Example 1.9.  cdp_event_latency_logparameter usage
-... modparam("ims_charging", "cdp_event_latency_log",
-        1) ...
+...
+modparam("ims_charging", "cdp_event_latency_log", 1)
+...
 
 4.10.  origin_host(string)
 
@@ -442,8 +455,9 @@ Chapter 1. Admin Guide
    Default value is "scscf.ims.smilecoms.com".
 
    Example 1.10.  origin_hostparameter usage
-... modparam("ims_charging", "origin_host",
-        "scscf.kamailio-ims.org") ...
+...
+modparam("ims_charging", "origin_host", "scscf.kamailio-ims.org")
+...
 
 4.11.  origin_realm(string)
 
@@ -452,8 +466,9 @@ Chapter 1. Admin Guide
    Default value is "ims.smilecome.com".
 
    Example 1.11.  origin_realmparameter usage
-... modparam("ims_charging", "origin_realm",
-        "kamailio-ims.org") ...
+...
+modparam("ims_charging", "origin_realm", "kamailio-ims.org")
+...
 
 4.12.  destination_host(string)
 
@@ -462,8 +477,9 @@ Chapter 1. Admin Guide
    Default value is 5s.
 
    Example 1.12.  destination_hostparameter usage
-... modparam("ims_charging", "destination_host",
-        "ocs.kamailio-ims.org") ...
+...
+modparam("ims_charging", "destination_host", "ocs.kamailio-ims.org")
+...
 
 4.13.  destination_realm(string)
 
@@ -472,8 +488,9 @@ Chapter 1. Admin Guide
    Default value is "ims.smilecoms.com".
 
    Example 1.13.  destination_realmparameter usage
-... modparam("ims_charging", "destination_realm",
-        "kamailio-ims.org") ...
+...
+modparam("ims_charging", "destination_realm", "kamailio-ims.org")
+...
 
 4.14.  service_context_id_root(string)
 
@@ -487,8 +504,7 @@ Chapter 1. Admin Guide
    provider, by the service element manufacturer, or by a standardization
    body, and MUST uniquely identify a given Diameter credit-control
    service specific document. The format of the Service-Context-Id is:
-"service-context" "@" "domain" service-context =
-      Token
+"service-context" "@" "domain" service-context = Token
 
    The Token is an arbitrary string of characters and digits.
 
@@ -508,8 +524,9 @@ Chapter 1. Admin Guide
    Default value is "[email protected]".
 
    Example 1.14.  service_context_id_rootparameter usage
-... modparam("ims_charging",
-        "service_context_id_root", "[email protected]") ...
+...
+modparam("ims_charging", "service_context_id_root", "[email protected]")
+...
 
 4.15.  service_context_id_ext(string)
 
@@ -519,8 +536,9 @@ Chapter 1. Admin Guide
    Default value is "ext".
 
    Example 1.15.  service_context_id_extparameter usage
-... modparam("ims_charging",
-        "service_context_id_ext", "ext2") ...
+...
+modparam("ims_charging", "service_context_id_ext", "ext2")
+...
 
 4.16.  service_context_id_mnc(string)
 
@@ -530,8 +548,9 @@ Chapter 1. Admin Guide
    Default value is "01".
 
    Example 1.16.  service_context_id_mncparameter usage
-... modparam("ims_charging",
-        "service_context_id_mnc", "42") ...
+...
+modparam("ims_charging", "service_context_id_mnc", "42")
+...
 
 4.17.  service_context_id_mcc(string)
 
@@ -544,8 +563,9 @@ Chapter 1. Admin Guide
    Default value is "001".
 
    Example 1.17.  service_context_id_mccparameter usage
-... modparam("ims_charging",
-        "service_context_id_mcc", "262") ...
+...
+modparam("ims_charging", "service_context_id_mcc", "262")
+...
 
 4.18.  service_context_id_release(string)
 
@@ -555,8 +575,9 @@ Chapter 1. Admin Guide
    Default value is "8" (Release 8).
 
    Example 1.18.  service_context_id_releaseparameter usage
-... modparam("ims_charging",
-        "service_context_id_release", "262") ...
+...
+modparam("ims_charging", "service_context_id_release", "262")
+...
 
 5. Functions
 
@@ -586,21 +607,34 @@ reservation_units)
    return value.
 
    Example 1.19. Ro_CCR
-... xlog("L_DBG","Sending initial CCR Request for
-        call\n"); Ro_CCR("CHARGING_CCR_REPLY", "orig", "SCUR", "", "30"); }
-        route[CHARGING_CCR_REPLY] { xlog("L_DBG","cca_return code is $avp(s:cca_
-return_code)\n");
-        switch ($avp(s:cca_return_code)){ case 1: #success xlog("L_DBG", "CCR su
-ccess - will route
-        message\n"); route(Finalize_Orig); break; case -1: #failure xlog("L_ERR"
-, "CCR failure -
-        error response sent from module\n"); sl_send_reply("402","Payment requir
-ed"); break; case
-        -2: #error xlog("L_ERR", "CCR error - error response sent from module\n"
-);
-        sl_send_reply("500", "Charging Error"); break; default: xlog("L_ERR", "U
-nknown return code
-        from CCR: [$avp(s:cca_return_code)] \n"); break; } exit; } ...
+...
+  xlog("L_DBG","Sending initial CCR Request for call\n");
+  Ro_CCR("CHARGING_CCR_REPLY", "orig", "SCUR", "", "30");
+}
+
+route[CHARGING_CCR_REPLY]
+  xlog("L_DBG","cca_return code is $avp(s:cca_return_code)\n");
+  switch ($avp(s:cca_return_code)) {
+    case 1: #success
+        xlog("L_DBG", "CCR success - will route message\n");
+        route(Finalize_Orig);
+        break;
+    case -1: #failure
+        xlog("L_ERR", "CCR failure - error response sent from module\n");
+        sl_send_reply("402","Payment required");
+        break;
+    case -2: #error
+        xlog("L_ERR", "CCR error - error response sent from module\n");
+        sl_send_reply("500", "Charging Error");
+        break;
+    default:
+        xlog("L_ERR", "Unknown return code from CCR: [$avp(s:cca_return_code)] \
+n");
+        break;
+  }
+  exit;
+  }
+...
 
 6. Statistics
 
@@ -615,8 +649,9 @@ nknown return code
    6.9. Failed final CCRs (failed_final_ccrs)
    6.10. CCRs average response time (ccr_avg_response_time)
    6.11. CCRs responses time (ccr_responses_time)
-   6.12. Billed seconds (billed_secs)
-   6.13. Killed calls (killed_calls)
+   6.12. CCRs requests, which ended with a timeout (ccr_timeouts)
+   6.13. Billed seconds (billed_secs)
+   6.14. Killed calls (killed_calls)
 
 6.1. Initial CCRs (initial_ccrs)
 
@@ -666,10 +701,14 @@ nknown return code
 
    Total CCA arrival time in milliseconds.
 
-6.12. Billed seconds (billed_secs)
+6.12. CCRs requests, which ended with a timeout (ccr_timeouts)
+
+   Number of CCR-Requests, which ran into an timeout.
+
+6.13. Billed seconds (billed_secs)
 
    Number of seconds billed in total.
 
-6.13. Killed calls (killed_calls)
+6.14. Killed calls (killed_calls)
 
    Number of calls that were killed due to lack of credit.

modules/ims_charging/dialog.c

@@ -42,12 +42,17 @@ void dlg_reply(struct dlg_cell *dlg, int type, struct dlg_cb_params *_params) {
 		ro_session_entry = &(ro_session_table->entries[session->h_entry]);
 		ro_session_lock(ro_session_table, ro_session_entry);
 
+		if (session->active) {
+			LM_CRIT("Why the heck am i receiving a double confirmation of the dialog? Ignoring... ");
+			ro_session_unlock(ro_session_table, ro_session_entry);
+			return;
+		}
+	
 		time_since_last_event = now - session->last_event_timestamp;
 		session->start_time = session->last_event_timestamp = now;
 		session->event_type = answered;
 		session->active = 1;
 		
-		ro_session_unlock(ro_session_table, ro_session_entry);
 
 		/* check to make sure that the validity of the credit is enough for the bundle */
 		int ret = 0;
@@ -64,12 +69,16 @@ void dlg_reply(struct dlg_cell *dlg, int type, struct dlg_cb_params *_params) {
 				ret = insert_ro_timer(&session->ro_tl, session->valid_for);
 			}
 		}
+
+
 		if (ret != 0) {
 			LM_CRIT("unable to insert timer for Ro Session [%.*s]\n", session->ro_session_id.len, session->ro_session_id.s); 
 		} else {
-			ref_ro_session(session, 1);
+			ref_ro_session_unsafe(session, 1); // lock already acquired
 		}
 				
+		ro_session_unlock(ro_session_table, ro_session_entry);
+
 		AAASession* cdp_session = cdpb.AAAGetCCAccSession(session->ro_session_id);
 		if (!cdp_session) {
 			LM_ERR("could not find find CC App CDP session for session [%.*s]\n", session->ro_session_id.len, session->ro_session_id.s);
@@ -121,25 +130,29 @@ void dlg_terminated(struct dlg_cell *dlg, int type, struct dlg_cb_params *_param
 					LM_ERR("Ro Session is not active, but may have been answered [%d]\n", (int)ro_session->start_time);
 					continue;
 				}
-				
+			
+	
 				ro_session_lock(ro_session_table, ro_session_entry);
-				int ret = remove_ro_timer(&ro_session->ro_tl);
-				if (ret < 0) {
-					LM_CRIT("unable to unlink the timer on ro_session %p [%.*s]\n", 
-						ro_session, ro_session->cdp_session_id.len, ro_session->cdp_session_id.s);
-				} else if (ret > 0) {
-					LM_WARN("inconsistent ro timer data on ro_session %p [%.*s]\n",
-						ro_session, ro_session->cdp_session_id.len, ro_session->cdp_session_id.s);						
-				} else {
-					unref++;
+
+				if (ro_session->active) { // if the call was never activated, there's no timer to remove
+					int ret = remove_ro_timer(&ro_session->ro_tl);
+					if (ret < 0) {
+						LM_CRIT("unable to unlink the timer on ro_session %p [%.*s]\n", 
+							ro_session, ro_session->cdp_session_id.len, ro_session->cdp_session_id.s);
+					} else if (ret > 0) {
+						LM_WARN("inconsistent ro timer data on ro_session %p [%.*s]\n",
+							ro_session, ro_session->cdp_session_id.len, ro_session->cdp_session_id.s);						
+					} else {
+						unref++;
+					}
 				}
 
 				LM_DBG("Sending CCR STOP on Ro_Session [%p]\n", ro_session);
 				send_ccr_stop(ro_session);
 				ro_session->active = 0;
 				//ro_session->start_time;
+				unref_ro_session_unsafe(ro_session, 2+unref, ro_session_entry); //lock already acquired
 				ro_session_unlock(ro_session_table, ro_session_entry);
-				unref_ro_session(ro_session, 2+unref);
 			}
 		}
 	}

modules/ims_charging/doc/ims_charging_admin.xml

@@ -185,8 +185,11 @@
       <example>
         <title>
         <varname>hash_size</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging", "hash_size", 1024)
-        ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "hash_size", 1024)
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -201,8 +204,11 @@
       <example>
         <title>
         <varname>interim_update_credits</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging",
-        "interim_update_credits", 600) ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "interim_update_credits", 600)
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -215,8 +221,11 @@
       <example>
         <title>
         <varname>timer_buffer</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging", "timer_buffer", 10)
-        ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "timer_buffer", 10)
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -230,8 +239,11 @@
       <example>
         <title>
         <varname>ro_forced_peer</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging", "ro_forced_peer",
-        "ocs.ims.smilecoms.com") ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "ro_forced_peer", "ocs.ims.smilecoms.com")
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -244,8 +256,11 @@
       <example>
         <title>
         <varname>ro_auth_expiry</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging", "ro_auth_expiry", 14400)
-        ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "ro_auth_expiry", 14400)
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -258,8 +273,11 @@
       <example>
         <title>
         <varname>ro_auth_expiry</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging", "ro_auth_expiry", 14400)
-        ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "ro_auth_expiry", 14400)
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -273,8 +291,11 @@
       <example>
         <title>
         <varname>cdp_event_latency</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging", "cdp_event_latency", 1)
-        ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "cdp_event_latency", 1)
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -289,8 +310,11 @@
       <example>
         <title>
         <varname>cdp_event_threshold</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging", "cdp_event_threshold",
-        500) ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "cdp_event_threshold", 500)
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -305,8 +329,11 @@
       <example>
         <title>
         <varname>cdp_event_latency_log</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging", "cdp_event_latency_log",
-        1) ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "cdp_event_latency_log", 1)
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -319,8 +346,11 @@
       <example>
         <title>
         <varname>origin_host</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging", "origin_host",
-        "scscf.kamailio-ims.org") ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "origin_host", "scscf.kamailio-ims.org")
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -333,8 +363,11 @@
       <example>
         <title>
         <varname>origin_realm</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging", "origin_realm",
-        "kamailio-ims.org") ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "origin_realm", "kamailio-ims.org")
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -347,8 +380,11 @@
       <example>
         <title>
         <varname>destination_host</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging", "destination_host",
-        "ocs.kamailio-ims.org") ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "destination_host", "ocs.kamailio-ims.org")
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -361,8 +397,11 @@
       <example>
         <title>
         <varname>destination_realm</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging", "destination_realm",
-        "kamailio-ims.org") ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "destination_realm", "kamailio-ims.org")
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -376,8 +415,9 @@
       service provider, by the service element manufacturer, or by a standardization body, and MUST
       uniquely identify a given Diameter credit-control service specific document. The format of
       the Service-Context-Id is:</para>
-      <programlisting format="linespecific">"service-context" "@" "domain" service-context =
-      Token</programlisting>
+      <programlisting format="linespecific">
+"service-context" "@" "domain" service-context = Token
+      </programlisting>
       <para>The Token is an arbitrary string of characters and digits.</para>
       <para>'domain' represents the entity that allocated the Service-Context-Id. It can be
       ietf.org, 3gpp.org, etc., if the identifier is allocated by a standardization body, or it can
@@ -394,8 +434,11 @@
       <example>
         <title>
         <varname>service_context_id_root</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging",
-        "service_context_id_root", "[email protected]") ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "service_context_id_root", "[email protected]")
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -409,8 +452,11 @@
       <example>
         <title>
         <varname>service_context_id_ext</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging",
-        "service_context_id_ext", "ext2") ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "service_context_id_ext", "ext2")
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -424,8 +470,11 @@
       <example>
         <title>
         <varname>service_context_id_mnc</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging",
-        "service_context_id_mnc", "42") ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "service_context_id_mnc", "42")
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -440,8 +489,11 @@
       <example>
         <title>
         <varname>service_context_id_mcc</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging",
-        "service_context_id_mcc", "262") ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "service_context_id_mcc", "262")
+...
+        </programlisting>
       </example>
     </section>
     <section>
@@ -454,8 +506,11 @@
       <example>
         <title>
         <varname>service_context_id_release</varname>parameter usage</title>
-        <programlisting format="linespecific">... modparam("ims_charging",
-        "service_context_id_release", "262") ...</programlisting>
+        <programlisting format="linespecific">
+...
+modparam("ims_charging", "service_context_id_release", "262")
+...
+        </programlisting>
       </example>
     </section>
   </section>
@@ -500,15 +555,35 @@
       value.</para>
       <example>
         <title>Ro_CCR</title>
-        <programlisting format="linespecific">... xlog("L_DBG","Sending initial CCR Request for
-        call\n"); Ro_CCR("CHARGING_CCR_REPLY", "orig", "SCUR", "", "30"); }
-        route[CHARGING_CCR_REPLY] { xlog("L_DBG","cca_return code is $avp(s:cca_return_code)\n");
-        switch ($avp(s:cca_return_code)){ case 1: #success xlog("L_DBG", "CCR success - will route
-        message\n"); route(Finalize_Orig); break; case -1: #failure xlog("L_ERR", "CCR failure -
-        error response sent from module\n"); sl_send_reply("402","Payment required"); break; case
-        -2: #error xlog("L_ERR", "CCR error - error response sent from module\n");
-        sl_send_reply("500", "Charging Error"); break; default: xlog("L_ERR", "Unknown return code
-        from CCR: [$avp(s:cca_return_code)] \n"); break; } exit; } ...</programlisting>
+        <programlisting format="linespecific">
+...
+  xlog("L_DBG","Sending initial CCR Request for call\n");
+  Ro_CCR("CHARGING_CCR_REPLY", "orig", "SCUR", "", "30");
+}
+
+route[CHARGING_CCR_REPLY] 
+  xlog("L_DBG","cca_return code is $avp(s:cca_return_code)\n");
+  switch ($avp(s:cca_return_code)) {
+    case 1: #success
+        xlog("L_DBG", "CCR success - will route message\n");
+        route(Finalize_Orig);
+        break;
+    case -1: #failure
+        xlog("L_ERR", "CCR failure - error response sent from module\n");
+        sl_send_reply("402","Payment required");
+        break;
+    case -2: #error
+        xlog("L_ERR", "CCR error - error response sent from module\n");
+        sl_send_reply("500", "Charging Error");
+        break;
+    default:
+        xlog("L_ERR", "Unknown return code from CCR: [$avp(s:cca_return_code)] \n");
+        break;
+  }
+  exit;
+  }
+...
+        </programlisting>
       </example>
     </section>
   </section>
@@ -558,6 +633,10 @@
       <title>CCRs responses time (ccr_responses_time)</title>
       <para>Total CCA arrival time in milliseconds.</para>
     </section>
+    <section>
+      <title>CCRs requests, which ended with a timeout (ccr_timeouts)</title>
+      <para>Number of CCR-Requests, which ran into an timeout.</para>
+    </section>
     <section>
       <title>Billed seconds (billed_secs)</title>
       <para>Number of seconds billed in total.</para>

modules/ims_charging/ims_ro.c

@@ -206,7 +206,7 @@ inline int Ro_add_user_equipment_info(AAAMessage *msg, unsigned int type, str va
     return Ro_add_avp(msg, group.s, group.len, AVP_User_Equipment_Info, AAA_AVP_FLAG_MANDATORY, 0, AVP_FREE_DATA, __FUNCTION__);
 }
 
-inline int Ro_add_termination_casue(AAAMessage *msg, unsigned int term_code) {
+inline int Ro_add_termination_cause(AAAMessage *msg, unsigned int term_code) {
     char x[4];
     str s = {x, 4};
     uint32_t code = htonl(term_code);
@@ -649,6 +649,12 @@ static void resume_on_interim_ccr(int is_timeout, void *param, AAAMessage *cca,
 	struct interim_ccr *i_req	= (struct interim_ccr *) param;
 	Ro_CCA_t * ro_cca_data = NULL;
 
+    if (is_timeout) {
+        update_stat(ccr_timeouts, 1);
+        LM_ERR("Transaction timeout - did not get CCA\n");
+        goto error;
+    }
+
     update_stat(ccr_responses_time, elapsed_msecs);
 
 	if (!i_req) {
@@ -692,8 +698,8 @@ error:
 	if (ro_cca_data)
 		Ro_free_CCA(ro_cca_data);
 
-	if (ro_cca_data)
-		cdpb.AAAFreeMessage(&cca);
+//	if (ro_cca_data)
+	cdpb.AAAFreeMessage(&cca);
 
 	if (i_req) {
 		i_req->credit_valid_for = 0;
@@ -798,7 +804,7 @@ void send_ccr_stop(struct ro_session *ro_session) {
         LM_ERR("Problem adding Multiple Service Credit Control data\n");
     }
     
-    if (!Ro_add_termination_casue(ccr, 4)) {
+    if (!Ro_add_termination_cause(ccr, TERM_CAUSE_LOGOUT)) {
         LM_ERR("problem add Termination cause AVP to STOP record.\n");
     }
 
@@ -827,6 +833,12 @@ error0:
 static void resume_on_termination_ccr(int is_timeout, void *param, AAAMessage *cca, long elapsed_msecs) {
     Ro_CCA_t *ro_cca_data = NULL;
 
+    if (is_timeout) {
+        update_stat(ccr_timeouts, 1);
+        LM_ERR("Transaction timeout - did not get CCA\n");
+        goto error;
+    }
+
     update_stat(ccr_responses_time, elapsed_msecs);
 
     if (!cca) {
@@ -849,15 +861,14 @@ static void resume_on_termination_ccr(int is_timeout, void *param, AAAMessage *c
     	LM_DBG("Valid CCA response for STOP record\n");
     }
 
-    Ro_free_CCA(ro_cca_data);
-    cdpb.AAAFreeMessage(&cca);
+//   Ro_free_CCA(ro_cca_data);
+//   cdpb.AAAFreeMessage(&cca);
 
     update_stat(successful_final_ccrs, 1);
 
-    return;
-
 error:
 	Ro_free_CCA(ro_cca_data);
+    cdpb.AAAFreeMessage(&cca);
 }
 
 
@@ -980,12 +991,12 @@ int Ro_Send_CCR(struct sip_msg *msg, str* direction, str* charge_type, str* unit
     Ro_free_CCR(ro_ccr_data);
 
     //TODO: if the following fail, we should clean up the Ro session.......
-    if (dlgb.register_dlgcb(dlg, DLGCB_RESPONSE_FWDED, dlg_reply, (void*)new_session ,NULL ) != 0) {
+    if (dlgb.register_dlgcb(dlg, /* DLGCB_RESPONSE_FWDED */ DLGCB_CONFIRMED, dlg_reply, (void*)new_session ,NULL ) != 0) {
     	LM_CRIT("cannot register callback for dialog confirmation\n");
     	goto error;
     }
 
-    if (dlgb.register_dlgcb(dlg, DLGCB_TERMINATED | DLGCB_FAILED | DLGCB_EXPIRED | DLGCB_DESTROY
+    if (dlgb.register_dlgcb(dlg, DLGCB_TERMINATED | DLGCB_FAILED | DLGCB_EXPIRED /*| DLGCB_DESTROY */
     		, dlg_terminated, (void*)new_session, NULL ) != 0) {
     	LM_CRIT("cannot register callback for dialog termination\n");
     	goto error;
@@ -1015,6 +1026,13 @@ static void resume_on_initial_ccr(int is_timeout, void *param, AAAMessage *cca,
     struct session_setup_data *ssd = (struct session_setup_data *) param;
     int error_code	= RO_RETURN_ERROR;
 
+    if (is_timeout) {
+        update_stat(ccr_timeouts, 1);
+        LM_ERR("Transaction timeout - did not get CCA\n");
+	error_code =  RO_RETURN_ERROR;
+        goto error0;
+    }
+
     update_stat(ccr_responses_time, elapsed_msecs);
 
     if (!cca) {
@@ -1033,7 +1051,7 @@ static void resume_on_initial_ccr(int is_timeout, void *param, AAAMessage *cca,
 	if (tmb.t_lookup_ident(&t, ssd->tindex, ssd->tlabel) < 0) {
 		LM_ERR("t_continue: transaction not found\n");
 		error_code	= RO_RETURN_ERROR;
-		goto error1;
+		goto error0;
 	}
 
 	// we bring the list of AVPs of the transaction to the current context
@@ -1093,6 +1111,8 @@ error0:
     LM_DBG("Trying to reserve credit on initial INVITE failed on cdp callback\n");
     create_cca_return_code(error_code);
 
+    cdpb.AAAFreeMessage(&cca);
+
     if (t)
     	tmb.unref_cell(t);
 
@@ -1130,6 +1150,8 @@ static int create_cca_return_code(int result) {
     avp_name.s.len = RO_AVP_CCA_RETURN_CODE_LENGTH;
 
     avp_val.n = result;
+    avp_val.s.s = RO_RETURN_TRUE_STR;	//assume true
+    avp_val.s.len = 1;
 
     switch(result) {
     case RO_RETURN_FALSE:

modules/ims_charging/mod.c

@@ -60,6 +60,7 @@ stat_var *successful_final_ccrs;
 stat_var *ccr_responses_time;
 stat_var *billed_secs;
 stat_var *killed_calls;
+stat_var *ccr_timeouts;
 
 /** module functions */
 static int mod_init(void);
@@ -113,6 +114,7 @@ stat_export_t charging_stats[] = {
     {"ccr_responses_time", STAT_NO_RESET, &ccr_responses_time},
     {"billed_secs", STAT_NO_RESET, &billed_secs},
     {"killed_calls", STAT_NO_RESET, &killed_calls},
+    {"ccr_timeouts", STAT_NO_RESET, &ccr_timeouts},
     {0, 0, 0}
 };
 

modules/ims_charging/mod.h

@@ -22,6 +22,7 @@
 #define RO_RETURN_BREAK	0
 /** Return true in the routing script */
 #define RO_RETURN_TRUE	1
+#define RO_RETURN_TRUE_STR "1"
 /** Return false in the routing script */
 #define RO_RETURN_FALSE -1
 #define RO_RETURN_FALSE_STR "-1"
@@ -29,6 +30,18 @@
 #define RO_RETURN_ERROR -2
 #define RO_RETURN_ERROR_STR "-2"
 
+/** Diameter Termination Cause Codes */
+#define TERM_CAUSE_LOGOUT 1
+#define TERM_CAUSE_SERVICE_NOT_PROVIDED 2
+#define TERM_CAUSE_BAD_ANSWER 3
+#define TERM_CAUSE_ADMINISTRATIVE 4
+#define TERM_CAUSE_LINK_BROKEN 5
+#define TERM_CAUSE_AUTH_EXPIRED 6
+#define TERM_CAUSE_USER_MOVED 7
+#define TERM_CAUSE_SESSION_TIMEOUT 8
+
+
+
 #define RO_AVP_CCA_RETURN_CODE "cca_return_code"
 #define RO_AVP_CCA_RETURN_CODE_LENGTH 15
 

modules/ims_charging/ro_timer.c

@@ -118,6 +118,8 @@ int insert_ro_timer(struct ro_tl *tl, int interval) {
     tl->timeout = get_ticks() + interval;
     insert_ro_timer_unsafe(tl);
 
+
+    LM_DBG("TIMER inserted");
     lock_release(roi_timer->lock);
 
     return 0;
@@ -141,7 +143,7 @@ static inline void remove_ro_timer_unsafe(struct ro_tl *tl) {
  */
 int remove_ro_timer(struct ro_tl *tl) {
     lock_get(roi_timer->lock);
-
+	
     if (tl->prev == NULL && tl->timeout == 0) {
         lock_release(roi_timer->lock);
         return 1;
@@ -153,7 +155,7 @@ int remove_ro_timer(struct ro_tl *tl) {
         lock_release(roi_timer->lock);
         return -1;
     }
-
+    LM_DBG("TIMER REMOVED");
     remove_ro_timer_unsafe(tl);
     tl->next = NULL;
     tl->prev = NULL;
@@ -337,8 +339,8 @@ void resume_ro_session_ontimeout(struct interim_ccr *i_req) {
 
 	ro_session_entry = &(ro_session_table->entries[i_req->ro_session->h_entry]);
 
+	unref_ro_session_unsafe(i_req->ro_session, 1, ro_session_entry);//unref from the initial timer that fired this event.
 	ro_session_unlock(ro_session_table, ro_session_entry);
-	unref_ro_session(i_req->ro_session, 1);//unref from the initial timer that fired this event.
 
 	shm_free(i_req);
 	LM_DBG("Exiting async ccr interim nicely");
@@ -363,12 +365,20 @@ void ro_session_ontimeout(struct ro_tl *tl) {
 		LM_ERR("Can't find a session. This is bad");
 		return;
 	}
-	
+
+//	LM_ALERT("LOCKING... ");	
 	ro_session_entry = &(ro_session_table->entries[ro_session->h_entry]);
 	ro_session_lock(ro_session_table, ro_session_entry);
-
+//	LM_ALERT("LOCKED!");
+	
 	LM_DBG("event-type=%d", ro_session->event_type);
-
+	
+//	if (!ro_session->active) {
+//		LM_ALERT("Looks like this session was terminated while requesting more units");
+//		goto exit;
+//		return;
+//	}
+	
 	switch (ro_session->event_type) {
 	case answered:
 		now = time(0);
@@ -435,8 +445,8 @@ void ro_session_ontimeout(struct ro_tl *tl) {
 
 	update_stat(killed_calls, 1);
 
+	unref_ro_session_unsafe(ro_session, 1, ro_session_entry); //unref from the initial timer that fired this event.
 	ro_session_unlock(ro_session_table, ro_session_entry);
-	unref_ro_session(ro_session, 1); //unref from the initial timer that fired this event.
 
 	return;
 }

modules/ims_charging/stats.h

@@ -19,6 +19,7 @@ extern stat_var *successful_final_ccrs;
 extern stat_var *ccr_responses_time;
 extern stat_var *billed_secs;
 extern stat_var *killed_calls;
+extern stat_var *ccr_timeouts;
 
 unsigned long get_failed_initial_ccrs();
 unsigned long get_failed_interim_ccrs();