Problem with outbound calls

spycat · November 15, 2012, 1:33pm

Hi,

on our server we have a2billing and asterisk and Debian latest version and also Parallel plesk, it was not so easy to find why there was problem with context a2billing, string include didn’t work, but now there is problem that whenever I make call it looks like that system doesn’t know where it send that call, here is the log:

o=3cxVCE 143424210 246579030 IN IP4 address of the softphone
s=3cxVCE Audio Call
c=IN IP4 address of the softphone
t=0 0
m=audio 40044 RTP/AVP 0 8 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
m=video 40046 RTP/AVP 34
c=IN IP4 address of the softphone
a=rtpmap:34 H263/90000
a=fmtp:34 QCIF=1;CIF=1;SQCIF=1;CIF4=1
a=sendrecv
<------------->
— (14 headers 18 lines) —
Sending to address of the softphone:58857 (NAT)
Using INVITE request as basis request - ZDBlMWQ3ZDVlZTEzYzM3ZjMyZTU4OGYxMWI0Mjk5NjM.
Found peer ‘0646679158’ for ‘0646679158’ from address of the softphone:58857
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 3
Found RTP audio format 101
Found audio description format PCMU for ID 0
Found audio description format PCMA for ID 8
Found audio description format GSM for ID 3
Found audio description format telephone-event for ID 101
Found RTP video format 34
Found video description format H263 for ID 34
Capabilities: us - 0x10e (gsm|ulaw|alaw|g729), peer - audio=0xe (gsm|ulaw|alaw)/video=0x80000 (h263)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port address of the softphone:40044
Looking for telephone number in a2billing (domain address of the server)
list_route: hop: <sip:0646679158@address of the softphone:58857;transport=UDP>

<— Transmitting (NAT) to address of the softphone:58857 —>
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.2.78:58857;branch=z9hG4bK-d8754z-930ca85ebf13d21c-1—d8754z-;received=address of the softphone;rport=58857
From: “pc”<sip:0646679158@address of the server:5060>;tag=2a46d213
To: <sip:telephone number@address of the server:5060>
Call-ID: ZDBlMWQ3ZDVlZTEzYzM3ZjMyZTU4OGYxMWI0Mjk5NjM.
CSeq: 2 INVITE
Server: Asterisk PBX 1.8.11.1-1digium1~squeeze
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
upported: replaces, timer
Contact: <sip:telephone number@address of the server:5060>
Content-Length: 0

<------------>
Audio is at 14836
Adding codec 0x4 (ulaw) to SDP
Adding codec 0x8 (alaw) to SDP
Adding codec 0x2 (gsm) to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<— Reliably Transmitting (NAT) to address of the softphone:58857 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.78:58857;branch=z9hG4bK-d8754z-930ca85ebf13d21c-1—d8754z-;received=address of the softphone;rport=58857
From: “pc”<sip:0646679158@address of the server:5060>;tag=2a46d213
To: <sip:telephone number@address of the server:5060>;tag=as4d79e82c
Call-ID: ZDBlMWQ3ZDVlZTEzYzM3ZjMyZTU4OGYxMWI0Mjk5NjM.
CSeq: 2 INVITE
Server: Asterisk PBX 1.8.11.1-1digium1~squeeze
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:telephone number@address of the server:5060>
Content-Type: application/sdp
Content-Length: 325

v=0
o=root 2069194054 2069194054 IN IP4 address of the server
s=Asterisk PBX 1.8.11.1-1digium1~squeeze
c=IN IP4 address of the server
t=0 0
m=audio 14836 RTP/AVP 0 8 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 0 RTP/AVP 34

<------------>
Retransmitting #1 (NAT) to address of the softphone:58857:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.2.78:58857;branch=z9hG4bK-d8754z-930ca85ebf13d21c-1—d8754z-;received=address of the softphone;rport=58857
From: “pc”<sip:0646679158@address of the server:5060>;tag=2a46d213
To: <sip:telephone number@address of the server:5060>;tag=as4d79e82c
Call-ID: ZDBlMWQ3ZDVlZTEzYzM3ZjMyZTU4OGYxMWI0Mjk5NjM.
CSeq: 2 INVITE
Server: Asterisk PBX 1.8.11.1-1digium1~squeeze
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:telephone number@address of the server:5060>
Content-Type: application/sdp
Content-Length: 325

