[OpenSIPS-Devel] [ opensips-Bugs-3607052 ] Load balancer - corrupt data when loading table

Fri Apr 5 23:04:17 CEST 2013

Bugs item #3607052, was opened at 2013-03-06 07:08
Message generated for change (Comment added) made by umautone
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=3607052&group_id=232389

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: modules
Group: 1.9.x
Status: Open
Resolution: None
Priority: 5
Private: No
Submitted By: Umberto Mautone (umautone)
Assigned to: Bogdan-Andrei Iancu (bogdan_iancu)
Summary: Load balancer - corrupt data when loading table

Initial Comment:

Tested on 1.9.x

Data table:

 id | group_id |      dst_uri      | resources | probe_mode 
----+----------+-------------------+-----------+------------
 19 |        1 | sip:192.168.1.5   | pstn=100  |          0
 20 |        1 | sip:192.168.1.8   | pstn=100  |          0
 21 |        2 | sip:192.168.1.100 | pstn=2500 |          0

I added this line in "lb_db_load_data()"  to log the actual table fields being loaded:

LM_ERR("Fields: %d %d %s %s\n", id, group, uri, resource);

The first row loads correctly but subsequent rows seem to lose a pointer alignment somewhere:

Mar  6 10:01:53 localhost opensips[1796]: ERROR:load_balancer:lb_db_load_data: Fields: 19 1 sip:192.168.1.5 pstn=100
Mar  6 10:01:53 localhost opensips[1796]: ERROR:load_balancer:lb_db_load_data: Fields: 20 1 sip:192.168.1.8  ¥Ý9w#177
Mar  6 10:01:53 localhost opensips[1796]: ERROR:load_balancer:parse_resources_list: resource must has value!
Mar  6 10:01:53 localhost opensips[1796]: ERROR:load_balancer:add_lb_dsturi: failed to parse resourse string < ¥Ý9w#177>
Mar  6 10:01:53 localhost opensips[1796]: ERROR:load_balancer:lb_db_load_data: failed to add destination 1 -> skipping
Mar  6 10:01:53 localhost opensips[1796]: ERROR:load_balancer:lb_db_load_data: Fields: 21 2 sip:192.168.1.100 192.168.1.5
Mar  6 10:01:53 localhost opensips[1796]: ERROR:load_balancer:parse_resources_list: resource must has value!
Mar  6 10:01:53 localhost opensips[1796]: ERROR:load_balancer:add_lb_dsturi: failed to parse resourse string <192.168.1.5>
Mar  6 10:01:53 localhost opensips[1796]: ERROR:load_balancer:lb_db_load_data: failed to add destination 1 -> skipping

Also tested in 1.8.2 and the problem is not present. The bug seems to be only in the 1.9.x branch.

----------------------------------------------------------------------

>Comment By: Umberto Mautone (umautone)
Date: 2013-04-05 14:04

Message:

Sorry for taking so long. This is using PostgreSQL 9.2 with unixODBC on a
64 bit box. Here is the output with debug=4 on startup:

