[Asterisk-Users] mgcp transfer takeback with ata186 (logs with comments - long
post)
Florian Overkamp
florian at obsimref.com
Mon Oct 20 00:59:59 MST 2003
Hi,
in following of a recent discussion I got to work on MGCP with the Cisco
ATA186 again, and got it to work very nicely. However, there is a little
thing with transfers I would like to get comments on:
Call comes in from PSTN and goes to an ATA186 (MGCP)
Call is answered and then, using flash, transferred to another extension
If the extension is available, there can be an announcement and the call
may be transferred by hanging up
If the extension is not available, it seems to be erratic to take the call
back. Hitting flash again sometimes gives another dialtone.
I realised this may be related to:
http://bugs.digium.com/bug_view_page.php?bug_id=0000129
Can anyone explain to me how all this should be used, for reference ? I can
also imagine I'm doing something wrong in the transfer process ?
I intend to hit this into the bugtracker when I get some more logs and a
better feeling for wether or not its actually a bug, but I'm curious to see
if anyone else saw this.
Here are some scenario's..
This one is a succesfully completed transfer (but notice the WARNING's):
-- Accepting AUTHENTICATED call from 217.114.97.249, requested format
= 8, actual format = 8
-- Executing Dial("IAX2[virtupbx at virtupbx]/16384", "Local/7001 at pbx")
in new stack
-- Called 7001 at pbx
-- Executing Dial("Local/7001 at pbx-0685,2",
"MGCP/aaln/1 at 217.114.96.220") in new stack
-- MGCP mgcp_request(aaln/1 at 217.114.96.220)
-- MGCP cw: 0, dnd: 0, so: 0, sno: 0
-- MGCP mgcp_new(MGCP/aaln/1 at 217.114.96.220-0) created in state: Down
-- Called aaln/1 at 217.114.96.220
-- MGCP/aaln/1 at 217.114.96.220-0 is ringing
-- Local/7001 at pbx-0685,1 is ringing
-- Endpoint 'aaln/1 at 217.114.96.220-0' observed 'hd'
-- MGCP/aaln/1 at 217.114.96.220-0 answered Local/7001 at pbx-0685,2
-- Local/7001 at pbx-0685,1 stopped sounds
-- Local/7001 at pbx-0685,1 answered IAX2[virtupbx at virtupbx]/16384
== Spawn extension (from-pstn, 537503051, 1) exited non-zero on
'Local/7001 at pbx-0685,2<ZOMBIE>'
-- Endpoint 'aaln/1 at 217.114.96.220-0' observed 'hf'
-- Swapping 0 for 1 on aaln/1 at 217.114.96.220
-- MGCP Muting 0 on aaln/1 at 217.114.96.220
-- Started music on hold, class 'default', on
IAX2[virtupbx at virtupbx]/16384
-- MGCP mgcp_new(MGCP/aaln/1 at 217.114.96.220-1) created in state: Down
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed '7'
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed '0'
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed '0'
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed '2'
-- Executing Dial("MGCP/aaln/1 at 217.114.96.220-1",
"MGCP/aaln/2 at 217.114.96.220") in new stack
-- MGCP mgcp_request(aaln/2 at 217.114.96.220)
-- MGCP cw: 0, dnd: 0, so: 0, sno: 0
-- MGCP mgcp_new(MGCP/aaln/2 at 217.114.96.220-1) created in state: Down
-- Called aaln/2 at 217.114.96.220
-- MGCP/aaln/2 at 217.114.96.220-1 is ringing
-- Endpoint 'aaln/2 at 217.114.96.220-1' observed 'hd'
-- MGCP/aaln/2 at 217.114.96.220-1 answered MGCP/aaln/1 at 217.114.96.220-1
-- MGCP mgcp_answer(MGCP/aaln/1 at 217.114.96.220-1) on
aaln/1 at 217.114.96.220-1
-- Attempting native bridge of MGCP/aaln/1 at 217.114.96.220-1 and
MGCP/aaln/2 at 217.114.96.220-1
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed 'hu'
-- Stopped music on hold on IAX2[virtupbx at virtupbx]/16384
NOTICE[46109]: File chan_mgcp.c, Line 775 (mgcp_fixup):
mgcp_fixup(MGCP/aaln/2 at 217.114.96.220-1, MGCP/aaln/2 at 217.114.96.220-1<MASQ>)
WARNING[46109]: File chan_mgcp.c, Line 777 (mgcp_fixup): old channel wasn't
0x8134958 but was (nil)
WARNING[46109]: File channel.c, Line 2011 (ast_do_masquerade): Fixup failed
on channel MGCP/aaln/2 at 217.114.96.220-1<MASQ>, strange things may happen.
NOTICE[46109]: File chan_mgcp.c, Line 775 (mgcp_fixup):
mgcp_fixup(MGCP/aaln/1 at 217.114.96.220-0<ZOMBIE>, MGCP/aaln/2 at 217.114.96.220-1)
-- Endpoint 'aaln/2 at 217.114.96.220-1' observed 'hu'
== Spawn extension (pbx, 7001, 1) exited non-zero on
'IAX2[virtupbx at virtupbx]/16384'
-- Hungup 'IAX2[virtupbx at virtupbx]/16384'
By the way: After this, the channel does remains unavailable, even though
all phones are on-hook (a show channels shows the MGCP line to be active
(not shown here). (You could conclude after analysing this that the MGCP
channel has not got a 'Spawn extension <foo> exited non-zero' line)
Here is an uncompleted transfer:
-- Accepting AUTHENTICATED call from 217.114.97.249, requested format
= 8, actual format = 8
-- Executing Dial("IAX2[virtupbx at virtupbx]/16384", "Local/7001 at pbx")
in new stack
-- Executing Dial("Local/7001 at pbx-226b,2",
"MGCP/aaln/1 at 217.114.96.220") in new stack
-- MGCP mgcp_request(aaln/1 at 217.114.96.220)
-- MGCP cw: 0, dnd: 0, so: 0, sno: 0
-- MGCP mgcp_new(MGCP/aaln/1 at 217.114.96.220-1) created in state: Down
-- Called aaln/1 at 217.114.96.220
-- MGCP/aaln/1 at 217.114.96.220-1 is ringing
-- Called 7001 at pbx
-- Local/7001 at pbx-226b,1 is ringing
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed 'hd'
-- MGCP/aaln/1 at 217.114.96.220-1 answered Local/7001 at pbx-226b,2
-- Local/7001 at pbx-226b,1 stopped sounds
-- Local/7001 at pbx-226b,1 answered IAX2[virtupbx at virtupbx]/16384
== Spawn extension (from-pstn, 537503051, 1) exited non-zero on
'Local/7001 at pbx-226b,2<ZOMBIE>'
-- Endpoint 'aaln/2 at 217.114.96.220-1' observed 'hd'
-- MGCP mgcp_new(MGCP/aaln/2 at 217.114.96.220-1) created in state: Down
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed 'hf'
-- Swapping 1 for 0 on aaln/1 at 217.114.96.220
-- MGCP Muting 1 on aaln/1 at 217.114.96.220
-- Started music on hold, class 'default', on
IAX2[virtupbx at virtupbx]/16384
-- MGCP mgcp_new(MGCP/aaln/1 at 217.114.96.220-0) created in state: Down
-- Endpoint 'aaln/1 at 217.114.96.220-0' observed '7'
-- Endpoint 'aaln/1 at 217.114.96.220-0' observed '0'
-- Endpoint 'aaln/1 at 217.114.96.220-0' observed '0'
-- Endpoint 'aaln/1 at 217.114.96.220-0' observed '2'
-- Executing Dial("MGCP/aaln/1 at 217.114.96.220-0",
"MGCP/aaln/2 at 217.114.96.220") in new stack
-- MGCP mgcp_request(aaln/2 at 217.114.96.220)
-- MGCP cw: 0, dnd: 0, so: 1, sno: 0
NOTICE[18450]: File app_dial.c, Line 502 (dial_exec): Unable to create
channel of type 'MGCP'
== Everyone is busy at this time
-- Timeout on MGCP/aaln/1 at 217.114.96.220-0
== CDR updated on MGCP/aaln/1 at 217.114.96.220-0
-- Executing Busy("MGCP/aaln/1 at 217.114.96.220-0", "") in new stack
-- Endpoint 'aaln/1 at 217.114.96.220-0' observed 'hf'
-- Swapping 0 for 1 on aaln/1 at 217.114.96.220
-- We didn't make one of the calls FLIPFLOP 0 and 1 on
aaln/1 at 217.114.96.220
-- MGCP Muting 0 on aaln/1 at 217.114.96.220
-- Stopped music on hold on IAX2[virtupbx at virtupbx]/16384
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed 'hu'
NOTICE[18450]: File chan_mgcp.c, Line 775 (mgcp_fixup):
mgcp_fixup(IAX2[virtupbx at virtupbx]/16384, IAX2[virtupbx at virtupbx]/16384<MASQ>)
WARNING[18450]: File chan_mgcp.c, Line 777 (mgcp_fixup): old channel wasn't
0x813a710 but was (nil)
WARNING[18450]: File channel.c, Line 2011 (ast_do_masquerade): Fixup failed
on channel IAX2[virtupbx at virtupbx]/16384<MASQ>, strange things may happen.
== Spawn extension (pbx, 7001, 1) exited non-zero on
'MGCP/aaln/1 at 217.114.96.220-0<ZOMBIE>'
-- Endpoint 'aaln/2 at 217.114.96.220-1' observed 'hu'
-- MGCP handle_request(aaln/2 at 217.114.96.220-1) ast_channel already
destroyed
-- MGCP handle_request(aaln/2 at 217.114.96.220) set vmwi(-)
*CLI> show channels
Channel (Context Extension Pri ) State Appl. Data
IAX2[virtupbx at virtupbx]/16384 (pbx t 1 ) Up
Busy (Empty)
1 active channel(s)
Hmm, in this case you can see aaln/2 being picked up so as to give a busy
tone during the transfer. This works, and I am able to hit flash again to
resume the original call. However, after hanging up the IAX channel
(inbound call) is not disconnected.
To show my incapability, here's another log of me trying to transfer
_again_ after the first one failed:
-- Accepting AUTHENTICATED call from 217.114.97.249, requested format
= 8, actual format = 8
-- Executing Dial("IAX2[virtupbx at virtupbx]/16384", "Local/7001 at pbx")
in new stack
-- Called 7001 at pbx
-- Executing Dial("Local/7001 at pbx-2100,2",
"MGCP/aaln/1 at 217.114.96.220") in new stack
-- MGCP mgcp_request(aaln/1 at 217.114.96.220)
-- MGCP cw: 0, dnd: 0, so: 0, sno: 0
-- MGCP mgcp_new(MGCP/aaln/1 at 217.114.96.220-0) created in state: Down
-- Called aaln/1 at 217.114.96.220
-- MGCP/aaln/1 at 217.114.96.220-0 is ringing
-- Local/7001 at pbx-2100,1 is ringing
-- Endpoint 'aaln/1 at 217.114.96.220-0' observed 'hd'
-- MGCP/aaln/1 at 217.114.96.220-0 answered Local/7001 at pbx-2100,2
-- Local/7001 at pbx-2100,1 stopped sounds
-- Local/7001 at pbx-2100,1 answered IAX2[virtupbx at virtupbx]/16384
== Spawn extension (from-pstn, 537503051, 1) exited non-zero on
'Local/7001 at pbx-2100,2<ZOMBIE>'
-- Endpoint 'aaln/2 at 217.114.96.220-1' observed 'hd'
-- MGCP mgcp_new(MGCP/aaln/2 at 217.114.96.220-1) created in state: Down
-- Endpoint 'aaln/1 at 217.114.96.220-0' observed 'hf'
-- Swapping 0 for 1 on aaln/1 at 217.114.96.220
-- MGCP Muting 0 on aaln/1 at 217.114.96.220
-- Started music on hold, class 'default', on
IAX2[virtupbx at virtupbx]/16384
-- MGCP mgcp_new(MGCP/aaln/1 at 217.114.96.220-1) created in state: Down
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed '7'
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed '0'
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed '0'
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed '2'
-- Executing Dial("MGCP/aaln/1 at 217.114.96.220-1",
"MGCP/aaln/2 at 217.114.96.220") in new stack
-- MGCP mgcp_request(aaln/2 at 217.114.96.220)
-- MGCP cw: 0, dnd: 0, so: 1, sno: 0
NOTICE[28694]: File app_dial.c, Line 502 (dial_exec): Unable to create
channel of type 'MGCP'
== Everyone is busy at this time
-- Timeout on MGCP/aaln/1 at 217.114.96.220-1
== CDR updated on MGCP/aaln/1 at 217.114.96.220-1
-- Executing Busy("MGCP/aaln/1 at 217.114.96.220-1", "") in new stack
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed 'hf'
-- Swapping 1 for 0 on aaln/1 at 217.114.96.220
-- We didn't make one of the calls FLIPFLOP 1 and 0 on
aaln/1 at 217.114.96.220
-- MGCP Muting 1 on aaln/1 at 217.114.96.220
-- Stopped music on hold on IAX2[virtupbx at virtupbx]/16384
-- Endpoint 'aaln/2 at 217.114.96.220-1' observed 'hu'
-- MGCP handle_request(aaln/2 at 217.114.96.220-1) ast_channel already
destroyed
-- MGCP handle_request(aaln/2 at 217.114.96.220) set vmwi(-)
-- Endpoint 'aaln/1 at 217.114.96.220-0' observed 'hf'
-- Swapping 0 for 1 on aaln/1 at 217.114.96.220
-- We didn't make one of the calls FLIPFLOP 0 and 1 on
aaln/1 at 217.114.96.220
-- MGCP Muting 0 on aaln/1 at 217.114.96.220
-- Started music on hold, class 'default', on
IAX2[virtupbx at virtupbx]/16384
WARNING[7176]: File chan_mgcp.c, Line 2123 (handle_hd_hf): Off hook, but
alreaedy have owner on aaln/1 at 217.114.96.220
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed '7'
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed '0'
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed '0'
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed '2'
-- Endpoint 'aaln/1 at 217.114.96.220-1' observed 'hf'
-- Swapping 1 for 0 on aaln/1 at 217.114.96.220
-- We didn't make one of the calls FLIPFLOP 1 and 0 on
aaln/1 at 217.114.96.220
-- MGCP Muting 1 on aaln/1 at 217.114.96.220
-- Stopped music on hold on IAX2[virtupbx at virtupbx]/16384
show channels
Channel (Context Extension Pri ) State Appl. Data
MGCP/aaln/1 at 217.114.96.220-1 (pbx t 1 ) Ring
Busy (Empty)
MGCP/aaln/1 at 217.114.96.220-0 (pbx 1 ) Up
Bridged Call IAX2[virtupbx at virtupbx]/16384
IAX2[virtupbx at virtupbx]/16384 (pbx 7001 1 ) Up
Dial MGCP/aaln/1 at 217.114.96.220
3 active channel(s)
-- Endpoint 'aaln/1 at 217.114.96.220-0' observed 'hu'
NOTICE[28694]: File chan_mgcp.c, Line 775 (mgcp_fixup):
mgcp_fixup(IAX2[virtupbx at virtupbx]/16384, IAX2[virtupbx at virtupbx]/16384<MASQ>)
WARNING[28694]: File chan_mgcp.c, Line 777 (mgcp_fixup): old channel wasn't
0x81245b8 but was (nil)
WARNING[28694]: File channel.c, Line 2011 (ast_do_masquerade): Fixup failed
on channel IAX2[virtupbx at virtupbx]/16384<MASQ>, strange things may happen.
== Spawn extension (pbx, t, 1) exited non-zero on
'IAX2[virtupbx at virtupbx]/16384'
-- Hungup 'IAX2[virtupbx at virtupbx]/16384'
Now, this is definitely wrong, both MGCP lines seem active but I can only
toggle back to the call: The second transfer never actually goes...
What happened ?
Met vriendelijke groet,
Florian Overkamp
ObSimRef BV (http://www.obsimref.com/)
More information about the asterisk-users
mailing list