From: Bogdan-Andrei Iancu <bogdan@opensips.org>
Date: Thu, 6 Jul 2017 14:49:05 +0300
Subject: [PATCH] Fix milliseconds (for call duration) consistency across ACC
 backends.

Each backend was evaluating the END time by itself, leading to discrepencies in the reported milliseconds between different backends (when multiple backends were used for CDR reporting).
The fix consists in having a single END time value shared to all ACC backends.

diff --git a/modules/acc/acc.c b/modules/acc/acc.c
index 673f1b795..d06370389 100644
--- a/modules/acc/acc.c
+++ b/modules/acc/acc.c
@@ -264,19 +264,18 @@ void acc_log_init(void)
 	SET_LOG_ATTR(n,CREATED);
 }
 
-int acc_log_cdrs(struct dlg_cell *dlg, struct sip_msg *msg)
+int acc_log_cdrs(struct dlg_cell *dlg, struct sip_msg *msg,
+														struct timeval *end)
 {
 	static char log_msg[MAX_SYSLOG_SIZE];
 	static char *log_msg_end=log_msg+MAX_SYSLOG_SIZE-2;
 	char *p;
 	int nr_vals, i, j, ret, res = -1, n;
 	time_t created;
-	struct timeval start_time,end;
+	struct timeval start_time;
 	str core_s, leg_s, extra_s;
 	short nr_legs;
 
-	gettimeofday(&end,NULL);
-
 	core_s.s = extra_s.s = leg_s.s = 0;
 
 	ret = prebuild_core_arr(dlg, &core_s, &start_time);
@@ -368,8 +367,8 @@ int acc_log_cdrs(struct dlg_cell *dlg, struct sip_msg *msg)
 		"%.*screated=%lu;call_start_time=%lu;duration=%lu;ms_duration=%lu;setuptime=%lu%s",
 		acc_env.text.len, acc_env.text.s,(unsigned long)created,
 		(unsigned long)start_time.tv_sec,
-		(unsigned long)(end.tv_sec-start_time.tv_sec),
-		(unsigned long)((end.tv_sec-start_time.tv_sec)*1000+(end.tv_usec-start_time.tv_usec)%1000),
+		(unsigned long)(end->tv_sec-start_time.tv_sec),
+		(unsigned long)((end->tv_sec-start_time.tv_sec)*1000+(end->tv_usec-start_time.tv_usec)%1000),
 		(unsigned long)(start_time.tv_sec - created), log_msg);
 
 	res = 1;
@@ -668,12 +667,13 @@ int acc_db_request( struct sip_msg *rq, struct sip_msg *rpl,
 	return 1;
 }
 
-int acc_db_cdrs(struct dlg_cell *dlg, struct sip_msg *msg)
+int acc_db_cdrs(struct dlg_cell *dlg, struct sip_msg *msg,
+														struct timeval *end)
 {
 	int total, nr_vals, i, ret, res = -1, nr_bye_vals = 0, j;
 	int remaining_bye_vals = 0;
 	time_t created;
-	struct timeval start_time,end;
+	struct timeval start_time;
 	str core_s, leg_s, extra_s, table;
 	short nr_legs;
 	static db_ps_t my_ps = NULL;
@@ -685,7 +685,6 @@ int acc_db_cdrs(struct dlg_cell *dlg, struct sip_msg *msg)
 	}
 
 	core_s.s = extra_s.s = leg_s.s = 0;
-	gettimeofday(&end,NULL);
 
 	ret = prebuild_core_arr(dlg, &core_s, &start_time);
 	if (ret < 0) {
@@ -729,9 +728,9 @@ int acc_db_cdrs(struct dlg_cell *dlg, struct sip_msg *msg)
 	VAL_TIME(db_vals_cdrs+ACC_CORE_LEN) = start_time.tv_sec;
 	VAL_INT(db_vals_cdrs+ret+nr_vals+nr_bye_vals+1) = start_time.tv_sec - created;
 	VAL_TIME(db_vals_cdrs+ret+nr_vals+nr_bye_vals+2) = created;
-	VAL_INT(db_vals_cdrs+ret+nr_vals+nr_bye_vals+3) = end.tv_sec - start_time.tv_sec;
+	VAL_INT(db_vals_cdrs+ret+nr_vals+nr_bye_vals+3) = end->tv_sec - start_time.tv_sec;
 	VAL_INT(db_vals_cdrs+ret+nr_vals+nr_bye_vals+4) =
-		(end.tv_sec-start_time.tv_sec)*1000+(end.tv_usec-start_time.tv_usec)%1000;
+		(end->tv_sec-start_time.tv_sec)*1000+(end->tv_usec-start_time.tv_usec)%1000;
 
 	total = ret + 5;
 	acc_dbf.use_table(db_handle, &table);
@@ -982,18 +981,18 @@ error:
 	return -1;
 }
 