v=0
o=root 2069194054 2069194054 IN IP4 address of the server
s=Asterisk PBX 1.8.11.1-1digium1~squeeze
c=IN IP4 address of the server
t=0 0
m=audio 14836 RTP/AVP 0 8 3 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 0 RTP/AVP 34

<— SIP read from UDP:address of the softphone:58857 —>
ACK sip:telephone number@address of the server:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.2.78:58857;branch=z9hG4bK-d8754z-cd78e9166e1b6967-1—d8754z-;rport
Max-Forwards: 70
Contact: <sip:0646679158@address of the softphone:58857;transport=UDP>
To: <sip:telephone number@address of the server:5060>;tag=as4d79e82c
From: “pc”<sip:0646679158@address of the server:5060>;tag=2a46d213
Call-ID: ZDBlMWQ3ZDVlZTEzYzM3ZjMyZTU4OGYxMWI0Mjk5NjM.
CSeq: 2 ACK
User-Agent: 3CXPhone 6.0.25732.0
Authorization: Digest username=“0646679158”,realm=“asterisk”,nonce=“5e9a183c”,uri=“sip:telephone number@address of the server:5060”,response=“8594f87b6e565e2931239c3dd791c6e9”,algorithm=MD5
Content-Length: 0

<------------->
— (11 headers 0 lines) —

<— SIP read from UDP:address of the softphone:58857 —>
ACK sip:telephone number@address of the server:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.2.78:58857;branch=z9hG4bK-d8754z-cd78e9166e1b6967-1—d8754z-;rport
Max-Forwards: 70
Contact: <sip:0646679158@address of the softphone:58857;transport=UDP>
To: <sip:telephone number@address of the server:5060>;tag=as4d79e82c
From: “pc”<sip:0646679158@address of the server:5060>;tag=2a46d213
Call-ID: ZDBlMWQ3ZDVlZTEzYzM3ZjMyZTU4OGYxMWI0Mjk5NjM.
CSeq: 2 ACK
User-Agent: 3CXPhone 6.0.25732.0
Authorization: Digest username=“0646679158”,realm=“asterisk”,nonce=“5e9a183c”,uri=“sip:telephone number@address of the server:5060”,response=“8594f87b6e565e2931239c3dd791c6e9”,algorithm=MD5
Content-Length: 0

<------------->
— (11 headers 0 lines) —
Scheduling destruction of SIP dialog ‘ZDBlMWQ3ZDVlZTEzYzM3ZjMyZTU4OGYxMWI0Mjk5NjM.’ in 9472 ms (Method: ACK)
set_destination: Parsing <sip:0646679158@address of the softphone:58857;transport=UDP> for address/port to send to
set_destination: set destination to address of the softphone:58857
Reliably Transmitting (NAT) to address of the softphone:58857:
BYE sip:0646679158@address of the softphone:58857;transport=UDP SIP/2.0
Via: SIP/2.0/UDP address of the server:5060;branch=z9hG4bK24b844fd;rport
Max-Forwards: 70
From: <sip:telephone number@address of the server:5060>;tag=as4d79e82c
To: “pc”<sip:0646679158@address of the server:5060>;tag=2a46d213
Call-ID: ZDBlMWQ3ZDVlZTEzYzM3ZjMyZTU4OGYxMWI0Mjk5NjM.
CSeq: 102 BYE
User-Agent: Asterisk PBX 1.8.11.1-1digium1~squeeze
Proxy-Authorization: Digest username=“0646679158”, realm=“asterisk”, algorithm=MD5, uri=“sip:address of the server”, nonce="", response="c9a60ff3026109800df9fe8d600e8ca2"
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

Any suggestion please?

Thank you.

david55 · November 15, 2012, 1:45pm

The trace, which is incomplete (initial invite truncated and no response to BYE), shows a successful incoming call which is normally cleared by Asterisk, on a dodgy network (or possibly involving VMs) (ACK to 200 is so late that it has to be re-sent).

There is inadequate verbosity to work out why the dialplan chose to close the call, and as this is screen-scraped, rather than from a log, it is not possible to tell how long there was from the ACK to the BYE.

There appear to be two complete copies of the posting. I’m assuming that they are both the same.

spycat · November 15, 2012, 2:45pm

Ok, can you tell me, what shall I do? The log now says: chan_sip.c: Correct auth, but based on stale nonce received from ‘“pc”<sip:0646679158@[IP of the server]:5060>;tag=7c653031’

david55 · November 15, 2012, 3:25pm

