[asterisk-dev] Trouble with originating a call through Asterisk Manager Interface

[eric weaver]

I am doing a little application to originate a call through Asterisk via AMI
(Perl Asterisk::Manager).
It logs in successfully, does an originate command with
Exten: 0020 (which is set up to answer and wait for 60 then hang up)
Channel: SIP/5101234567 at test-host  (which comes to my desktop machine also
running Asterisk).

At the target machine I see only a CANCEL to which it immediately responds
with a No Transaction.

It looks like AstMan is asking for a Slin connection and the channel is set
up only for Ulaw.  Don't know if that's a red herring.
Any advice welcome.

The debug log:
[Jul 12 11:31:16] DEBUG[11317] manager.c: Manager received command
'Challenge'
[Jul 12 11:31:16] DEBUG[11317] manager.c: Manager received command 'Login'
[Jul 12 11:31:16] DEBUG[11317] config.c: Parsing /etc/asterisk/manager.conf
[Jul 12 11:31:16] DEBUG[11317] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to
acl for peer
[Jul 12 11:31:16] DEBUG[11317] acl.c:
127.0.0.1/255.255.255.255/255.255.255.255 appended to acl for peer
[Jul 12 11:31:16] DEBUG[11317] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
[Jul 12 11:31:16] DEBUG[11317] acl.c: ##### Testing 127.0.0.1 with 127.0.0.1
[Jul 12 11:31:16] DEBUG[11317] manager.c: Manager received command
'Originate'
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: Asked to create a SIP channel
with formats: 0x40 (slin)
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: Allocating new SIP dialog for (No
Call-ID) - INVITE (With RTP)
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: Setting NAT on RTP to Off
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: *** Our native formats are 0x4
(ulaw)
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: *** Joint capabilities are 0x0
(nothing)
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: *** Our capabilities are 0x44
(ulaw|slin)
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: *** AST_CODEC_CHOOSE formats are
0x4 (ulaw)
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: *** Our preferred formats from
the incoming channel are 0x40 (slin)
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: This channel will not be able to
handle video.
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: Outgoing Call for 5101234567
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: Updating call counter for
outgoing call
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: Our T38 capability (0), joint T38
capability (0)
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: ** Our capability: 0x44
(ulaw|slin) Video flag: False
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: ** Our prefcodec: 0x40 (slin)
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: -- Done with adding codecs to SDP
[Jul 12 11:31:16] DEBUG[11317] channel.c: Internal timing is disabled
(option_internal_timing=0 chan->timingfd=-1)
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: Done building SDP. Settling with
this capability: 0x44 (ulaw|slin)
[Jul 12 11:31:16] DEBUG[11317] channel.c: Hanging up channel
'SIP/sip-flat5th-081d0500'
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: Hangup call
SIP/sip-flat5th-081d0500, SIP callid
30d8df253ccd7e0a5725087117c688ec at 192.168.253.35)
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: Hanging up channel in state Down
(not UP)
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: Acked pending invite 102
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: Stopping retransmission on '
30d8df253ccd7e0a5725087117c688ec at 192.168.253.35' of Request 102: Match Found
[Jul 12 11:31:16] DEBUG[11317] chan_sip.c: Updating call counter for
outgoing call
[Jul 12 11:31:16] DEBUG[11317] devicestate.c: Notification of state change
to be queued on device/channel SIP/sip-flat5th
[Jul 12 11:31:16] DEBUG[11317] devicestate.c: Notification of state change
to be queued on device/channel
[Jul 12 11:31:16] DEBUG[11290] devicestate.c: No provider found, checking
channel drivers for SIP - sip-flat5th
[Jul 12 11:31:16] DEBUG[11290] chan_sip.c: Checking device state for peer
sip-flat5th
[Jul 12 11:31:16] DEBUG[11290] devicestate.c: Changing state for
SIP/sip-flat5th - state 1 (Not in use)
[Jul 12 11:31:16] DEBUG[11290] devicestate.c: Checking if I can find
provider for "" - number: (null)
[Jul 12 11:31:16] DEBUG[11290] devicestate.c: Checking provider Park with
[Jul 12 11:31:16] DEBUG[11290] devicestate.c: Changing state for  - state 4
(Invalid)
[Jul 12 11:31:16] DEBUG[11314] app_queue.c: Device 'SIP/sip-flat5th' changed
to state '1' (Not in use) but we don't care because they're not a member of
any queue.
[Jul 12 11:31:16] DEBUG[11313] chan_sip.c: = Found Their Call ID:
30d8df253ccd7e0a5725087117c688ec at 192.168.253.35 Their Tag  Our tag:
as55af6a38
[Jul 12 11:31:16] DEBUG[11313] chan_sip.c: Stopping retransmission on '
30d8df253ccd7e0a5725087117c688ec at 192.168.253.35' of Request 102: Match Found
[Jul 12 11:31:48] DEBUG[11313] chan_sip.c: Auto destroying SIP dialog '
30d8df253ccd7e0a5725087117c688ec at 192.168.253.35'
[Jul 12 11:31:48] DEBUG[11313] chan_sip.c: Destroying SIP dialog
30d8df253ccd7e0a5725087117c688ec at 192.168.253.35
--
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.digium.com/pipermail/asterisk-dev/attachments/20090712/053c56ce/attachment.htm