-int acc_aaa_cdrs(struct dlg_cell *dlg, struct sip_msg *msg)
+int acc_aaa_cdrs(struct dlg_cell *dlg, struct sip_msg *msg,
+														struct timeval *end)
 {
 	int nr_vals, i, j, ret, res = -1;
 	time_t created;
-	struct timeval start_time,end;
+	struct timeval start_time;
 	str core_s, leg_s, extra_s;
 	short nr_legs;
 	aaa_message *send = NULL;
 	int offset, av_type;
 	aaa_map *r_stat;
 
-	gettimeofday(&end,NULL);
 	core_s.s = extra_s.s = leg_s.s = 0;
 
 	ret = prebuild_core_arr(dlg, &core_s, &start_time);
@@ -1053,9 +1052,9 @@ int acc_aaa_cdrs(struct dlg_cell *dlg, struct sip_msg *msg)
 	offset = ret + 2;
 
 	/* add duration and setup values */
-	av_type = (uint32_t)(end.tv_sec - start_time.tv_sec);
+	av_type = (uint32_t)(end->tv_sec - start_time.tv_sec);
 	ADD_AAA_AVPAIR( offset + nr_vals, &av_type, -1);
-	av_type = (uint32_t)((end.tv_sec-start_time.tv_sec)*1000+(end.tv_usec-start_time.tv_usec)%1000);
+	av_type = (uint32_t)((end->tv_sec-start_time.tv_sec)*1000+(end->tv_usec-start_time.tv_usec)%1000);
 	ADD_AAA_AVPAIR( offset + nr_vals + 1, &av_type, -1);
 	av_type = (uint32_t)(start_time.tv_sec - created);
 	ADD_AAA_AVPAIR( offset + nr_vals + 2, &av_type, -1);
@@ -1529,12 +1528,13 @@ end:
 	return ret;
 }
 
-int acc_evi_cdrs(struct dlg_cell *dlg, struct sip_msg *msg)
+int acc_evi_cdrs(struct dlg_cell *dlg, struct sip_msg *msg,
+														struct timeval *end)
 {
 	int nr_vals, i, ret, res = -1, nr_bye_vals = 0, j;
 	int aux_time;
 	time_t created;
-	struct timeval start_time,end;
+	struct timeval start_time;
 	str core_s, leg_s, extra_s;
 	short nr_legs;
 
@@ -1547,7 +1547,6 @@ int acc_evi_cdrs(struct dlg_cell *dlg, struct sip_msg *msg)
 	if (!evi_probe_event(acc_cdr_event))
 		return 1;
 
-	gettimeofday(&end,NULL);
 	core_s.s = extra_s.s = leg_s.s = 0;
 
 	ret = prebuild_core_arr(dlg, &core_s, &start_time);
@@ -1597,12 +1596,13 @@ int acc_evi_cdrs(struct dlg_cell *dlg, struct sip_msg *msg)
 		LM_ERR("cannot set start_time parameter\n");
 		goto end;
 	}
-	aux_time = end.tv_sec - start_time.tv_sec;
+	aux_time = end->tv_sec - start_time.tv_sec;
 	if (evi_param_set_int(evi_params[ret+nr_vals+nr_bye_vals+1], &aux_time) < 0) {
 		LM_ERR("cannot set duration parameter\n");
 		goto end;
 	}