You need to set the verbosity to at least 3. You should also provide the relevant part of the dialplan, as one cannot see the source forms of expressions in the verbose output.

However, if this is in dialplan provided as part of a2billing, an a2billing forum may be a better choice, as that sort of dialplan tends to be quite complex, and without detailed knowledge, one won’t know what can safely be changed.

spycat · November 15, 2012, 3:33pm

This is context of our dialplan:

[a2billing]
exten => _X.,1,Answer
exten => _X.,n,Wait(1)
exten => _X.,n,AGI(a2billing.php,1)
exten => _X.,n,Hangup

spycat · November 15, 2012, 3:42pm

and this is log after change of the verbosity to 3:

<— SIP read from UDP:[address of the softphone]:53991 —>
ACK sip:[calling number]@[IP of the server]:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.2.78:53991;branch=z9hG4bK-d8754z-4a51ef3b034f2469-1—d8754z-;rport
Max-Forwards: 70
Contact: <sip:0646679158@[address of the softphone]:53991;transport=UDP>
To: <sip:[calling number]@[IP of the server]:5060>;tag=as4790a6c2
From: “pc”<sip:0646679158@[IP of the server]:5060>;tag=c1672278
Call-ID: YTBjZGUyY2JjYzY0Y2RkODAzZjkxNjE1MGUxZWQxN2E.
CSeq: 2 ACK
User-Agent: 3CXPhone 6.0.25732.0
Authorization: Digest username=“0646679158”,realm=“asterisk”,nonce=“61665e43”,uri=“sip:[calling number]@[IP of the server]:5060”,response=“118a9886625726c787cfa844d80fa020”,algorithm=MD5
Content-Length: 0

<------------->
— (11 headers 0 lines) —
– Executing [[calling number]@a2billing:2] Wait(“SIP/0646679158-00000003”, “1”) in new stack
– Executing [[calling number]@a2billing:3] AGI(“SIP/0646679158-00000003”, “a2billing.php,1”) in new stack
– Launched AGI Script /usr/share/asterisk/agi-bin/a2billing.php
– <SIP/0646679158-00000003>AGI Script a2billing.php completed, returning 0
– Executing [[calling number]@a2billing:4] Hangup(“SIP/0646679158-00000003”, “”) in new stack
== Spawn extension (a2billing, [calling number], 4) exited non-zero on 'SIP/0646679158-00000003’
Scheduling destruction of SIP dialog ‘YTBjZGUyY2JjYzY0Y2RkODAzZjkxNjE1MGUxZWQxN2E.’ in 11520 ms (Method: ACK)
set_destination: Parsing <sip:0646679158@[address of the softphone]:53991;transport=UDP> for address/port to send to
set_destination: set destination to [address of the softphone]:53991
Reliably Transmitting (NAT) to [address of the softphone]:53991:
BYE sip:0646679158@[address of the softphone]:53991;transport=UDP SIP/2.0
Via: SIP/2.0/UDP [IP of the server]:5060;branch=z9hG4bK4f7b5f88;rport
Max-Forwards: 70
From: <sip:[calling number]@[IP of the server]:5060>;tag=as4790a6c2
To: “pc”<sip:0646679158@[IP of the server]:5060>;tag=c1672278
Call-ID: YTBjZGUyY2JjYzY0Y2RkODAzZjkxNjE1MGUxZWQxN2E.
CSeq: 102 BYE
User-Agent: Asterisk PBX 1.8.11.1-1digium1~squeeze
Proxy-Authorization: Digest username=“0646679158”, realm=“asterisk”, algorithm=MD5, uri=“sip:[IP of the server]”, nonce="", response="c9a60ff3026109800df9fe8d600e8ca2"
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

david55 · November 15, 2012, 4:16pm

It’s an a2billing issue, not an Asterisk one, although you may get a bit more out by enabling AGI debugging.

spycat · November 15, 2012, 6:21pm

Here is the log with enabled AGI debug:

