I tried to add a couple of SIP phones (polycom 601s) to my existing
asterisk installation. I can successfully make a call from the SIP phone
to any other phone (inside or outside), but I can not make any calls to
a SIP phone. Attached are the pertinent parts of sip.conf and
extensions.conf.
The log starts off normal with:
Mar 26 09:51:15 DEBUG[4885] chan_zap.c: DTMF digit: 2 on Zap/55-1
Mar 26 09:51:15 DEBUG[4885] chan_zap.c: DTMF digit: 0 on Zap/55-1
Mar 26 09:51:15 DEBUG[4885] chan_zap.c: DTMF digit: 1 on Zap/55-1
Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Auto destroying call
'a5306fd4-bcea3062-caa16c03@192.168.3.2'
Mar 26 09:51:18 DEBUG[4885] chan_zap.c: Enabled echo cancellation on
channel 55
Mar 26 09:51:18 VERBOSE[4885] logger.c: -- Executing Goto("Zap/55-1",
"to-sip|201|1") in new stack
Mar 26 09:51:18 VERBOSE[4885] logger.c: -- Goto (to-sip,201,1)
Mar 26 09:51:18 VERBOSE[4885] logger.c: -- Executing Dial("Zap/55-1",
"SIP/201@192.168.2.13|120") in new stack
Mar 26 09:51:18 DEBUG[4885] chan_sip.c: Outgoing Call for 201
Mar 26 09:51:18 VERBOSE[4885] logger.c: -- Called 201@192.168.2.13
Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Acked pending invite 102
Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Stopping retransmission on
'10e2724033eccc6458c1f3cc7d9e1088@192.168.2.13' of Request 102: Match
Found
Mar 26 09:51:18 VERBOSE[3896] logger.c: -- Got SIP response 482 "Loop
Detected" back from 192.168.2.13
Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Hairpin detected, setting up
call forward for what it's worth
Mar 26 09:51:18 VERBOSE[4885] logger.c: -- Now forwarding Zap/55-1 to
'Local/201@from-sip' (thanks to SIP/192.168.2.13-08e24bd0)
Mar 26 09:51:18 DEBUG[4885] chan_sip.c: update_call_counter(201) -
decrement call limit counter
After that it will loop hundreds of times with a block like this in the log:
Mar 26 09:51:18 VERBOSE[4888] logger.c: -- Executing
Goto("Local/201@from-sip-661a,2", "to-sip|201|1") in new
stack
Mar 26 09:51:18 VERBOSE[4888] logger.c: -- Goto (to-sip,201,1)
Mar 26 09:51:18 VERBOSE[4888] logger.c: -- Executing
Dial("Local/201@from-sip-661a,2",
"SIP/201@192.168.2.13|120") in new stack
Mar 26 09:51:18 DEBUG[4888] chan_sip.c: Outgoing Call for 201
Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Failed to grab lock, trying again...
Mar 26 09:51:18 VERBOSE[4888] logger.c: -- Called 201@192.168.2.13
Mar 26 09:51:18 NOTICE[4888] channel.c: Dropping incompatible voice frame on
Local/201@from-sip-661a,2 of format ulaw since our native format has changed to
slin
Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Acked pending invite 102
Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Stopping retransmission on
'4bf4e48d35343cad482650206ce86df0@192.168.2.13' of Request 102: Match
Found
Mar 26 09:51:18 VERBOSE[3896] logger.c: -- Got SIP response 482 "Loop
Detected" back from 192.168.2.13
Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Hairpin detected, setting up call
forward for what it's worth
Mar 26 09:51:18 VERBOSE[4888] logger.c: -- Now forwarding
Local/201@from-sip-661a,2 to 'Local/201@from-sip' (thanks to
SIP/192.168.2.13-08da2240)
Mar 26 09:51:18 DEBUG[4888] chan_sip.c: update_call_counter(201) - decrement
call limit counter
(intertwined two parts, I know, but it's all the same messages)
Eventually, this given:
Mar 26 09:51:20 WARNING[6217] rtp.c: Unable to allocate socket: Too many open
files
Mar 26 09:51:20 WARNING[6217] acl.c: Cannot create socket
Mar 26 09:51:20 WARNING[6217] channel.c: Channel allocation failed: Can't
create alert pipe!
Mar 26 09:51:20 WARNING[6217] chan_sip.c: Unable to allocate SIP channel
structure
Mar 26 09:51:20 NOTICE[6217] app_dial.c: Unable to create channel of type
'SIP' (cause 0 - Unknown)
Mar 26 09:51:20 VERBOSE[6217] logger.c: == Everyone is busy/congested at this
time (1:0/0/1)
Mar 26 09:51:20 DEBUG[6217] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
Mar 26 09:51:20 VERBOSE[6217] logger.c: -- Executing
Playback("Local/201@from-sip-d3ce,2", "tt-allbusy") in new
stack
Mar 26 09:51:20 DEBUG[6217] channel.c: Scheduling timer at 160 sample intervals
Mar 26 09:51:20 VERBOSE[6217] logger.c: -- Playing 'tt-allbusy'
(language 'en')
After that, it will give back a response like this for each loop:
Mar 26 09:51:20 VERBOSE[6214] logger.c: -- Local/201@from-sip-d3ce,1
answered Local/201@from-sip-478c,2
Then finally it will give this block for each loop:
Mar 26 09:51:20 DEBUG[6208] channel.c: Got clone lock for masquerade on
'Local/201@from-sip-d3ce,1' at 0x8de2084
Mar 26 09:51:20 DEBUG[6208] channel.c: Putting channel Local/201@from-sip-d3ce,1
in 64/64 formats
Mar 26 09:51:20 DEBUG[6208] channel.c: Released clone lock on
'Local/201@from-sip-ee33,1<ZOMBIE>'
Mar 26 09:51:20 DEBUG[6208] channel.c: Done Masquerading
Local/201@from-sip-d3ce,1 (6)
Mar 26 09:51:20 DEBUG[6208] channel.c: Planning to masquerade channel
Local/201@from-sip-d3ce,1 into the structure of Local/201@from-sip-5cc0,1
Mar 26 09:51:20 DEBUG[6208] channel.c: Done planning to masquerade channel
Local/201@from-sip-d3ce,1 into the structure of Local/201@from-sip-5cc0,1
Mar 26 09:51:20 DEBUG[6208] chan_local.c: Not posting to queue since already
masked on 'Local/201@from-sip-5cc0,2'
Mar 26 09:51:20 DEBUG[6208] channel.c: Didn't get a frame from channel:
Local/201@from-sip-5cc0,2
Mar 26 09:51:20 DEBUG[6208] channel.c: Bridge stops bridging channels
Local/201@from-sip-5cc0,2 and Local/201@from-sip-5cc0,1<ZOMBIE>
Mar 26 09:51:20 DEBUG[6208] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Mar 26 09:51:20 VERBOSE[6208] logger.c: == Spawn extension (to-sip, 201, 1)
exited non-zero on 'Local/201@from-sip-5cc0,2'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '(null)'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '(null)'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '201'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is 'to-sip'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is
'Local/201@from-sip-5cc0,2'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is
'Local/201@from-sip-ee33,1'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is 'Dial'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is
'SIP/201@192.168.2.13|120'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '2007-03-26
09:51:20'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '2007-03-26
09:51:20'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '2007-03-26
09:51:20'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '0'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '0'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is 'ANSWERED'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is 'DOCUMENTATION'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '(null)'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '1174924280.41882'
Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '(null)'
For a complete log (1.7 mb) of a single call to the extension, see
http://www.actarg.com/all_log
The polycoms are running bootrom 3.2.2.0019 and application version
1.6.7.0098. Any help on this would be greatly appreciated.
Sorry, forgot to attach the sip.conf and extensions.conf files. Attached
now.
-------------- next part --------------
[general]
context=from-sip ; Default context for incoming calls
; if asterisk was compiled with OSP support.
realm=actarg.com ; Realm for digest authentication
; defaults to "asterisk"
; Realms MUST be globally unique according to RFC 3261
; Set this to your host name or domain name
bindport=5060 ; UDP Port to bind to (SIP standard port is 5060)
bindaddr=0.0.0.0 ; IP address to bind to (0.0.0.0 binds to all)
srvlookup=yes ; Enable DNS SRV lookups on outbound calls
; Note: Asterisk only uses the first host
; in SRV records
; Disabling DNS SRV lookups disables the
; ability to place SIP calls based on domain
; names to some other SIP users on the Internet
autodomain=yes ; Turn this on to have Asterisk add local host
; name and local IP to domain list.
; and multiline formatted headers for strict
qualify=yes
disallow=all
allow=ulaw ; dtmfmode=inband only works with ulaw or alaw!
progressinband=no ; Polycom phones don't work properly with
"never"
dtmfmode=rfc2833 ; Choices are inband, rfc2833, or info
nat=no ; there is not NAT between phone and Asterisk
canreinvite=no ; disallow RTP voice traffic to bypass Asterisk
[201]
type=friend ; Friends place calls and receive calls
context=from-sip ; Context for incoming calls from this user
secret=asteriskpassword
host=dynamic ; This peer register with us
callerid=John Doe <201>
[202]
type=friend ; Friends place calls and receive calls
context=from-sip ; Context for incoming calls from this user
secret=asteriskpassword
host=dynamic ; This peer register with us
callerid=Jane Doe <202>
-------------- next part --------------
; from outside T1
[from-ptsn]
exten => s,1,Answer()
include => cac-ext
include => sip-ext
include => intertel-ext
exten => t,1,Playback(vm-goodbye)
exten => t,2,Hangup()
; from sip lines
[from-sip]
include => internal
; generic interal route
[internal]
exten => s,1,Answer()
include => cac-ext
include => sip-ext
include => intertel-ext
include => to-ptsn
; check if extension is to sip
[sip-ext]
exten => _20X,1,Goto(to-sip,${EXTEN},1)
; send call to sip
[to-sip]
exten => _X.,1,Dial(SIP/${EXTEN}@192.168.2.13,120)
exten => _X.,2,Playback(vm-nobodyavail)
exten => _X.,3,Hangup()
exten => _X.,102,Playback(tt-allbusy)
exten => _X.,103,Hangup()
nathan, can you post your extensions.conf file [to-sip], and your sip.conf section for extension 201... ie [201]? it looks like, perhaps, it is a dialplan problem... daveC Nathan Bell wrote:> I tried to add a couple of SIP phones (polycom 601s) to my existing > asterisk installation. I can successfully make a call from the SIP > phone to any other phone (inside or outside), but I can not make any > calls to a SIP phone. Attached are the pertinent parts of sip.conf and > extensions.conf. > > The log starts off normal with: > Mar 26 09:51:15 DEBUG[4885] chan_zap.c: DTMF digit: 2 on Zap/55-1 > Mar 26 09:51:15 DEBUG[4885] chan_zap.c: DTMF digit: 0 on Zap/55-1 > Mar 26 09:51:15 DEBUG[4885] chan_zap.c: DTMF digit: 1 on Zap/55-1 > Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Auto destroying call > 'a5306fd4-bcea3062-caa16c03@192.168.3.2' > Mar 26 09:51:18 DEBUG[4885] chan_zap.c: Enabled echo cancellation on > channel 55 > Mar 26 09:51:18 VERBOSE[4885] logger.c: -- Executing Goto("Zap/55-1", > "to-sip|201|1") in new stack > Mar 26 09:51:18 VERBOSE[4885] logger.c: -- Goto (to-sip,201,1) > Mar 26 09:51:18 VERBOSE[4885] logger.c: -- Executing Dial("Zap/55-1", > "SIP/201@192.168.2.13|120") in new stack > Mar 26 09:51:18 DEBUG[4885] chan_sip.c: Outgoing Call for 201 > Mar 26 09:51:18 VERBOSE[4885] logger.c: -- Called 201@192.168.2.13 > Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Acked pending invite 102 > Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Stopping retransmission on > '10e2724033eccc6458c1f3cc7d9e1088@192.168.2.13' of Request 102: Match > Found > Mar 26 09:51:18 VERBOSE[3896] logger.c: -- Got SIP response 482 "Loop > Detected" back from 192.168.2.13 > Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Hairpin detected, setting up > call forward for what it's worth > Mar 26 09:51:18 VERBOSE[4885] logger.c: -- Now forwarding Zap/55-1 to > 'Local/201@from-sip' (thanks to SIP/192.168.2.13-08e24bd0) > Mar 26 09:51:18 DEBUG[4885] chan_sip.c: update_call_counter(201) - > decrement call limit counter > > After that it will loop hundreds of times with a block like this in > the log: > > Mar 26 09:51:18 VERBOSE[4888] logger.c: -- Executing > Goto("Local/201@from-sip-661a,2", "to-sip|201|1") in new stack > Mar 26 09:51:18 VERBOSE[4888] logger.c: -- Goto (to-sip,201,1) > Mar 26 09:51:18 VERBOSE[4888] logger.c: -- Executing > Dial("Local/201@from-sip-661a,2", "SIP/201@192.168.2.13|120") in new > stack > Mar 26 09:51:18 DEBUG[4888] chan_sip.c: Outgoing Call for 201 > Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Failed to grab lock, trying > again... > Mar 26 09:51:18 VERBOSE[4888] logger.c: -- Called 201@192.168.2.13 > Mar 26 09:51:18 NOTICE[4888] channel.c: Dropping incompatible voice > frame on Local/201@from-sip-661a,2 of format ulaw since our native > format has changed to slin > Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Acked pending invite 102 > Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Stopping retransmission on > '4bf4e48d35343cad482650206ce86df0@192.168.2.13' of Request 102: Match > Found > Mar 26 09:51:18 VERBOSE[3896] logger.c: -- Got SIP response 482 > "Loop Detected" back from 192.168.2.13 > Mar 26 09:51:18 DEBUG[3896] chan_sip.c: Hairpin detected, setting up > call forward for what it's worth > Mar 26 09:51:18 VERBOSE[4888] logger.c: -- Now forwarding > Local/201@from-sip-661a,2 to 'Local/201@from-sip' (thanks to > SIP/192.168.2.13-08da2240) > Mar 26 09:51:18 DEBUG[4888] chan_sip.c: update_call_counter(201) - > decrement call limit counter > > (intertwined two parts, I know, but it's all the same messages) > > Eventually, this given: > > Mar 26 09:51:20 WARNING[6217] rtp.c: Unable to allocate socket: Too > many open files > Mar 26 09:51:20 WARNING[6217] acl.c: Cannot create socket > Mar 26 09:51:20 WARNING[6217] channel.c: Channel allocation failed: > Can't create alert pipe! > Mar 26 09:51:20 WARNING[6217] chan_sip.c: Unable to allocate SIP > channel structure > Mar 26 09:51:20 NOTICE[6217] app_dial.c: Unable to create channel of > type 'SIP' (cause 0 - Unknown) > Mar 26 09:51:20 VERBOSE[6217] logger.c: == Everyone is > busy/congested at this time (1:0/0/1) > Mar 26 09:51:20 DEBUG[6217] app_dial.c: Exiting with > DIALSTATUS=CHANUNAVAIL. > Mar 26 09:51:20 VERBOSE[6217] logger.c: -- Executing > Playback("Local/201@from-sip-d3ce,2", "tt-allbusy") in new stack > Mar 26 09:51:20 DEBUG[6217] channel.c: Scheduling timer at 160 sample > intervals > Mar 26 09:51:20 VERBOSE[6217] logger.c: -- Playing 'tt-allbusy' > (language 'en') > > After that, it will give back a response like this for each loop: > > Mar 26 09:51:20 VERBOSE[6214] logger.c: -- > Local/201@from-sip-d3ce,1 answered Local/201@from-sip-478c,2 > > Then finally it will give this block for each loop: > > Mar 26 09:51:20 DEBUG[6208] channel.c: Got clone lock for masquerade > on 'Local/201@from-sip-d3ce,1' at 0x8de2084 > Mar 26 09:51:20 DEBUG[6208] channel.c: Putting channel > Local/201@from-sip-d3ce,1 in 64/64 formats > Mar 26 09:51:20 DEBUG[6208] channel.c: Released clone lock on > 'Local/201@from-sip-ee33,1<ZOMBIE>' > Mar 26 09:51:20 DEBUG[6208] channel.c: Done Masquerading > Local/201@from-sip-d3ce,1 (6) > Mar 26 09:51:20 DEBUG[6208] channel.c: Planning to masquerade channel > Local/201@from-sip-d3ce,1 into the structure of Local/201@from-sip-5cc0,1 > Mar 26 09:51:20 DEBUG[6208] channel.c: Done planning to masquerade > channel Local/201@from-sip-d3ce,1 into the structure of > Local/201@from-sip-5cc0,1 > Mar 26 09:51:20 DEBUG[6208] chan_local.c: Not posting to queue since > already masked on 'Local/201@from-sip-5cc0,2' > Mar 26 09:51:20 DEBUG[6208] channel.c: Didn't get a frame from > channel: Local/201@from-sip-5cc0,2 > Mar 26 09:51:20 DEBUG[6208] channel.c: Bridge stops bridging channels > Local/201@from-sip-5cc0,2 and Local/201@from-sip-5cc0,1<ZOMBIE> > Mar 26 09:51:20 DEBUG[6208] app_dial.c: Exiting with DIALSTATUS=ANSWER. > Mar 26 09:51:20 VERBOSE[6208] logger.c: == Spawn extension (to-sip, > 201, 1) exited non-zero on 'Local/201@from-sip-5cc0,2' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '(null)' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '(null)' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '201' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is 'to-sip' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is > 'Local/201@from-sip-5cc0,2' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is > 'Local/201@from-sip-ee33,1' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is 'Dial' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is > 'SIP/201@192.168.2.13|120' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '2007-03-26 > 09:51:20' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '2007-03-26 > 09:51:20' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '2007-03-26 > 09:51:20' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '0' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '0' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is 'ANSWERED' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is 'DOCUMENTATION' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '(null)' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '1174924280.41882' > Mar 26 09:51:20 DEBUG[6208] pbx.c: Function result is '(null)' > > For a complete log (1.7 mb) of a single call to the extension, see > http://www.actarg.com/all_log > > The polycoms are running bootrom 3.2.2.0019 and application version > 1.6.7.0098. Any help on this would be greatly appreciated. > _______________________________________________ > --Bandwidth and Colocation provided by Easynews.com -- > > asterisk-users mailing list > To UNSUBSCRIBE or update options visit: > http://lists.digium.com/mailman/listinfo/asterisk-users > > >-- Building Strong Relationships w/ Intelligent Customer Service -- Interlocking Business Solutions, LLC 856-380-0894 x5000