[asterisk-users] Problems with supervised transfer and agents

Ivan Cetta icetta at gmail.com
Mon Jul 31 10:14:24 MST 2006


Hi list.
    We are having some strange behavior with supervised transfers made by
agents. If a call who came from a queue to an agent wants to be supervised
transfer to another exten, if the other exten dont't answer the phone, i
lost the call.

Here is a simple log of the behavior with the explanation.  8702 call to the
queue (8820). The call is answered by the Agent 8911 (in Sip/8704), then,
the agent try to do a supervised transfer to Sip/8703.  At this point the
agent didnt get any ringback or anything, only silence (and in the log
constantly show this "
Jul 31 13:30:51 WARNING[2547] chan_sip.c: Asked to transmit frame type 64,
while native formats is 8 (read/write = 8/8)"). After the timeout of the
transfer (15 secs), the agent receive a busy signal, instead of recover the
call, and the person who called (8702), in matter of seconds, receive a busy
too.

The log here.

Jul 31 13:30:47 VERBOSE[2547] logger.c:     -- Agent/8911 answered
SIP/8702-081af768
Jul 31 13:30:47 VERBOSE[2547] logger.c:     -- Stopped music on hold on
SIP/8702-081af768
Jul 31 13:30:47 DEBUG[2547] channel.c: Scheduling timer at 0 sample
intervals
Jul 31 13:30:47 DEBUG[2548] channel.c: Planning to masquerade channel
SIP/8704-081b6558 into the structure of Local/8704 at ext-513f,1
Jul 31 13:30:47 DEBUG[2548] channel.c: Done planning to masquerade channel
SIP/8704-081b6558 into the structure of Local/8704 at ext-513f,1
Jul 31 13:30:47 DEBUG[2548] chan_local.c: Not posting to queue since already
masked on 'Local/8704 at ext-513f,2'
Jul 31 13:30:47 DEBUG[2547] channel.c: Got clone lock for masquerade on
'SIP/8704-081b6558' at 0x81bbb34
Jul 31 13:30:47 DEBUG[2547] channel.c: Putting channel SIP/8704-081b6558 in
8/8 formats
Jul 31 13:30:47 DEBUG[2547] channel.c: Released clone lock on '
Local/8704 at ext-513f,1<ZOMBIE>'
Jul 31 13:30:47 DEBUG[2547] channel.c: Done Masquerading SIP/8704-081b6558
(6)
Jul 31 13:30:47 DEBUG[2547] chan_agent.c: Bridge on 'SIP/8704-081b6558'
being set to 'Agent/8911' (3)
Jul 31 13:30:47 DEBUG[2548] channel.c: Didn't get a frame from channel:
Local/8704 at ext-513f,1<ZOMBIE>
Jul 31 13:30:47 DEBUG[2548] channel.c: Bridge stops bridging channels
Local/8704 at ext-513f,2 and Local/8704 at ext-513f,1<ZOMBIE>
Jul 31 13:30:47 DEBUG[2548] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Jul 31 13:30:47 VERBOSE[2548] logger.c:   == Spawn extension (ext, 8704, 1)
exited non-zero on 'Local/8704 at ext-513f,2'
Jul 31 13:30:49 DEBUG[2547] channel.c: Got DTMF on channel (Agent/8911)
Jul 31 13:30:49 DEBUG[2547] channel.c: Bridge stops bridging channels
SIP/8702-081af768 and Agent/8911
Jul 31 13:30:49 DEBUG[2547] res_features.c: Feature interpret:
chan=SIP/8702-081af768, peer=Agent/8911, sense=2, features=6
Jul 31 13:30:49 DEBUG[2547] res_features.c: Set time limit to 500
Jul 31 13:30:49 DEBUG[2547] channel.c: Got DTMF on channel (Agent/8911)
Jul 31 13:30:49 DEBUG[2547] channel.c: Bridge stops bridging channels
SIP/8702-081af768 and Agent/8911
Jul 31 13:30:49 DEBUG[2547] res_features.c: Feature interpret:
chan=SIP/8702-081af768, peer=Agent/8911, sense=2, features=6
Jul 31 13:30:49 DEBUG[2547] res_features.c: Executing Attended Transfer
SIP/8702-081af768, Agent/8911 (sense=2) XXX
Jul 31 13:30:49 VERBOSE[2547] logger.c:     -- Started music on hold, class
'banco', on SIP/8702-081af768
Jul 31 13:30:49 DEBUG[2547] channel.c: Scheduling timer at 160 sample
intervals
Jul 31 13:30:49 DEBUG[2547] channel.c: Scheduling timer at 160 sample
intervals
Jul 31 13:30:49 VERBOSE[2547] logger.c:     -- Playing 'pbx-transfer'
(language 'en')
Jul 31 13:30:49 DEBUG[2559] channel.c: Generator got voice, switching to
phase locked mode
Jul 31 13:30:49 DEBUG[2559] channel.c: Scheduling timer at 0 sample
intervals
Jul 31 13:30:50 DEBUG[2547] channel.c: Scheduling timer at 0 sample
intervals
Jul 31 13:30:50 DEBUG[2547] channel.c: Scheduling timer at 0 sample
intervals
Jul 31 13:30:50 DEBUG[2547] channel.c: Scheduling timer at 160 sample
intervals
Jul 31 13:30:50 DEBUG[2547] channel.c: Generator got voice, switching to
phase locked mode
Jul 31 13:30:50 DEBUG[2547] channel.c: Scheduling timer at 0 sample
intervals
Jul 31 13:30:51 DEBUG[2547] channel.c: Scheduling timer at 0 sample
intervals
Jul 31 13:30:51 DEBUG[2547] channel.c: Scheduling timer at 160 sample
intervals
Jul 31 13:30:51 VERBOSE[2561] logger.c:     -- Executing Dial("
Local/8703 at ext-e417,2", "Sip/8703") in new stack
Jul 31 13:30:51 DEBUG[2561] chan_sip.c: Setting NAT on RTP to 0
Jul 31 13:30:51 DEBUG[2561] chan_sip.c: Outgoing Call for 8703
Jul 31 13:30:51 VERBOSE[2561] logger.c:     -- Called 8703
Jul 31 13:30:51 DEBUG[2547] channel.c: Generator got voice, switching to
phase locked mode
Jul 31 13:30:51 DEBUG[2547] channel.c: Scheduling timer at 0 sample
intervals
Jul 31 13:30:51 WARNING[2547] chan_sip.c: Asked to transmit frame type 64,
while native formats is 8 (read/write = 8/8)
Jul 31 13:30:51 WARNING[2547] chan_sip.c: Asked to transmit frame type 64,
while native formats is 8 (read/write = 8/8)
Jul 31 13:30:51 WARNING[2547] chan_sip.c: Asked to transmit frame type 64,
while native formats is 8 (read/write = 8/8)
Jul 31 13:30:52 WARNING[2547] chan_sip.c: Asked to transmit frame type 64,
while native formats is 8 (read/write = 8/8)
Jul 31 13:30:52 DEBUG[2542] chan_sip.c: (Provisional) Stopping
retransmission (but retaining packet) on '
45ae4d9e794a5a25442fb7300a7ccaf8 at 10.3.7.254' Request 102: Found
Jul 31 13:30:52 WARNING[2547] chan_sip.c: Asked to transmit frame type 64,
while native formats is 8 (read/write = 8/8)
Jul 31 13:30:52 DEBUG[2542] chan_sip.c: (Provisional) Stopping
retransmission (but retaining packet) on '
45ae4d9e794a5a25442fb7300a7ccaf8 at 10.3.7.254' Request 102: Found
Jul 31 13:30:52 VERBOSE[2561] logger.c:     -- SIP/8703-081d40f0 is ringing
Jul 31 13:30:52 VERBOSE[2547] logger.c:     -- Local/8703 at ext-e417,1 is
ringing
Jul 31 13:30:52 DEBUG[2547] channel.c: Driver for channel
'SIP/8704-081b6558' does not support indication 3, emulating it
Jul 31 13:30:52 DEBUG[2547] channel.c: Scheduling timer at 160 sample
intervals
Jul 31 13:30:52 DEBUG[2547] channel.c: Generator got voice, switching to
phase locked mode
Jul 31 13:30:52 DEBUG[2547] channel.c: Scheduling timer at 0 sample
intervals
Jul 31 13:30:52 WARNING[2547] chan_sip.c: Asked to transmit frame type 64,
while native formats is 8 (read/write = 8/8)
Jul 31 13:30:52 WARNING[2547] chan_sip.c: Asked to transmit frame type 64,
while native formats is 8 (read/write = 8/8)
Jul 31 13:30:52 WARNING[2547] chan_sip.c: Asked to transmit frame type 64,
while native formats is 8 (read/write = 8/8)
Jul 31 13:30:52 WARNING[2547] chan_sip.c: Asked to transmit frame type 64,
while native formats is 8 (read/write = 8/8)
Jul 31 13:30:52 WARNING[2547] chan_sip.c: Asked to transmit frame type 64,
while native formats is 8 (read/write = 8/8)
*
(a lot more of this)
*
Jul 31 13:31:01 DEBUG[2547] channel.c: Scheduling timer at 0 sample
intervals
Jul 31 13:31:01 DEBUG[2547] chan_agent.c: Bridge on 'SIP/8704-081b6558'
being cleared (2)
Jul 31 13:31:01 DEBUG[2547] chan_sip.c: update_call_counter(8704) -
decrement call limit counter
Jul 31 13:31:01 WARNING[2547] res_features.c: SALI!!!!!!!!!!!Jul 31 13:31:01
DEBUG[2561] chan_sip.c: update_call_counter(8703) - decrement call limit
counter
Jul 31 13:31:01 DEBUG[2561] chan_sip.c: Acked pending invite 102
Jul 31 13:31:01 DEBUG[2561] chan_sip.c: Stopping retransmission on '
45ae4d9e794a5a25442fb7300a7ccaf8 at 10.3.7.254' of Request 102: Match Found
Jul 31 13:31:01 DEBUG[2561] app_dial.c: Exiting with DIALSTATUS=CANCEL.
Jul 31 13:31:01 VERBOSE[2561] logger.c:   == Spawn extension (ext, 8703, 1)
exited non-zero on 'Local/8703 at ext-e417,2'
Jul 31 13:31:01 WARNING[2547] file.c: Failed to write frame
Jul 31 13:31:01 DEBUG[2547] channel.c: Scheduling timer at 0 sample
intervals
Jul 31 13:31:01 VERBOSE[2547] logger.c:     -- Playing 'beep' (language
'en')
Jul 31 13:31:01 DEBUG[2547] channel.c: Scheduling timer at 0 sample
intervals
Jul 31 13:31:01 WARNING[2547] res_features.c: Failed to play transfer sound!
Jul 31 13:31:01 VERBOSE[2547] logger.c:     -- Stopped music on hold on
SIP/8702-081af768
Jul 31 13:31:01 DEBUG[2547] channel.c: Scheduling timer at 0 sample
intervals
Jul 31 13:31:01 DEBUG[2542] chan_sip.c: Stopping retransmission on '
45ae4d9e794a5a25442fb7300a7ccaf8 at 10.3.7.254' of Request 102: Match Not Found
Jul 31 13:31:01 DEBUG[2542] chan_sip.c: Stopping retransmission on '
45ae4d9e794a5a25442fb7300a7ccaf8 at 10.3.7.254' of Request 102: Match Found
Jul 31 13:31:07 DEBUG[2547] channel.c: Didn't get a frame from channel:
SIP/8702-081af768
Jul 31 13:31:07 DEBUG[2547] channel.c: Bridge stops bridging channels
SIP/8702-081af768 and Agent/8911
Jul 31 13:31:07 DEBUG[2547] chan_agent.c: Hangup called for state Up
Jul 31 13:31:07 VERBOSE[2547] logger.c:   == Spawn extension (ext-local,
8820, 3) exited non-zero on 'SIP/8702-081af768'
Jul 31 13:31:07 DEBUG[2547] chan_sip.c: update_call_counter(8702) -
decrement call limit counter

Anybody knows whats happening or what i am missing?. One thing to notice, if
i use instead of agents, with CallbackLogin(), i use Addqueuemember() with
sips directly, this problem  it never ocurs..

P.D.: it happened with asterisk 1.2.5, i upgraded to 1.2.10, but the problem
persists.

thanks.
Ivan.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.digium.com/pipermail/asterisk-users/attachments/20060731/09c2e173/attachment.htm


More information about the asterisk-users mailing list