<------------->
— (11 headers 0 lines) —
– Executing [[telephone number]@a2billing:3] AGI(“SIP/0646679158-00000021”, “a2billing.php,1”) in new stack
– Launched AGI Script /usr/share/asterisk/agi-bin/a2billing.php
<SIP/0646679158-00000021>AGI Tx >> agi_request: a2billing.php
<SIP/0646679158-00000021>AGI Tx >> agi_channel: SIP/0646679158-00000021
<SIP/0646679158-00000021>AGI Tx >> agi_language: en
<SIP/0646679158-00000021>AGI Tx >> agi_type: SIP
<SIP/0646679158-00000021>AGI Tx >> agi_uniqueid: 1353003320.33
<SIP/0646679158-00000021>AGI Tx >> agi_version: 1.8.11.1-1digium1~squeeze
<SIP/0646679158-00000021>AGI Tx >> agi_callerid: 0646679158
<SIP/0646679158-00000021>AGI Tx >> agi_calleridname: pc
<SIP/0646679158-00000021>AGI Tx >> agi_callingpres: 0
<SIP/0646679158-00000021>AGI Tx >> agi_callingani2: 0
<SIP/0646679158-00000021>AGI Tx >> agi_callington: 0
<SIP/0646679158-00000021>AGI Tx >> agi_callingtns: 0
<SIP/0646679158-00000021>AGI Tx >> agi_dnid: [telephone number]
<SIP/0646679158-00000021>AGI Tx >> agi_rdnis: unknown
<SIP/0646679158-00000021>AGI Tx >> agi_context: a2billing
<SIP/0646679158-00000021>AGI Tx >> agi_extension: [telephone number]
<SIP/0646679158-00000021>AGI Tx >> agi_priority: 3
<SIP/0646679158-00000021>AGI Tx >> agi_enhanced: 0.0
<SIP/0646679158-00000021>AGI Tx >> agi_accountcode: 0694257425
<SIP/0646679158-00000021>AGI Tx >> agi_threadid: 139824741795584
<SIP/0646679158-00000021>AGI Tx >> agi_arg_1: 1
<SIP/0646679158-00000021>AGI Tx >>
– <SIP/0646679158-00000021>AGI Script a2billing.php completed, returning 0
– Executing [[telephone number]@a2billing:4] Hangup(“SIP/0646679158-00000021”, “”) in new stack
== Spawn extension (a2billing, [telephone number], 4) exited non-zero on 'SIP/0646679158-00000021’
Scheduling destruction of SIP dialog ‘YWJhY2M3ZTU5NTQxZDBhYzg3OWQwOTgzOGIzYjYyZjM.’ in 12032 ms (Method: ACK)
set_destination: Parsing <sip:0646679158@[IP of the softphone]:64682;transport=UDP> for address/port to send to
set_destination: set destination to [IP of the softphone]:64682
Reliably Transmitting (NAT) to [IP of the softphone]:64682:
BYE sip:0646679158@[IP of the softphone]:64682;transport=UDP SIP/2.0
Via: SIP/2.0/UDP [IP of the server/pbx]:5060;branch=z9hG4bK24d54a9e;rport
Max-Forwards: 70
From: <sip:[telephone number]@[IP of the server/pbx]:5060>;tag=as63ca21e6
To: “pc”<sip:0646679158@[IP of the server/pbx]:5060>;tag=64060e2e
Call-ID: YWJhY2M3ZTU5NTQxZDBhYzg3OWQwOTgzOGIzYjYyZjM.
CSeq: 102 BYE
User-Agent: Asterisk PBX 1.8.11.1-1digium1~squeeze
Proxy-Authorization: Digest username=“0646679158”, realm=“asterisk”, algorithm=MD5, uri=“sip:[IP of the server/pbx]”, nonce="", response="c9a60ff3026109800df9fe8d600e8ca2"
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

david55 · November 15, 2012, 6:38pm

I don’t know what it should do, but it doesn’t seem to have done anything. It might not even be running the a2billing code at all.

Definitely needs to be treated as an a2billing problem.

jsmithx · February 5, 2013, 4:47am

I think you having an issue with 3CXPhone for Windows (“User-Agent: 3CXPhone 6.0.25732.0”).

I also can’t dial or receive calls with it although 3CXPhone for Android is working good in the same LAN.

Don’t have a clue how to solve it…

Topic		Replies	Views
V. 1.8.4 fake ring Asterisk Support	14	1877	August 11, 2011
[HELP] Newbie can't get SIP softphone to call asterisk serve Asterisk Support	11	401	November 2, 2005
Unable to receive incoming calls via SIP Asterisk SIP	12	372	October 10, 2024
How to outbound call Asterisk SIP	8	883	December 7, 2023
PLEASE HELP!- Asterisk hungs up after 2 seconds Asterisk Support	7	825	November 6, 2015

Problem with outbound calls

Related topics