===================================
Apr  5 16:57:24 localhost opensips: WARNING:core:warn: warning in config
file /usr//etc/opensips/opensips.cfg, line 44, column 13-16: tls support
not compiled in
Apr  5 16:57:24 localhost opensips: INFO:core:init_tcp: using epoll_lt as
the TCP io watch method (auto detected)
Apr  5 16:57:24 localhost opensips[13284]: NOTICE:core:main: version:
opensips 1.9.0-notls (x86_64/linux)
Apr  5 16:57:24 localhost opensips[13284]: INFO:core:main: using 32 Mb
shared memory
Apr  5 16:57:24 localhost opensips[13284]: INFO:core:main: using 2 Mb
private memory per process
Apr  5 16:57:24 localhost opensips[13284]: INFO:core:evi_publish_event:
Registered event <E_CORE_THRESHOLD(0)>
Apr  5 16:57:24 localhost opensips[13284]: INFO:core:evi_publish_event:
Registered event <E_CORE_SHM_THRESHOLD(1)>
Apr  5 16:57:24 localhost opensips[13284]: INFO:core:evi_publish_event:
Registered event <E_CORE_PKG_THRESHOLD(2)>
Apr  5 16:57:24 localhost opensips[13284]: NOTICE:signaling:mod_init:
initializing module ...
Apr  5 16:57:24 localhost opensips[13284]: INFO:sl:mod_init: Initializing
StateLess engine
Apr  5 16:57:24 localhost opensips[13284]: INFO:tm:mod_init: TM -
initializing...
Apr  5 16:57:24 localhost opensips[13284]: INFO:rr:mod_init: rr -
initializing
Apr  5 16:57:24 localhost opensips[13284]: INFO:maxfwd:mod_init:
initializing...
Apr  5 16:57:24 localhost opensips[13284]: INFO:sipmsgops:mod_init:
initializing...
Apr  5 16:57:24 localhost opensips[13284]: INFO:dialog:mod_init: Dialog
module - initializing
Apr  5 16:57:24 localhost opensips[13284]: INFO:load_balancer:mod_init:
Load-Balancer module - initializing
Apr  5 16:57:24 localhost opensips[13284]:
ERROR:load_balancer:parse_resources_list: resource must has value!
Apr  5 16:57:24 localhost opensips[13284]:
ERROR:load_balancer:add_lb_dsturi: failed to parse resourse string
<HÿóÇ*#177>
Apr  5 16:57:24 localhost opensips[13284]:
ERROR:load_balancer:lb_db_load_data: failed to add destination 3 ->
skipping
Apr  5 16:57:24 localhost opensips[13284]: ERROR:core:parse_uri: bad uri, 
state 0 parsed: <72.0> (4) / <1.2.3.179> (12)
Apr  5 16:57:24 localhost opensips[13284]:
ERROR:load_balancer:add_lb_dsturi: bad uri [1.2.3.179] for destination
Apr  5 16:57:24 localhost opensips[13284]:
ERROR:load_balancer:lb_db_load_data: failed to add destination 3 ->
skipping
Apr  5 16:57:24 localhost opensips[13284]: INFO:sipmsgops:hname_fixup:
using hdr type name <X-Auth-IP>
Apr  5 16:57:24 localhost opensips[13284]: INFO:sipmsgops:hname_fixup:
using hdr type (9) instead of <Route>
Apr  5 16:57:24 localhost rsyslogd-2177: imuxsock begins to drop messages
from pid 13284 due to rate-limiting
Apr  5 16:57:24 localhost opensips: INFO:core:daemonize: pre-daemon process
exiting with 0
===================================

And here is the output when I issue an "lb_reload":

===================================
Apr  5 16:57:39 localhost opensips[13285]: INFO:load_balancer:mi_lb_reload:
"lb_reload" MI command received!
Apr  5 16:57:39 localhost opensips[13285]:
ERROR:load_balancer:parse_resources_list: resource must has value!
Apr  5 16:57:39 localhost opensips[13285]:
ERROR:load_balancer:add_lb_dsturi: failed to parse resourse string <
ôóÇ*#177>
Apr  5 16:57:39 localhost opensips[13285]:
ERROR:load_balancer:lb_db_load_data: failed to add destination 3 ->
skipping
Apr  5 16:57:39 localhost opensips[13285]: ERROR:core:parse_uri: bad uri, 
state 0 parsed: <72.0> (4) / <1.2.3.179> (12)
Apr  5 16:57:39 localhost opensips[13285]:
ERROR:load_balancer:add_lb_dsturi: bad uri [1.2.3.179] for destination
Apr  5 16:57:39 localhost opensips[13285]:
ERROR:load_balancer:lb_db_load_data: failed to add destination 3 ->
skipping

----------------------------------------------------------------------

Comment By: Umberto Mautone (umautone)
Date: 2013-03-07 14:34

Message:
I have both 1.8.2 and 1.9.0 running on the same box. If I start up 1.8.2,
it only loads the first record and I have to call "opensipsctl fifo
lb_reload" to force all profiles to be loaded and they load correctly.

When I start 1.9.0, it tries to load all profiles but some get mangled with
garbage. Even issuing a reload will load the exact same records mangled at
the exact same place.

I'm using db_unixodbc  connected to PostgreSQL. 

I'll try the same load with debug level set to 4 and paste the result.

----------------------------------------------------------------------

Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2013-03-07 08:04

Message:
Hi Umberto,

The code for loading LB data did not change from 1.8 to 1.9....so it is a
bit odd.  I was not able to reproduce it :(.

What DB engine are you using ? Also, could you try running in full debug
(set debug=4).

Thanks and regards,
Bogdan

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=3607052&group_id=232389