[Asterisk-Users] mgcp transfer takeback with ata186 (logs with
comments - long post)
Pavel Litvinenko
litw at krypton.ru
Mon Oct 20 07:26:55 MST 2003
Florian Overkamp wrote:
> 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
>
that bug_id is a first part of this problem - it does not let you
flip-flop two down channel
but here one channel is up_and_bridged and the second - your not
success dial - it needs to destroy that channel not just mute it ...
it time to open/reopen the ticket
> 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/)
>
> _______________________________________________
> Asterisk-Users mailing list
> Asterisk-Users at lists.digium.com
> http://lists.digium.com/mailman/listinfo/asterisk-users
>
--
----
---------
Best Regards,
Pavel Litvinenko.
ICQ: 16224754
Ph: (8632) 923962, 923640
sip:litw at iptel.org
More information about the asterisk-users
mailing list