Hi Marcio,

The issue is related to incomplete DBG logging - you see, the DR module loads the rules in chunks (and not all in the same time). And the debug you got reports only the size of the first chunk of rules.

Just as an experiment, apply the attached patch - it has extra DBG logs to print the size for all chunks (you will get more "records found in dr_rules" for a single load) and to also print the final counting of rules that were validated and stored in memory.

Regards,
Bogdan



On 05/04/2012 05:52 AM, Marcio Veloso Antunes wrote:
Hi all!

   I am lost here. I think there is a problem on drouting module. I am using 
OpenSIPS 1.7.2 and my OpenSIPS cannot load the entire
dr_rules table but it shows no Error.

   I have 50104 records in dr_rules table:

SELECT count(*) from dr_rules;
  count
-------
  50104

   I have one big group id and 5 smaller ones with just 1 rule each.

   First i thought that memory could be the problem, so i lauched opensips with 
STARTOPTIONS="-u opensips -g opensips -m 256", but the
problem still there.

   I've started opensips with fork=no and debug=7 to trace what was going wrong.

   My memory stats are:
root@perseu:/var/log/opensips# opensipsctl fifo get_statistics free_size
shmem:free_size = 239755320
root@perseu:/var/log/opensips# opensipsctl fifo get_statistics used_size
shmem:used_size = 22432196
root@perseu:/var/log/opensips# opensipsctl fifo get_statistics real_used_size
shmem:real_used_size = 28680136
root@perseu:/var/log/opensips# opensipsctl fifo get_statistics max_used_size
shmem:max_used_size = 44551012
root@perseu:/var/log/opensips# opensipsctl fifo get_statistics fragments
shmem:fragments = 260538


   At debug file i found:
DBG:drouting:dr_load_routing_info: 3278 records found in dr_rules

   So i have made a dr_reload (opensipsctl fifo dr_reload), and i found at 
debug file:
DBG:drouting:dr_load_routing_info: 3275 records found in dr_rules

   So i issued again the dr_reload and now debug file shows:
DBG:drouting:dr_load_routing_info: 3113 records found in dr_rules

   So i dive into the debug file to find that records found message, the lines 
around it is shown below:

May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
allocated 0 bytes for row_buf[3] at 0x82ba2a0
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
[3112][3] Column[timerec]=[]
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
PQgetvalue(0x82284a4,3112,4)=[0]
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
allocated 1 bytes for row_buf[4] at 0x82ba1dc
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
[3112][4] Column[priority]=[0]
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
PQgetvalue(0x82284a4,3112,5)=[], zero len
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
allocated 0 bytes for row_buf[5] at 0x82ba28c
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
[3112][5] Column[routeid]=[]
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
PQgetvalue(0x82284a4,3112,6)=[#2]
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
allocated 2 bytes for row_buf[6] at 0x82ba25c
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
[3112][6] Column[gwlist]=[#2]
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_str2val: 
converting INT [38154]
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_str2val: 
converting STRING [0]
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_str2val: 
converting STRING [55929998]
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_str2val: 
converting STRING []
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_str2val: 
converting INT [0]
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_str2val: 
converting STRING []
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_str2val: 
converting STRING [#2]
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
freeing row_buf[0] at 0x82ba248
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
freeing row_buf[4] at 0x82ba1dc
May  3 23:20:58 perseu opensips: DBG:db_postgres:db_postgres_convert_rows: 
freeing row buffer at 0x822d574
May  3 23:20:58 perseu opensips: DBG:drouting:dr_load_routing_info: 3113 
records found in dr_rules
May  3 23:20:58 perseu opensips: DBG:drouting:add_prefix: adding info 
0xa7e5d1fc, 0 at: 0xa8c2afd4 (7)
May  3 23:20:58 perseu opensips: DBG:drouting:add_prefix: adding info 
0xa7e5d1bc, 0 at: 0xa8c2afe4 (8)
May  3 23:20:58 perseu opensips: DBG:drouting:add_prefix: adding info 
0xa8f8f890, 0 at: 0xa8c2aff4 (9)
May  3 23:20:58 perseu opensips: DBG:drouting:add_prefix: adding info 
0xa7e5cf64, 0 at: 0xa8c29f68 (1)
May  3 23:20:58 perseu opensips: DBG:drouting:add_prefix: adding info 
0xa7e5cf24, 1 at: 0xa8f8f938 (5)
May  3 23:20:58 perseu opensips: DBG:drouting:add_prefix: adding info 
0xa8c2b574, 0 at: 0xa8c29f78 (2)
May  3 23:20:58 perseu opensips: DBG:drouting:add_prefix: adding info 
0xa8c2b2c0, 0 at: 0xa8c29f88 (3)

   I think it is curious if not wrong it stops converting records, inform the numbers of 
rows found and then shows messages "add_prefix".

   Why the other 47000 records were not loaded?

   Please help, it is a production instalation.


   Marcio Veloso Antunes
   Tel.+55.11.3588.0802 Ext.106
   Tel.+55.21.3005.3004 Ext.106
   Cel. +55.21.8539.2949

_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users



--
Bogdan-Andrei Iancu
OpenSIPS Founder and Developer
http://www.opensips-solutions.com

Index: modules/drouting/dr_load.c
===================================================================
--- modules/drouting/dr_load.c	(revision 8896)
+++ modules/drouting/dr_load.c	(working copy)
@@ -527,7 +527,7 @@
 		LM_WARN("table \"%.*s\" is empty\n", drr_table->len, drr_table->s);
 	}
 
-	LM_DBG("%d records found in %.*s\n", RES_ROW_N(res),
+	LM_DBG("initial %d records found in %.*s\n", RES_ROW_N(res),
 		drr_table->len, drr_table->s);
 
 	n = 0;
@@ -614,6 +614,8 @@
 				LM_ERR( "fetching rows (1)\n");
 				goto error;
 			}
+			LM_DBG("additional %d records found in %.*s\n", RES_ROW_N(res),
+				drr_table->len, drr_table->s);
 		} else {
 			break;
 		}
@@ -624,6 +626,8 @@
 
 	free_tmp_gw_list();
 
+	LM_DBG("%d total records loaded from table %.*s\n", n,
+		drr_table->len, drr_table->s);
 	if (n==0) {
 		LM_WARN("no valid routing rules -> discarding all destinations\n");
 		free_rt_data( rdata, 0 );
_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users

Reply via email to