Nobody any idea?
It would be really helpful,
Markus
Am 06.01.2017 um 12:07 schrieb Markus Weiler:
Hi List,
we're calling a sip phone from our Asterisk Server, and try to add logic
depending on the dialstatus
Stripped down example;
exten = 494XXXXXXXXX,n,Dial(SIP/4120089,15,w)
exten = 494XXXXXXXXX,n,Goto(98-${DIALSTATUS},1)
exten = 494XXXXXXXXX,n,Hangup()
.....
exten = 98-BUSY,1,NoOp(Busy)
exten = 98-BUSY,n,ExecIf($["${Voicemail}" =
"1"]?Playback(/home/4120/mitarbeiter/ab))
....
exten = 98-NOANSWER,1,NoOp(noanswer)
exten = 98-NOANSWER,n,ExecIf($["${Voicemail}" =
"1"]?Playback(/home/4120/mitarbeiter/ab))
....
Íf the phone call times out, the call is sent to 98-NOANSWER and then
answered as expected.
If the User presses DND on his phone the call is sent to 98-BUSY which
is identical but then the call is hung up. This behaviour is
unexpected/unwanted.
We tried to figure out what the difference is and think it's how
Asterisk handles the "480 Do Not Disturb" from the phone
(xxx.xxx.xxx.xxx).
It is passed to our main incoming server (zzz.zzz.zzz.zzz) as "181 call
is being forwarded".
Is this a bug or a feature? :-) How could we handle this correctly?
SIP and Asterisk debug log below. Any help would be appreciated!
Markus
SIP:
#
U 2017/01/06 11:38:29.515836 xxx.xxx.xxx.xxx:45731 ->
yyy.yyy.yyy.yy:5060
SIP/2.0 480 Do Not Disturb.
v: SIP/2.0/UDP yyy.yyy.yyy.yy:5060;branch=z9hG4bK749dbc68;rport=5060.
f: "0160XXXXXXX" <sip:0160xxxx...@yyy.yyy.yyy.yy>;tag=as4ef364e1.
t: <sip:4120089@192.168.178.70:45731;line=8lln9qsq>;tag=0380h4r478.
i: 7568eb9e7c148e535166a89702423...@yyy.yyy.yyy.yy:5060.
CSeq: 102 INVITE.
User-Agent: snom760/8.7.5.13.
m: <sip:4120089@192.168.178.70:45731;line=8lln9qsq>;reg-id=1.
l: 0.
.
#
U 2017/01/06 11:38:29.516045 yyy.yyy.yyy.yy:5060 ->
xxx.xxx.xxx.xxx:45731
ACK sip:4120089@192.168.178.70:45731;line=8lln9qsq SIP/2.0.
Via: SIP/2.0/UDP yyy.yyy.yyy.yy:5060;branch=z9hG4bK749dbc68;rport.
Max-Forwards: 70.
From: "0160XXXXXXX" <sip:0160xxxx...@yyy.yyy.yyy.yy>;tag=as4ef364e1.
To: <sip:4120089@192.168.178.70:45731;line=8lln9qsq>;tag=0380h4r478.
Contact: <sip:0160xxxx...@yyy.yyy.yyy.yy:5060>.
Call-ID: 7568eb9e7c148e535166a89702423...@yyy.yyy.yyy.yy:5060.
CSeq: 102 ACK.
User-Agent: Asterisk PBX 13.12.1.
Content-Length: 0.
.
#
U 2017/01/06 11:38:29.516166 yyy.yyy.yyy.yy:5060 -> zzz.zzz.zzz.zzz:5060
SIP/2.0 181 Call is being forwarded.
Via: SIP/2.0/UDP
zzz.zzz.zzz.zzz;branch=z9hG4bK120a.dcdd311bf80a9536d4eec1ce380f66a7.0;received=zzz.zzz.zzz.zzz.
Via: SIP/2.0/UDP 93.189.169.102:5060;branch=z9hG4bK4ec14865.
Record-Route: <sip:zzz.zzz.zzz.zzz;lr=on;ftag=as47cd4bd4>.
From: "49160XXXXXXX" <sip:49160XXXXXXX@93.189.169.102>;tag=as47cd4bd4.
To: <sip:494xxxxxx...@zzz.zzz.zzz.zzz>;tag=as0823beee.
Call-ID: 15f8ee0e657ba8687db29cff0093c95b@93.189.169.102:5060.
CSeq: 102 INVITE.
Server: Asterisk PBX 13.12.1.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY,
INFO, PUBLISH, MESSAGE.
Supported: replaces, timer.
Session-Expires: 1800;refresher=uas.
Contact: <sip:494xxxxxx...@yyy.yyy.yyy.yy:5060>.
Content-Length: 0.
.
Asterisk Debug:
[Jan 6 11:38:29] VERBOSE[5383][C-000473c5] pbx.c: Executing
[494XXXXXXXXX@4120:7] Dial("SIP/SER_IB-0004cd6d", "SIP/4120089,15,w") in
new stack
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Asked to create a
SIP channel with formats: (alaw)
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Allocating new SIP
dialog for 0dac947057f4ddc613b1391948770...@yyy.yyy.yyy.yy:5060 - INVITE
(No RTP)
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] rtp_engine.c: Using engine
'asterisk' for RTP instance '0x7fae14073678'
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] res_rtp_asterisk.c: Allocated
port 14098 for RTP instance '0x7fae14073678'
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] rtp_engine.c: RTP instance
'0x7fae14073678' is setup and ready to go
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] acl.c: Not an IPv4 nor IPv6
address, cannot get port.
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] netsock2.c: Splitting 'pbx6'
into...
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] netsock2.c: ...host 'pbx6' and
port ''.
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] res_rtp_asterisk.c: Setup RTCP
on RTP instance '0x7fae14073678'
[Jan 6 11:38:29] VERBOSE[5383][C-000473c5] netsock2.c: Using SIP RTP
TOS bits 184
[Jan 6 11:38:29] VERBOSE[5383][C-000473c5] netsock2.c: Using SIP RTP
CoS mark 5
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Setting NAT on RTP
to On
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] acl.c: For destination
'xxx.xxx.xxx.xxx', our source address is 'yyy.yyy.yyy.yy'.
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Setting
AST_TRANSPORT_UDP with address yyy.yyy.yyy.yy:5060
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Setting NAT on RTP
to On
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: SIP call-id
changed from '0dac947057f4ddc613b1391948770...@yyy.yyy.yyy.yy:5060' to
'7568eb9e7c148e535166a89702423...@yyy.yyy.yyy.yy:5060'
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: *** Our native
formats are (alaw)
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: *** Joint
capabilities are (alaw)
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: *** Our
capabilities are (alaw|ulaw|gsm)
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: ***
AST_CODEC_CHOOSE formats are alaw
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: *** Our preferred
formats from the incoming channel are (alaw)
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: This channel will
not be able to handle video.
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] channel_internal_api.c:
Channel Call ID changing from [C-000473c5] to [C-000473c5]
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Outgoing Call for
4120089
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Updating call
counter for outgoing call
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: ** Our capability:
(alaw|ulaw|gsm) Video flag: False Text flag: False
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: ** Our prefcodec:
(alaw)
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: -- Done with
adding codecs to SDP
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Done building SDP.
Settling with this capability: (alaw|ulaw|gsm)
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Initializing
initreq for method INVITE - callid
7568eb9e7c148e535166a89702423...@yyy.yyy.yyy.yy:5060
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Trying to put
'INVITE sip:' onto UDP socket destined for xxx.xxx.xxx.xxx:45731
[Jan 6 11:38:29] VERBOSE[5383][C-000473c5] app_dial.c: Called
SIP/4120089
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] chan_sip.c: (Provisional)
Stopping retransmission (but retaining packet) on
'7568eb9e7c148e535166a89702423...@yyy.yyy.yyy.yy:5060' Request 102:
Found
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] chan_sip.c: SIP response 100
to standard invite
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] chan_sip.c: Acked pending
invite 102
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] chan_sip.c: Stopping
retransmission on '7568eb9e7c148e535166a89702423...@yyy.yyy.yyy.yy:5060'
of Request 102: Match Found
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] chan_sip.c: SIP response 480
to standard invite
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] chan_sip.c: Trying to put
'ACK sip:412' onto UDP socket destined for xxx.xxx.xxx.xxx:45731
[Jan 6 11:38:29] VERBOSE[5383][C-000473c5] app_dial.c:
SIP/4120089-0004cd6e redirecting info has changed, passing it to
SIP/SER_IB-0004cd6d
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Trying to put
'SIP/2.0 181' onto UDP socket destined for zzz.zzz.zzz.zzz:5060
[Jan 6 11:38:29] VERBOSE[5383][C-000473c5] app_dial.c:
SIP/4120089-0004cd6e is busy
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] channel.c: Hanging up channel
'SIP/4120089-0004cd6e'
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Hangup call
SIP/4120089-0004cd6e, SIP callid
7568eb9e7c148e535166a89702423...@yyy.yyy.yyy.yy:5060
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Updating call
counter for outgoing call
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] res_rtp_asterisk.c: Setting
RTCP address on RTP instance '0x7fae14073678'
[Jan 6 11:38:29] VERBOSE[5383][C-000473c5] app_dial.c: Everyone is
busy/congested at this time (1:1/0/0)
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] app_dial.c: Exiting with
DIALSTATUS=BUSY.
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] pbx_variables.c: Result of
'DIALSTATUS' is 'BUSY'
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] pbx.c: Launching 'Goto'
[Jan 6 11:38:29] VERBOSE[5383][C-000473c5] pbx.c: Executing
[494XXXXXXXXX@4120:8] Goto("SIP/SER_IB-0004cd6d", "98-BUSY,1") in new
stack
[Jan 6 11:38:29] VERBOSE[5383][C-000473c5] pbx_builtins.c: Goto
(4120,98-BUSY,1)
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] pbx.c: Launching 'NoOp'
[Jan 6 11:38:29] VERBOSE[5383][C-000473c5] pbx.c: Executing
[98-BUSY@4120:1] NoOp("SIP/SER_IB-0004cd6d", "Busy") in new stack
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] pbx_variables.c: Result of
'Voicemail' is '1'
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] pbx_variables.c: Expression
result is '1'
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] pbx.c: Launching 'ExecIf'
[Jan 6 11:38:29] VERBOSE[5383][C-000473c5] pbx.c: Executing
[98-BUSY@4120:2] ExecIf("SIP/SER_IB-0004cd6d",
"1?Playback(/home/4120/mitarbeiter/ab)") in new stack
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: SIP answering
channel: SIP/SER_IB-0004cd6d
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] res_rtp_asterisk.c: Setting
the marker bit due to a source update
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: ** Our capability:
(alaw|ulaw|gsm) Video flag: True Text flag: True
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: ** Our prefcodec:
(nothing)
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: -- Done with
adding codecs to SDP
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Setting framing on
incoming call: 0
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Done building SDP.
Settling with this capability: (alaw|ulaw|gsm)
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] chan_sip.c: Trying to put
'SIP/2.0 200' onto UDP socket destined for zzz.zzz.zzz.zzz:5060
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] chan_sip.c: **** Received ACK
(6) - Command in SIP ACK
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] chan_sip.c: Stopping
retransmission on '15f8ee0e657ba8687db29cff0093c95b@93.189.169.102:5060'
of Response 102: Match Found
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] chan_sip.c: **** Received BYE
(8) - Command in SIP BYE
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] netsock2.c: Splitting
'zzz.zzz.zzz.zzz' into...
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] netsock2.c: ...host
'zzz.zzz.zzz.zzz' and port ''.
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] chan_sip.c: Setting
SIP_ALREADYGONE on dialog
15f8ee0e657ba8687db29cff0093c...@zzz.zzz.zzz.zzz:5060
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] res_rtp_asterisk.c: Setting
RTCP address on RTP instance '0x7fae95307ec8'
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] chan_sip.c: Received bye,
issuing owner hangup
[Jan 6 11:38:29] DEBUG[28758][C-000473c5] chan_sip.c: Trying to put
'SIP/2.0 200' onto UDP socket destined for zzz.zzz.zzz.zzz:5060
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] channel.c: Hangup of channel
SIP/SER_IB-0004cd6d detected in answer routine
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] pbx.c: Spawn extension
(4120,98-BUSY,2) exited non-zero on 'SIP/SER_IB-0004cd6d'
[Jan 6 11:38:29] VERBOSE[5383][C-000473c5] pbx.c: Spawn extension
(4120, 98-BUSY, 2) exited non-zero on 'SIP/SER_IB-0004cd6d'
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] channel.c: Soft-Hanging (0x10)
up channel 'SIP/SER_IB-0004cd6d'
[Jan 6 11:38:29] DEBUG[5383][C-000473c5] channel.c: Soft-Hanging (0x80)
up channel 'SIP/SER_IB-0004cd6d'
--
_____________________________________________________________________
-- Bandwidth and Colocation Provided by http://www.api-digital.com --
Check out the new Asterisk community forum at: https://community.asterisk.org/
New to Asterisk? Start here:
https://wiki.asterisk.org/wiki/display/AST/Getting+Started
asterisk-users mailing list
To UNSUBSCRIBE or update options visit:
http://lists.digium.com/mailman/listinfo/asterisk-users
