[OpenSIPS-Users] Problem Scripting Load Balancer to Dotted Decimal IP addresses

John S. Robinson js.robinson at comcast.net
Thu Aug 6 05:01:24 CEST 2009


Hello, all -- I am a nOOb having difficulty debugging a load
balancing implementation.  I must route only to dotted decimal
IP address, because my gateways are not available in DNS.

Any help would be appreciated.  I am running opensips-1.5.1-notls
on Linux kernel 2.6.18-128.2.1.el5 / CentOS release 5.3 (Final)

Many thanks,

JS Robinson
"communichanic"


My load_balancer table is:

+----+----------+--------------------+------------+-------------+
| id | group_id | dst_uri            | resources  | description |
+----+----------+--------------------+------------+-------------+
|  1 |        1 | sip:126.137.16.148 | mcu1=322   | Router 8    |
|  3 |        1 | 126.137.16.145     | mcu2=644   | Router 5    |
|  4 |        1 | 126.137.16.153     | mcu2=437   | Router 13   |
|  6 |        1 | sip:97.65.187.10   | mcu3 = 322 | Router 104  |
+----+----------+--------------------+------------+-------------+

If I change my dst_uri to sip:126.137.16.145, I get a slightly
different result from what is shown below.  It tries to do a
DNS lookup, which (predictably) fails.

 From examining the logs, I am fairly confident that the table is
populated correctly.

Here is a code snippett which handles an incoming call, with log
results shown below
#
    xlog("L_ERR","  JSR: Checking Laundry list...");
    xlog("L_ERR"," Starting LB code with selected DU  $du\n");
    if ($ru=~"^sip:5506") {
        xlog("L_ERR","  JSR: Call for 5506. \n");
        if (!load_balance("1","mcu2")) {
            sl_send_reply("503","Service full mcu2");
            xlog("L_ERR", "Error!  LB service full on MCU 2. \n");
            xlog("L_ERR","       Bail out.\n");
            exit;
        } else {
            xlog("L_ERR","       LB selected $du for MCU 2.  \n");
            if (!t_relay()) {
                sl_reply_error();
            xlog("L_ERR","       Back from t_relay \n");
            }
        }
    }
#

       Checking Laundry list...
   16:47:50 [4778] DBG:core:pv_get_dsturi: no destination URI
 Starting LB code with selected DU  <null>
  JSR: Call for 5506.
   16:47:50 [4778] DBG:load_balancer:do_load_balance: found requested 
(0) resource mcu2
   16:47:50 [4778] DBG:dialog:build_new_dlg: new dialog 0xb60f6160 
(c=call-71E1E3D0-0864-2C10-1116-30 at 74.93.75.194,f=sip:17982468207 at 174.39.15.93,t=sip:550617985431259 at 174.39.15.93,ft=4a5d4bc2-2b) 
on hash 118
   16:47:50 [4778] DBG:core:parse_headers: flags=400
   16:47:50 [4778] DBG:dialog:populate_leg_info: route_set , contact 
sip:17982468207 at 74.93.75.194:5070, cseq 1 and bind_addr 
udp:174.39.15.93:5060
   16:47:50 [4778] DBG:dialog:dlg_set_leg_info: set leg 0 for 
0xb60f6160: tag=<4a5d4bc2-2b> rr=<> 
ct=<sip:17982468207 at 74.93.75.194:5070> cseq=<1>
   16:47:50 [4778] DBG:dialog:link_dlg: ref dlg 0xb60f6160 with 3 -> 3
   16:47:50 [4778] DBG:rr:add_rr_param: adding (;did=67.99ee0b9) 0x81a5290
   16:47:50 [4778] DBG:load_balancer:do_load_balance: destination 
<126.137.16.145> selected for LB set with free=644 (max=644)
   16:47:50 [4778] DBG:load_balancer:do_load_balance: destination 
<126.137.16.153> selected for LB set with free=437 (max=644)
       LB selected 126.137.16.145 for MCU 2.
   16:47:50 [4778] DBG:tm:t_newtran: transaction on entrance=(nil)
   16:47:50 [4778] DBG:core:parse_headers: flags=ffffffffffffffff
   16:47:50 [4778] DBG:core:parse_headers: flags=78
   16:47:50 [4778] DBG:tm:t_lookup_request: start searching: hash=22525, 
isACK=0
   16:47:50 [4778] DBG:tm:matching_3261: RFC3261 transaction matching failed
   16:47:50 [4778] DBG:tm:t_lookup_request: no transaction found
   16:47:50 [4778] DBG:tm:run_reqin_callbacks: trans=0xb60f6318, 
callback type 1, id 1 entered
   16:47:50 [4778] DBG:tm:run_reqin_callbacks: trans=0xb60f6318, 
callback type 1, id 0 entered
   16:47:50 [4778] DBG:dialog:get_dlg_timeout: invalid AVP value, use 
default timeout
   16:47:50 [4778] DBG:core:parse_headers: flags=ffffffffffffffff
   16:47:50 [4778] DBG:core:check_via_address: params 74.93.75.194, 
74.93.75.194, 0
   16:47:50 [4778] DBG:core:_shm_resize: resize(0) called
   16:47:50 [4778] DBG:tm:_reply_light: reply sent out. buf=0x81b6d50: 
SIP/2.0 1..., shmem=0xb60f7f70: SIP/2.0 1
   16:47:50 [4778] DBG:tm:_reply_light: finished


####
#### Things seem to go wrong here. ... and the
####    xlog("L_ERR","       Back from t_relay \n");
#### never gets executed.
####


   16:47:50 [4778] ERROR:core:parse_uri: bad uri,  state 0 parsed: 
