Problem Scripting Load Balancer to Dotted Decimal IP addresses

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|

Problem Scripting Load Balancer to Dotted Decimal IP addresses

John S. Robinson
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@74.93.75.194,f=sip:17982468207@174.39.15.93,t=sip:550617985431259@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@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@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


_______________________________________________
Users mailing list
[hidden email]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
Reply | Threaded
Open this post in threaded view
|

Re: Problem Scripting Load Balancer to Dotted Decimal IP addresses

Bogdan-Andrei Iancu
Hi John,

In the dst_uri field you must have a valid SIP URI ; entries 3 and 4 are
not as they miss the "sip:" prefix. This is why you get the parsing
error when opensips is trying to forward to the them.

Regards,
Bogdan

John S. Robinson wrote:

> 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@74.93.75.194,f=sip:17982468207@174.39.15.93,t=sip:550617985431259@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@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@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
>
>
> _______________________________________________
> Users mailing list
> [hidden email]
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>
>  


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