Inbound call not works

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

Inbound call not works

Spady#7
Hi all, I am tryng to understand how OpenSIPS works and i am playng with OpenSIPS liveCD.
I am able to register to it user and make outbound call toward asterisk machine ( is a separated server with different IP ).
The problem is when an asterisk user try to call a OpenSIPS user.
I always have these logs:

Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_msg: SIP Request:
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_msg:  method:  <INVITE>
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_msg:  uri:     <sip:6000@172.16.52.139>
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_msg:  version: <SIP/2.0>
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_headers: flags=2
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK144b79e0>; state=16
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_via: end of header reached, state=5
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_headers: via found, flags=2
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_headers: this is the first via
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:receive_msg: After parse_msg...
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:receive_msg: preparing to run routing scripts...
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_headers: flags=100
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:maxfwd:is_maxfwd_present: value = 70
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:check_ip_address: params 172.16.52.123, 172.16.52.123, 0
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_headers: flags=ffffffffffffffff
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_to: end of header reached, state=10
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_to: display={}, ruri={sip:6000@172.16.52.139}
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:get_hdr_field: <To> [26]; uri=[sip:6000@172.16.52.139]
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:get_hdr_field: to body [<sip:6000@172.16.52.139>^M ]
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:get_hdr_field: cseq <CSeq>: <102> <INVITE>
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:get_hdr_field: content_length=691
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:get_hdr_field: found end of header
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_headers: flags=ffffffffffffffff
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:uri:has_totag: no totag
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_headers: flags=78
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:tm:t_lookup_request: start searching: hash=4543, isACK=0
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:tm:t_lookup_request: no transaction found
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_to_param: tag=as575851dd
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_to: end of header reached, state=29
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_to: display={"Thomson 3950"}, ruri={sip:3950@172.16.52.139}
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:parse_headers: flags=ffffffffffffffff
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:check_ip_address: params 172.16.52.123, 172.16.52.123, 0
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:destroy_avp_list: destroying list (nil)
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3211]: DBG:core:receive_msg: cleaning up
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:parse_msg: SIP Request:
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:parse_msg:  method:  <ACK>
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:parse_msg:  uri:     <sip:6000@172.16.52.139>
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:parse_msg:  version: <SIP/2.0>
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:parse_headers: flags=2
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK144b79e0>; state=16
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:parse_via: end of header reached, state=5
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:parse_headers: via found, flags=2
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:parse_headers: this is the first via
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:receive_msg: After parse_msg...
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:receive_msg: preparing to run routing scripts...
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:parse_headers: flags=8
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:parse_to_param: tag=988e82a5532bada72d6d9bbb7ebb56fd.647c
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:parse_to: end of header reached, state=29
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:parse_to: display={}, ruri={sip:6000@172.16.52.139}
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:get_hdr_field: <To> [68]; uri=[sip:6000@172.16.52.139]
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:get_hdr_field: to body [<sip:6000@172.16.52.139>]
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:sl:sl_filter_ACK: local ACK found -> dropping it!
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:destroy_avp_list: destroying list (nil)
Jul 27 04:08:26 opensips /usr/local/opensips_proxy/sbin/opensips[3210]: DBG:core:receive_msg: cleaning up



and


U 2011/07/27 04:12:25.959849 172.16.52.123:5060 -> 172.16.52.139:5060
INVITE sip:6000@172.16.52.139 SIP/2.0.
Via: SIP/2.0/UDP 172.16.52.123:5060;branch=z9hG4bK4359b3d8.
Max-Forwards: 70.
From: "Thomson 3950" <sip:3950@172.16.52.139>;tag=as4f95741d.
To: <sip:6000@172.16.52.139>.
Contact: <sip:3950@172.16.52.123:5060>.
Call-ID: 50b618447ccfbd4b6e23336e33e301e2@172.16.52.139.
CSeq: 102 INVITE.
User-Agent: FPBX-2.9.0(1.8.5.0).
Date: Wed, 27 Jul 2011 08:14:44 GMT.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH.
Supported: replaces, timer.
Content-Type: application/sdp.
Content-Length: 693.
.
v=0.
o=root 1272428081 1272428081 IN IP4 172.16.52.123.
s=Asterisk PBX 1.8.5.0.
c=IN IP4 172.16.52.123.
b=CT:384.
t=0 0.
m=audio 17670 RTP/AVP 8 0 3 112 5 10 7 111 9 118 101.
a=rtpmap:8 PCMA/8000.
a=rtpmap:0 PCMU/8000.
a=rtpmap:3 GSM/8000.
a=rtpmap:112 AAL2-G726-32/8000.
a=rtpmap:5 DVI4/8000.
a=rtpmap:10 L16/8000.
a=rtpmap:7 LPC/8000.
a=rtpmap:111 G726-32/8000.
a=rtpmap:9 G722/8000.
a=rtpmap:118 L16/16000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.
a=sendrecv.
m=video 16088 RTP/AVP 26 31 34 98 99 104.
a=rtpmap:26 JPEG/90000.
a=rtpmap:31 H261/90000.
a=rtpmap:34 H263/90000.
a=rtpmap:98 h263-1998/90000.
a=rtpmap:99 H264/90000.
a=rtpmap:104 MP4V-ES/90000.
a=sendrecv.


