[OpenSIPS-Devel] topology hiding not accepting BYE after 180 ringing

Vlad Paiu vladpaiu at opensips.org
Mon Aug 3 16:41:34 CEST 2015


Hello,

Please update your OpenSIPS sources. There was a recent bug fix which 
addresses this issue - see 
https://github.com/OpenSIPS/opensips/commit/d171b7aaa47a23481a1e374ca58305d1898511a6

Best Regards,

Vlad Paiu
OpenSIPS Developer
http://www.opensips-solutions.com

On 03.08.2015 16:52, Trevor Steyn wrote:
> Anyone have any ideas?
>
> On 28/07/2015 11:01, Trevor Steyn wrote:
>> Hi Guys,
>>
>> I seem to be having some trouble with the new topology_hiding module in
>> opensips 2.1
>>
>>   
>> here is the call scenario
>>
>> UAC --> Opensips --> UAS
>>
>> UAC Sends Invite to UAS with topology hiding module
>> UAS sends 180 with to-tag
>> UAC sends BYE
>>
>> When the Bye is sent opensips loops the call till max forwards is reached
>>
>> from what i can see from the debugs the  Bye from UAC is accepted and
>> matches the topology_hiding_match function but does not rewrite the
>> destination IP so when the message passes t_relay() its sending the Bye
>> to Itself from Itself.
>>
>> I have tried this without topology hiding and the BYE is relayed as it
>> should
>> .
>>
>> My route looks as follows
>>
>>
>> route{
>>      script_trace( 3, "$rm from $si, ruri=$ru", "me");
>>
>>      if (!mf_process_maxfwd_header("10")) {
>>          sl_send_reply("483","Too Many Hops");
>>          exit;
>>      }
>>
>>      if ( check_source_address("1","$avp(trunk_attrs)") ) {
>>          # request comes from trunks
>>          setflag(IS_TRUNK);
>>      } else if ( is_from_gw() ) {
>>          # request comes from GWs
>>      } else {
>> #        send_reply("403","Forbidden");
>>      xlog("Message is not from Trunk or GW $si");
>> #        exit;
>>      }
>>
>>      if (has_totag()) {
>>          # sequential request withing a dialog should
>>          # take the path determined by record-routing
>>          #if (loose_route()) {
>>          if(topology_hiding_match()) {
>>             
>>              # validate the sequential request against dialog
>>              if ( $DLG_status!=NULL && !validate_dialog() ) {
>>                  xlog("In-Dialog $rm from $si (callid=$ci) is not valid
>> according to dialog\n");
>>                  ## exit;
>>              }
>>             
>>              if (is_method("BYE")) {
>>                  setflag(ACC_DO); # do accounting ...
>>                  setflag(ACC_FAILED); # ... even if the transaction fails
>>              } else if (is_method("INVITE")) {
>>                  # even if in most of the cases is useless, do RR for
>>                  # re-INVITEs alos, as some buggy clients do change route set
>>                  # during the dialog.
>>                  record_route();
>>              }
>>
>>              # lets handle re-invites and offer proxy
>>              if (has_body("application/sdp"))  {
>>                  # Begin rtp session update gyrations
>>                  if (method == "INVITE") {
>>                      # INVITE w/ SDP, so early neg
>>                      # This is offer, reply is answer
>>                      rtpproxy_offer("iewlz20");
>>                      t_on_reply("1");
>>                  } else if (method == "ACK") {
>>                      # ACK w/ SDP, so late neg (done now)
>>                      # This is answer
>>                      rtpproxy_answer("iewlz20");
>>                  }
>>          }
>>
>> .............
>>
>>      if (is_method("INVITE")) {
>>          force_send_socket(udp:XXX.XXX.XXX.XXX:5060);
>>          #rtpproxy_engage('ierz20');
>>          topology_hiding();
>>      }
>>
>>      if (has_body("application/sdp")) {
>>          if (rtpproxy_offer('iewz20')) {
>>              t_on_reply("1");
>>          } else {
>>              t_on_reply("2");
>>          }
>>      }
>>
>>
>>      route(RELAY);
>> }
>>
>>
>> route[RELAY] {
>>      if (!t_relay()) {
>>          sl_reply_error();
>>      };
>>      exit;
>> }
>>
>>
>>
>>
>>
>>
>> Debug below
>>
>>
>> [Script Trace][/etc/opensips/opensips.cfg:176][me][core if] -> (BYE from
>> 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:171][me][module
>> mf_process_maxfwd_header] -> (BYE from 10.10.16.1,
>> ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=100
>> Jul 23 16:01:16 [22780] DBG:core:parse_to_param: tag=6pou4pvn6xe2phuk.i
>> Jul 23 16:01:16 [22780] DBG:core:parse_to: end of header reached, state=29
>> Jul 23 16:01:16 [22780] DBG:core:parse_to: display={},
>> ruri={sip:27111000626 at 10.10.16.1:5060;user=phone}
>> Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: <To> [70];
>> uri=[sip:27111000626 at 10.10.16.1:5060;user=phone]
>> Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: to body
>> [<sip:27111000626 at 10.10.16.1:5060;user=phone>]
>> Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: cseq <CSeq>: <2> <BYE>
>> Jul 23 16:01:16 [22780] DBG:maxfwd:is_maxfwd_present: value = 67
>> [Script Trace][/etc/opensips/opensips.cfg:185][me][core if] -> (BYE from
>> 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:176][me][module
>> check_source_address] -> (BYE from 10.10.16.1,
>> ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:permissions:check_src_addr_3: Looking for :
>> <1, 10.10.16.1, 5060, 1> in tables
>> Jul 23 16:01:16 [22780] DBG:permissions:hash_match: no pattern to match
>> Jul 23 16:01:16 [22780] DBG:permissions:hash_match: match found in the
>> hash table
>> [Script Trace][/etc/opensips/opensips.cfg:178][me][core setflag] -> (BYE
>> from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:248][me][core if] -> (BYE from
>> 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:187][me][module has_totag] ->
>> (BYE from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:uri:has_totag: totag found
>> [Script Trace][/etc/opensips/opensips.cfg:242][me][core if] -> (BYE from
>> 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:191][me][module
>> topology_hiding_match] -> (BYE from 10.10.16.1,
>> ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=200
>> Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: content_length=0
>> Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: found end of header
>> Jul 23 16:01:16 [22780] DBG:core:grep_sock_info: checking if host==us:
>> 13==13 &&  [10.10.16.2] == [10.10.16.2]
>> Jul 23 16:01:16 [22780] DBG:core:grep_sock_info: checking if port 5060
>> matches port 5060
>> Jul 23 16:01:16 [22780] DBG:dialog:w_match_dialog: We found DID param in
>> R-URI with value of dbf.d239f4f3
>> Jul 23 16:01:16 [22780] DBG:dialog:dlg_onroute: route param is
>> 'dbf.d239f4f3' (len=12)
>> Jul 23 16:01:16 [22780] DBG:dialog:lookup_dlg: ref dlg 0x7f81e1b3c2f8
>> with 1 -> 4
>> Jul 23 16:01:16 [22780] DBG:dialog:lookup_dlg: dialog id=1062179629
>> found on entry 4029
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=58
>> Jul 23 16:01:16 [22780] DBG:core:parse_to_param:
>> tag=SDl3i7c02-55B0F3A1-1DDB4E1-0ADE2C1B
>> Jul 23 16:01:16 [22780] DBG:core:parse_to: end of header reached, state=29
>> Jul 23 16:01:16 [22780] DBG:core:parse_to: display={},
>> ruri={sip:27115138000 at 10.10.17.55;user=phone}
>> Jul 23 16:01:16 [22780] DBG:dialog:next_state_dlg: dialog 0x7f81e1b3c2f8
>> changed from state 2 to state 2, due event 7
>> [Script Trace][/etc/opensips/opensips.cfg:199][me][core if] -> (BYE from
>> 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:194][me][module
>> validate_dialog] -> (BYE from 10.10.16.1,
>> ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:dialog:dlg_validate_dialog: CSEQ validation
>> passed
>> [Script Trace][/etc/opensips/opensips.cfg:210][me][core if] -> (BYE from
>> 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:199][me][module is_method] ->
>> (BYE from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:200][me][core setflag] -> (BYE
>> from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:201][me][core setflag] -> (BYE
>> from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:227][me][core if] -> (BYE from
>> 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:210][me][module has_body] ->
>> (BYE from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:sipmsgops:has_body_f: content length is zero
>> [Script Trace][/etc/opensips/opensips.cfg:227][me][route RELAY] -> (BYE
>> from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:340][me][core if] -> (BYE from
>> 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:338][me][module t_relay] ->
>> (BYE from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:tm:t_newtran: transaction on
>> entrance=0xffffffffffffffff
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=ffffffffffffffff
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=78
>> Jul 23 16:01:16 [22780] DBG:tm:t_lookup_request: start searching:
>> hash=40946, isACK=0
>> Jul 23 16:01:16 [22780] DBG:tm:matching_3261: RFC3261 transaction
>> matching failed
>> Jul 23 16:01:16 [22780] DBG:tm:t_lookup_request: no transaction found
>> Jul 23 16:01:16 [22780] DBG:tm:run_reqin_callbacks:
>> trans=0x7f81e1b41548, callback type 1, id 1 entered
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=78
>> Jul 23 16:01:16 [22780] DBG:tm:run_reqin_callbacks:
>> trans=0x7f81e1b41548, callback type 1, id 0 entered
>> Jul 23 16:01:16 [22780] DBG:dialog:ref_dlg: ref dlg 0x7f81e1b3c2f8 with
>> 1 -> 5
>> Jul 23 16:01:16 [22780] DBG:core:mk_proxy: doing DNS lookup...
>> Jul 23 16:01:16 [22780] DBG:core:check_ip_address: params 10.10.16.1,
>> 10.10.16.1, 0
>> Jul 23 16:01:16 [22780] DBG:tm:set_timer: relative timeout is 500000
>> Jul 23 16:01:16 [22780] DBG:tm:insert_timer_unsafe: [4]: 0x7f81e1b41768
>> (15800000)
>> Jul 23 16:01:16 [22780] DBG:tm:insert_timer_unsafe: [0]: 0x7f81e1b41798 (20)
>> Jul 23 16:01:16 [22780] DBG:tm:t_relay_to: new transaction fwd'ed
>> [Script Trace][/etc/opensips/opensips.cfg:341][me][core exit] -> (BYE
>> from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:tm:t_unref: UNREF_UNSAFE: [0x7f81e1b41548]
>> after is 0
>> Jul 23 16:01:16 [22780] DBG:dialog:unref_dlg: unref dlg 0x7f81e1b3c2f8
>> with 1 -> 4 in entry 0x7f81e1b35838
>> Jul 23 16:01:16 [22780] DBG:core:destroy_avp_list: destroying list (nil)
>> Jul 23 16:01:16 [22780] DBG:core:receive_msg: cleaning up
>> Jul 23 16:01:16 [22780] DBG:core:parse_msg: SIP Request:
>> Jul 23 16:01:16 [22780] DBG:core:parse_msg:  method:  <BYE>
>> Jul 23 16:01:16 [22780] DBG:core:parse_msg:  uri:
>> <sip:10.10.16.2;did=dbf.d239f4f3>
>> Jul 23 16:01:16 [22780] DBG:core:parse_msg:  version: <SIP/2.0>
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=2
>> Jul 23 16:01:16 [22780] DBG:core:parse_via_param: found param type 232,
>> <branch> = <z9hG4bK2ff9.7dfac551.0>; state=16
>> Jul 23 16:01:16 [22780] DBG:core:parse_via: end of header reached, state=5
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: via found, flags=2
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: this is the first via
>> Jul 23 16:01:16 [22780] DBG:core:receive_msg: After parse_msg...
>> Jul 23 16:01:16 [22780] DBG:core:receive_msg: preparing to run routing
>> scripts...
>> [Script Trace][/etc/opensips/opensips.cfg:176][me][core if] -> (BYE from
>> 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:171][me][module
>> mf_process_maxfwd_header] -> (BYE from 10.10.16.2,
>> ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=100
>> Jul 23 16:01:16 [22780] DBG:core:parse_via_param: found param type 232,
>> <branch> = <z9hG4bK53eneb00a89gqfc5m0o0.1>; state=16
>> Jul 23 16:01:16 [22780] DBG:core:parse_via: end of header reached, state=5
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: via found, flags=100
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: parse_headers: this is
>> the second via
>> Jul 23 16:01:16 [22780] DBG:core:parse_to_param: tag=6pou4pvn6xe2phuk.i
>> Jul 23 16:01:16 [22780] DBG:core:parse_to: end of header reached, state=29
>> Jul 23 16:01:16 [22780] DBG:core:parse_to: display={},
>> ruri={sip:27111000626 at 10.10.16.1:5060;user=phone}
>> Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: <To> [70];
>> uri=[sip:27111000626 at 10.10.16.1:5060;user=phone]
>> Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: to body
>> [<sip:27111000626 at 10.10.16.1:5060;user=phone>]
>> Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: cseq <CSeq>: <2> <BYE>
>> Jul 23 16:01:16 [22780] DBG:maxfwd:is_maxfwd_present: value = 66
>> [Script Trace][/etc/opensips/opensips.cfg:185][me][core if] -> (BYE from
>> 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:176][me][module
>> check_source_address] -> (BYE from 10.10.16.2,
>> ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:permissions:check_src_addr_3: Looking for :
>> <1, 10.10.16.2, 5060, 1> in tables
>> Jul 23 16:01:16 [22780] DBG:permissions:hash_match: no match in the hash
>> table
>> Jul 23 16:01:16 [22780] DBG:permissions:match_subnet_table: subnet table
>> is empty
>> [Script Trace][/etc/opensips/opensips.cfg:185][me][core if] -> (BYE from
>> 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:179][me][module is_from_gw] ->
>> (BYE from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:183][me][core xlog] -> (BYE
>> from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:core:buf_init: initializing...
>> Message is not from Trunk or GW 10.10.16.2[Script
>> Trace][/etc/opensips/opensips.cfg:248][me][core if] -> (BYE from
>> 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:187][me][module has_totag] ->
>> (BYE from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:uri:has_totag: totag found
>> [Script Trace][/etc/opensips/opensips.cfg:242][me][core if] -> (BYE from
>> 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:191][me][module
>> topology_hiding_match] -> (BYE from 10.10.16.2,
>> ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=200
>> Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: content_length=0
>> Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: found end of header
>> Jul 23 16:01:16 [22780] DBG:core:grep_sock_info: checking if host==us:
>> 13==13 &&  [10.10.16.2] == [10.10.16.2]
>> Jul 23 16:01:16 [22780] DBG:core:grep_sock_info: checking if port 5060
>> matches port 5060
>> Jul 23 16:01:16 [22780] DBG:dialog:w_match_dialog: We found DID param in
>> R-URI with value of dbf.d239f4f3
>> Jul 23 16:01:16 [22780] DBG:dialog:dlg_onroute: route param is
>> 'dbf.d239f4f3' (len=12)
>> Jul 23 16:01:16 [22780] DBG:dialog:lookup_dlg: ref dlg 0x7f81e1b3c2f8
>> with 1 -> 5
>> Jul 23 16:01:16 [22780] DBG:dialog:lookup_dlg: dialog id=1062179629
>> found on entry 4029
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=58
>> Jul 23 16:01:16 [22780] DBG:core:parse_to_param:
>> tag=SDl3i7c02-55B0F3A1-1DDB4E1-0ADE2C1B
>> Jul 23 16:01:16 [22780] DBG:core:parse_to: end of header reached, state=29
>> Jul 23 16:01:16 [22780] DBG:core:parse_to: display={},
>> ruri={sip:27115138000 at 10.10.17.55;user=phone}
>> Jul 23 16:01:16 [22780] DBG:dialog:next_state_dlg: dialog 0x7f81e1b3c2f8
>> changed from state 2 to state 2, due event 7
>> [Script Trace][/etc/opensips/opensips.cfg:199][me][core if] -> (BYE from
>> 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Trevor
>> [Script Trace][/etc/opensips/opensips.cfg:194][me][module
>> validate_dialog] -> (BYE from 10.10.16.2,
>> ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:dialog:dlg_validate_dialog: CSEQ validation
>> passed
>> [Script Trace][/etc/opensips/opensips.cfg:210][me][core if] -> (BYE from
>> 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:199][me][module is_method] ->
>> (BYE from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:200][me][core setflag] -> (BYE
>> from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:201][me][core setflag] -> (BYE
>> from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:227][me][core if] -> (BYE from
>> 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:210][me][module has_body] ->
>> (BYE from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:sipmsgops:has_body_f: content length is zero
>> [Script Trace][/etc/opensips/opensips.cfg:227][me][route RELAY] -> (BYE
>> from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:340][me][core if] -> (BYE from
>> 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:338][me][module t_relay] ->
>> (BYE from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:tm:t_newtran: transaction on
>> entrance=0xffffffffffffffff
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=ffffffffffffffff
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=78
>> Jul 23 16:01:16 [22780] DBG:tm:t_lookup_request: start searching:
>> hash=40946, isACK=0
>> Jul 23 16:01:16 [22780] DBG:tm:matching_3261: RFC3261 transaction
>> matching failed
>> Jul 23 16:01:16 [22780] DBG:tm:t_lookup_request: no transaction found
>> Jul 23 16:01:16 [22780] DBG:tm:run_reqin_callbacks:
>> trans=0x7f81e1b446a0, callback type 1, id 1 entered
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=78
>> Jul 23 16:01:16 [22780] DBG:tm:run_reqin_callbacks:
>> trans=0x7f81e1b446a0, callback type 1, id 0 entered
>> Jul 23 16:01:16 [22780] DBG:dialog:ref_dlg: ref dlg 0x7f81e1b3c2f8 with
>> 1 -> 6
>> Jul 23 16:01:16 [22780] DBG:core:mk_proxy: doing DNS lookup...
>> Jul 23 16:01:16 [22780] DBG:core:check_ip_address: params 10.10.16.2,
>> 10.10.16.2, 0
>> Jul 23 16:01:16 [22780] DBG:tm:set_timer: relative timeout is 500000
>> Jul 23 16:01:16 [22780] DBG:tm:insert_timer_unsafe: [4]: 0x7f81e1b448c0
>> (15800000)
>> Jul 23 16:01:16 [22780] DBG:tm:insert_timer_unsafe: [0]: 0x7f81e1b448f0 (20)
>> Jul 23 16:01:16 [22780] DBG:tm:t_relay_to: new transaction fwd'ed
>> [Script Trace][/etc/opensips/opensips.cfg:341][me][core exit] -> (BYE
>> from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:tm:t_unref: UNREF_UNSAFE: [0x7f81e1b446a0]
>> after is 0
>> Jul 23 16:01:16 [22780] DBG:dialog:unref_dlg: unref dlg 0x7f81e1b3c2f8
>> with 1 -> 5 in entry 0x7f81e1b35838
>> Jul 23 16:01:16 [22780] DBG:core:destroy_avp_list: destroying list (nil)
>> Jul 23 16:01:16 [22780] DBG:core:receive_msg: cleaning up
>> Jul 23 16:01:16 [22780] DBG:core:parse_msg: SIP Request:
>> Jul 23 16:01:16 [22780] DBG:core:parse_msg:  method:  <BYE>
>> Jul 23 16:01:16 [22780] DBG:core:parse_msg:  uri:
>> <sip:10.10.16.2;did=dbf.d239f4f3>
>> Jul 23 16:01:16 [22780] DBG:core:parse_msg:  version: <SIP/2.0>
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=2
>> Jul 23 16:01:16 [22780] DBG:core:parse_via_param: found param type 232,
>> <branch> = <z9hG4bK2ff9.8dfac551.0>; state=16
>> Jul 23 16:01:16 [22780] DBG:core:parse_via: end of header reached, state=5
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: via found, flags=2
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: this is the first via
>> Jul 23 16:01:16 [22780] DBG:core:receive_msg: After parse_msg...
>> Jul 23 16:01:16 [22780] DBG:core:receive_msg: preparing to run routing
>> scripts...
>> [Script Trace][/etc/opensips/opensips.cfg:176][me][core if] -> (BYE from
>> 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:171][me][module
>> mf_process_maxfwd_header] -> (BYE from 10.10.16.2,
>> ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=100
>> Jul 23 16:01:16 [22780] DBG:core:parse_via_param: found param type 232,
>> <branch> = <z9hG4bK2ff9.7dfac551.0>; state=16
>> Jul 23 16:01:16 [22780] DBG:core:parse_via: end of header reached, state=5
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: via found, flags=100
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: parse_headers: this is
>> the second via
>> Jul 23 16:01:16 [22780] DBG:core:parse_via_param: found param type 232,
>> <branch> = <z9hG4bK53eneb00a89gqfc5m0o0.1>; state=16
>> Jul 23 16:01:16 [22780] DBG:core:parse_via: end of header reached, state=5
>> Jul 23 16:01:16 [22780] DBG:core:parse_headers: via found, flags=100
>> Jul 23 16:01:16 [22780] DBG:core:parse_to_param: tag=6pou4pvn6xe2phuk.i
>> Jul 23 16:01:16 [22780] DBG:core:parse_to: end of header reached, state=29
>> Jul 23 16:01:16 [22780] DBG:core:parse_to: display={},
>> ruri={sip:27111000626 at 10.10.16.1:5060;user=phone}
>> Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: <To> [70];
>> uri=[sip:27111000626 at 10.10.16.1:5060;user=phone]
>> Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: to body
>> [<sip:27111000626 at 10.10.16.1:5060;user=phone>]
>> Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: cseq <CSeq>: <2> <BYE>
>> Jul 23 16:01:16 [22780] DBG:maxfwd:is_maxfwd_present: value = 65
>> [Script Trace][/etc/opensips/opensips.cfg:185][me][core if] -> (BYE from
>> 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:176][me][module
>> check_source_address] -> (BYE from 10.10.16.2,
>> ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Jul 23 16:01:16 [22780] DBG:permissions:check_src_addr_3: Looking for :
>> <1, 10.10.16.2, 5060, 1> in tables
>> Jul 23 16:01:16 [22780] DBG:permissions:hash_match: no match in the hash
>> table
>> Jul 23 16:01:16 [22780] DBG:permissions:match_subnet_table: subnet table
>> is empty
>> [Script Trace][/etc/opensips/opensips.cfg:185][me][core if] -> (BYE from
>> 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:179][me][module is_from_gw] ->
>> (BYE from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> [Script Trace][/etc/opensips/opensips.cfg:183][me][core xlog] -> (BYE
>> from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>> Message is not from Trunk or GW 10.10.16.2[Script
>> Trace][/etc/opensips/opensips.cfg:248][me][core if] -> (BYE from
>> 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
>>
>>
>> Regards
>> Trevor Steyn
>>
>
> _______________________________________________
> Devel mailing list
> Devel at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/devel




More information about the Devel mailing list