-	aux_time = (end.tv_sec-start_time.tv_sec)*1000+(end.tv_usec-start_time.tv_usec)%1000;
+	aux_time = (end->tv_sec-start_time.tv_sec)*1000
+		+ (end->tv_usec-start_time.tv_usec)%1000;
 	if (evi_param_set_int(evi_params[ret+nr_vals+nr_bye_vals+2], &aux_time) < 0) {
 		LM_ERR("cannot set duration parameter\n");
 		goto end;
diff --git a/modules/acc/acc.h b/modules/acc/acc.h
index 878fc77f3..2be0fabd1 100644
--- a/modules/acc/acc.h
+++ b/modules/acc/acc.h
@@ -81,7 +81,8 @@ extern struct dlg_binds dlg_api;
 
 void acc_log_init();
 int  acc_log_request( struct sip_msg *req, struct sip_msg *rpl, int cdr_flag);
-int  acc_log_cdrs(struct dlg_cell *dlg, struct sip_msg *msg);
+int  acc_log_cdrs(struct dlg_cell *dlg, struct sip_msg *msg,
+		struct timeval *end);
 int  store_log_extra_values(struct dlg_cell *dlg, struct sip_msg *req,
 		struct sip_msg *reply);
 
@@ -90,14 +91,16 @@ int  acc_db_init_child(const str* db_url);
 void acc_db_close();
 int  acc_db_request( struct sip_msg *req, struct sip_msg *rpl,
 		query_list_t **ins_list, int cdr_flag);
-int  acc_db_cdrs(struct dlg_cell *dlg, struct sip_msg *msg);
+int  acc_db_cdrs(struct dlg_cell *dlg, struct sip_msg *msg,
+		struct timeval *end);
 int  store_db_extra_values(struct dlg_cell *dlg, struct sip_msg *req,
 		struct sip_msg *reply);
 
 int  init_acc_aaa(char* aaa_proto_url, int srv_type);
 int  acc_aaa_request( struct sip_msg *req, struct sip_msg *rpl, int cdr_flag);
 int  acc_aaa_cdrs_request(struct dlg_cell *dlg);
-int  acc_aaa_cdrs(struct dlg_cell *dlg, struct sip_msg *msg);
+int  acc_aaa_cdrs(struct dlg_cell *dlg, struct sip_msg *msg,
+		struct timeval *end);
 int  store_aaa_extra_values(struct dlg_cell *dlg, struct sip_msg *req,
 		struct sip_msg *reply);
 
@@ -107,7 +110,8 @@ int  create_acc_dlg(struct sip_msg* req);
 
 int  init_acc_evi(void);
 int  acc_evi_request( struct sip_msg *req, struct sip_msg *rpl, int cdr_flag);
-int  acc_evi_cdrs(struct dlg_cell *dlg, struct sip_msg *msg);
+int  acc_evi_cdrs(struct dlg_cell *dlg, struct sip_msg *msg,
+		struct timeval *end);
 int  store_evi_extra_values(struct dlg_cell *dlg, struct sip_msg *req,
 		struct sip_msg *reply);
 extern event_id_t acc_cdr_event;
diff --git a/modules/acc/acc_logic.c b/modules/acc/acc_logic.c
index a92acdf74..6d21f676f 100644
--- a/modules/acc/acc_logic.c
+++ b/modules/acc/acc_logic.c
@@ -739,6 +739,7 @@ static void acc_dlg_callback(struct dlg_cell *dlg, int type,
 		struct dlg_cb_params *_params)
 {
 	unsigned long long flags;
+	struct timeval end;
 
 	if (!_params) {
 		LM_ERR("not enough info\n");
@@ -764,9 +765,11 @@ static void acc_dlg_callback(struct dlg_cell *dlg, int type,
 	 */
 	set_dlg_cb_used(*((unsigned long long*)*_params->param));
 
+	gettimeofday(&end,NULL);
+
 	if (is_evi_acc_on(flags)) {
 		env_set_event(acc_cdr_event);
-		if (acc_evi_cdrs(dlg, _params->msg) < 0) {
+		if (acc_evi_cdrs(dlg, _params->msg, &end) < 0) {
 			LM_ERR("cannot send accounting events\n");
 			return;
 		}
@@ -774,7 +777,7 @@ static void acc_dlg_callback(struct dlg_cell *dlg, int type,
 
 	if (is_log_acc_on(flags)) {
 		env_set_text( ACC_ENDED, ACC_ENDED_LEN);
-		if (acc_log_cdrs(dlg, _params->msg) < 0) {
+		if (acc_log_cdrs(dlg, _params->msg, &end) < 0) {
 			LM_ERR("Cannot log values\n");
 			return;
 		}
@@ -782,13 +785,13 @@ static void acc_dlg_callback(struct dlg_cell *dlg, int type,
 
 	if (is_db_acc_on(flags)) {
 		env_set_text( db_table_acc.s, db_table_acc.len);
-		if (acc_db_cdrs(dlg, _params->msg) < 0) {
+		if (acc_db_cdrs(dlg, _params->msg, &end) < 0) {
 			LM_ERR("Cannot insert into database\n");
 			return;
 		}
 	}
 
-	if (is_aaa_acc_on(flags) && acc_aaa_cdrs(dlg, _params->msg) < 0) {
+	if (is_aaa_acc_on(flags) && acc_aaa_cdrs(dlg, _params->msg, &end) < 0) {
 		LM_ERR("Cannot create radius accounting\n");
 		return;
 	}