U 2011/07/27 04:12:25.962767 172.16.52.139:5060 -> 172.16.52.123:5060
SIP/2.0 403 No relaying.
Via: SIP/2.0/UDP 172.16.52.123:5060;branch=z9hG4bK4359b3d8;rport=5060.
From: "Thomson 3950" <sip:3950@172.16.52.139>;tag=as4f95741d.
To: <sip:6000@172.16.52.139>;tag=988e82a5532bada72d6d9bbb7ebb56fd.13cf.
Call-ID: 50b618447ccfbd4b6e23336e33e301e2@172.16.52.139.
CSeq: 102 INVITE.
Server: OpenSIPS (1.6.3-notls (i386/linux)).
Content-Length: 0.
.


U 2011/07/27 04:12:25.964102 172.16.52.123:5060 -> 172.16.52.139:5060
ACK sip:6000@172.16.52.139 SIP/2.0.
Via: SIP/2.0/UDP 172.16.52.123:5060;branch=z9hG4bK4359b3d8.
Max-Forwards: 70.
From: "Thomson 3950" <sip:3950@172.16.52.139>;tag=as4f95741d.
To: <sip:6000@172.16.52.139>;tag=988e82a5532bada72d6d9bbb7ebb56fd.13cf.
Contact: <sip:3950@172.16.52.123:5060>.
Call-ID: 50b618447ccfbd4b6e23336e33e301e2@172.16.52.139.
CSeq: 102 ACK.
User-Agent: FPBX-2.9.0(1.8.5.0).
Content-Length: 0.



IP 172.16.52.139 = OpenSIPS
IP 172.16.52.123 = Asterisk


Can you help me where is the problem???

Thanks
Reply | Threaded
Open this post in threaded view
|

Re: Inbound call not works

Spady#7
Hi all, I am getting closer to solution. After many tests and changes I understood that the domain into From HEADER of INVITE was not present into DOMAIN table of mysql. After added it the error message into "ngrep" is changed; now it's

U 2011/07/28 04:49:40.126784 172.16.52.139:5060 -> 172.16.52.123:5060
SIP/2.0 404 Not Found.
Via: SIP/2.0/UDP 172.16.52.123:5060;branch=z9hG4bK41cebffd;rport=5060.
From: "Thomson 3950" <sip:3950@172.16.52.139>;tag=as6de7a212.
To: <sip:6000@172.16.52.139>;tag=377ee575c0f232753ada2b7982794fac-4408.
Call-ID: 54925a5c3d5c4e33733f3d3418832488@172.16.52.139.
CSeq: 102 INVITE.
Server: OpenSIPS (1.6.3-notls (i386/linux)).
Content-Length: 0.

OK I found,after some DBG, that user 6000 is not present into usrloc table. See below:

Jul 28 04:21:31 opensips /usr/local/opensips_proxy/sbin/opensips[3371]: DBG:dialplan:dp_translate_f: input is 6000
Jul 28 04:21:31 opensips /usr/local/opensips_proxy/sbin/opensips[3371]: DBG:dialplan:translate: regex operator testing
Jul 28 04:21:31 opensips /usr/local/opensips_proxy/sbin/opensips[3371]: DBG:dialplan:test_match: test_match:[0] 6
Jul 28 04:21:31 opensips /usr/local/opensips_proxy/sbin/opensips[3371]: DBG:dialplan:translate: found a matching rule 0xaf1d422c: pr 0, match_exp ^6
Jul 28 04:21:31 opensips /usr/local/opensips_proxy/sbin/opensips[3371]: DBG:dialplan:translate: the rule's attrs are usrloc
Jul 28 04:21:31 opensips /usr/local/opensips_proxy/sbin/opensips[3371]: DBG:dialplan:translate: the copied attributes are: usrloc
Jul 28 04:21:31 opensips /usr/local/opensips_proxy/sbin/opensips[3371]: DBG:dialplan:rule_translate: null replacement
Jul 28 04:21:31 opensips /usr/local/opensips_proxy/sbin/opensips[3371]: DBG:dialplan:dp_translate_f: input 6000 with dpid 0 => output
Jul 28 04:21:31 opensips /usr/local/opensips_proxy/sbin/opensips[3371]: usrloc
Jul 28 04:21:31 opensips /usr/local/opensips_proxy/sbin/opensips[3371]: DBG:core:comp_scriptvar: str 20 : usrloc
Jul 28 04:21:31 opensips /usr/local/opensips_proxy/sbin/opensips[3371]: DBG:registrar:lookup: '6000@172.16.52.139' Not found in usrloc

As you can see 6000 is not present BUT if I call this user by OPENSIPS user it works. 6000 is an alias for xxxx@yyyy.com user.
So now what is not clear is how OpenSIPS works if it receive a call from inside site and from outside site.
I mean, why if I call number 6000 ( that's an alias fro user xxxx@yyyy.com ) from opensips's user i can reach it BUT if I call same number from outside ( in my case from asterisk box ) does not work???
Regards.
Reply | Threaded
Open this post in threaded view
|

Re: Inbound call not works

Spady#7
Solved!!!
I was wrong at asterisk side. I had put "from domain" *'s TG that was altering From header. Now it works on both direction.
Hope my experience reported here can help someone else.
Best regards.