[OpenSIPS-Users] dr_rules does not load all DB records

Sat May 5 09:11:12 CEST 2012

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 at perseu:/var/log/opensips# opensipsctl fifo get_statistics free_size
> shmem:free_size = 239755320
> root at perseu:/var/log/opensips# opensipsctl fifo get_statistics used_size
> shmem:used_size = 22432196
> root at perseu:/var/log/opensips# opensipsctl fifo get_statistics real_used_size
> shmem:real_used_size = 28680136
> root at perseu:/var/log/opensips# opensipsctl fifo get_statistics max_used_size
> shmem:max_used_size = 44551012
> root at 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
> Users at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>

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

-------------- next part --------------
A non-text attachment was scrubbed...
Name: drouting.patch
Type: text/x-patch
Size: 918 bytes
Desc: not available
URL: <http://lists.opensips.org/pipermail/users/attachments/20120505/c893a8e6/attachment.bin>