<206.> (4) / <126.137.16.145> (12)
   16:47:50 [4778] ERROR:tm:uri2proxy: bad_uri: 126.137.16.145
   16:47:50 [4778] ERROR:tm:t_forward_nonack: failure to add branches
   16:47:50 [4778] DBG:tm:t_relay_to: t_forward_nonack returned error
   16:47:50 [4778] DBG:core:parse_headers: flags=ffffffffffffffff
   16:47:50 [4778] DBG:core:check_via_address: params 74.93.75.194, 
74.93.75.194, 0
   16:47:50 [4778] DBG:tm:run_trans_callbacks: trans=0xb60f6318, 
callback type 128, id 0 entered
   16:47:50 [4778] DBG:dialog:next_state_dlg: dialog 0xb60f6160 changed 
from state 1 to state 5, due event 4
   16:47:50 [4778] DBG:dialog:dlg_onreply: dialog 0xb60f6160 failed 
(negative reply)
   16:47:50 [4778] DBG:dialog:unref_dlg: unref dlg 0xb60f6160 with 1 -> 2
   16:47:50 [4778] DBG:tm:cleanup_uac_timers: RETR/FR timers reset
   16:47:50 [4778] DBG:tm:set_timer: relative timeout is 500000
   16:47:50 [4778] DBG:tm:insert_timer_unsafe: [4]: 0xb60f63e0 (19400000)
   16:47:50 [4778] DBG:tm:set_timer: relative timeout is 30
   16:47:50 [4778] DBG:tm:insert_timer_unsafe: [0]: 0xb60f63fc (48)
   16:47:50 [4778] DBG:tm:_reply_light: reply sent out. buf=0x81b6ea8: 
SIP/2.0 4..., shmem=0xb60f7f70: SIP/2.0 4
   16:47:50 [4778] DBG:tm:_reply_light: finished
   16:47:50 [4778] DBG:tm:t_relay_to: generation of a stateful reply on 
error succeeded
   16:47:50 [4778] DBG:dialog:unref_dlg: unref dlg 0xb60f6160 with 1 -> 1
   16:47:50 [4778] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
   16:47:50 [4778] DBG:core:destroy_avp_list: destroying list (nil)
   16:47:50 [4778] DBG:core:receive_msg: cleaning up
   16:47:51 [4782] DBG:tm:utimer_routine: timer routine:4,tl=0xb60f63e0 
next=(nil), timeout=19400000
   16:47:51 [4782] DBG:tm:retransmission_handler: retransmission_handler 
: reply resending (t=0xb60f6318, SIP/2.0 4 ... )
   16:47:51 [4782] DBG:tm:t_retransmit_reply: buf=0x15b860: SIP/2.0 
4..., shmem=0xb60f7f70: SIP/2.0 4
   16:47:51 [4782] DBG:tm:set_timer: relative timeout is 1000000
   16:47:51 [4782] DBG:tm:insert_timer_unsafe: [5]: 0xb60f63e0 (20400000)
   16:47:51 [4782] DBG:tm:retransmission_handler: retransmission_handler 
: done
   16:47:52 [4782] DBG:tm:utimer_routine: timer routine:5,tl=0xb60f63e0 
next=(nil), timeout=20400000
   16:47:52 [4782] DBG:tm:retransmission_handler: retransmission_handler 
: reply resending (t=0xb60f6318, SIP/2.0 4 ... )
   16:47:52 [4782] DBG:tm:t_retransmit_reply: buf=0x15b860: SIP/2.0 
4..., shmem=0xb60f7f70: SIP/2.0 4
   16:47:52 [4782] DBG:tm:set_timer: relative timeout is 2000000
   16:47:52 [4782] DBG:tm:insert_timer_unsafe: [6]: 0xb60f63e0 (22400000)
   16:47:52 [4782] DBG:tm:retransmission_handler: retransmission_handler 
: done
   16:47:54 [4782] DBG:tm:utimer_routine: timer routine:6,tl=0xb60f63e0 
next=(nil), timeout=22400000
   16:47:54 [4782] DBG:tm:retransmission_handler: retransmission_handler 
: reply resending (t=0xb60f6318, SIP/2.0 4 ... )
   16:47:54 [4782] DBG:tm:t_retransmit_reply: buf=0x15b860: SIP/2.0 
4..., shmem=0xb60f7f70: SIP/2.0 4
   16:47:54 [4782] DBG:tm:set_timer: relative timeout is 4000000
   16:47:54 [4782] DBG:tm:insert_timer_unsafe: [7]: 0xb60f63e0 (26400000)
   16:47:54 [4782] DBG:tm:retransmission_handler: retransmission_handler 
: done
   16:47:58 [4782] DBG:tm:utimer_routine: timer routine:7,tl=0xb60f63e0 
next=(nil), timeout=26400000
   16:47:58 [4782] DBG:tm:retransmission_handler: retransmission_handler 
: reply resending (t=0xb60f6318, SIP/2.0 4 ... )
   16:47:58 [4782] DBG:tm:t_retransmit_reply: buf=0x15b860: SIP/2.0 
4..., shmem=0xb60f7f70: SIP/2.0 4
   16:47:58 [4782] DBG:tm:set_timer: relative timeout is 4000000
   16:47:58 [4782] DBG:tm:insert_timer_unsafe: [7]: 0xb60f63e0 (30400000)
   16:47:58 [4782] DBG:tm:retransmission_handler: retransmission_handler 
: done




More information about the Users mailing list