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

Trevor Steyn trevor at webon.co.za
Mon Aug 3 20:03:56 CEST 2015


Thanks for the Info Vlad I will update.

Regards
Trevor Steyn


On 03/08/2015 16:41, Vlad Paiu wrote:
> 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
>
>
> _______________________________________________
> Devel mailing list
> Devel at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/devel




More information about the Devel mailing list