[Home]

Summary:ASTERISK-08207: Agents and SIP attended transfers gives warning messages (codec issue)
Reporter:Miguel Paolino (punkgode)Labels:
Date Opened:2006-11-28 13:17:53.000-0600Date Closed:2007-06-30 09:20:01
Priority:MinorRegression?No
Status:Closed/CompleteComponents:Channels/chan_sip/CodecHandling
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) debug
( 1) messages
( 2) verbosedebug.txt
Description:I get the same output as in bug 0005866 but I solve it converting ALL sound files to gsm, pcm (ulaw) and wav (Microsoft PCM 16bit), so it woulnd't have to make the translation, and not fail.
The problem keeps showing up when making attended transfers from a queue, but only during the time of the call negotiation (to announce the call by the agent); once the phone to where the call will be transfered is reached (starts ringing de destination phone) it stops displaying de WARNING message. The transfer is completed, but with lots of WARNINGs. I guess Asterisk is trying to reproduce a sound in the time it takes to setup the call to the destination phone.
In sip.conf I have limited the usable codecs to just 'ulaw'.

****** ADDITIONAL INFORMATION ******

To make things a clearer in log files:
- SIP/751 is the "client" whose call is attended by agent 704 (SIP/704).
- SIP/704 (Agent 704) takes the call and makes the attended transfer to extension 701 (SIP/701) using DTMF "9" as specified in my features.conf. (It really doesn't matter if SIP/701 is registered or not the WARNING is displayed anyway)
- Same WARNING message all over until the message of the "extention not found" is played.


The warning message is:

Nov 28 16:12:32 WARNING[17959] chan_sip.c: Asked to transmit frame type 64, while native formats is 4 (read/write = 4/4)
Comments:By: Anthony LaMantia (alamantia) 2006-11-28 13:50:36.000-0600

why is the view status for this issue marked private?
By: Miguel Paolino (punkgode) 2006-11-28 14:42:07.000-0600

I would like to change it to public, but I realized that I don't wan't some info on the logs to be shown, can you remove the files so I can upload them again?
By: Anthony LaMantia (alamantia) 2006-11-28 15:30:04.000-0600

sure thing, i just rm'ed the logs and change the status of this to public.
By: Miguel Paolino (punkgode) 2006-11-29 07:31:09.000-0600

I think the problem is between this log lines (in english):
1- The agent pressed '9' for attended transfer
2- The agent pressed '701' as the destination phone of the transfer
3- Here is where the warnings show up


Nov 29 11:12:38 DEBUG[19852] rtp.c: Sending dtmf: 57 (9), at 192.168.1.171
Nov 29 11:12:38 DEBUG[19852] channel.c: Got DTMF on channel (Agent/704)
Nov 29 11:12:38 DEBUG[19852] channel.c: Bridge stops bridging channels SIP/751-0a1745c8 and Agent/704
Nov 29 11:12:38 DEBUG[19852] res_features.c: Feature interpret: chan=SIP/751-0a1745c8, peer=Agent/704, sense=2, features=2
Nov 29 11:12:38 DEBUG[19852] res_features.c: Executing Attended Transfer SIP/751-0a1745c8, Agent/704 (sense=2) XXX
Nov 29 11:12:38 DEBUG[19852] chan_sip.c: Bridged channel now on holdcvnwmjumcaciojk@192.168.1.245
Nov 29 11:12:38 DEBUG[19852] channel.c: Scheduling timer at 160 sample intervals
Nov 29 11:12:38 DEBUG[19863] channel.c: Generator got voice, switching to phase locked mode
Nov 29 11:12:38 DEBUG[19863] channel.c: Scheduling timer at 0 sample intervals
Nov 29 11:12:38 DEBUG[19863] res_musiconhold.c: SIP/751-0a1745c8 Opened file 10 '/var/lib/asterisk/moh-native/Enya/08_Evening_Falls'
Nov 29 11:12:38 DEBUG[19852] channel.c: Scheduling timer at 160 sample intervals
Nov 29 11:12:39 DEBUG[19852] channel.c: Scheduling timer at 0 sample intervals
Nov 29 11:12:39 DEBUG[19852] channel.c: Scheduling timer at 0 sample intervals
Nov 29 11:12:39 DEBUG[19852] channel.c: Set channel Agent/704 to write format slin
Nov 29 11:12:39 DEBUG[19852] channel.c: Scheduling timer at 160 sample intervals
Nov 29 11:12:39 DEBUG[19852] channel.c: Generator got voice, switching to phase locked mode
Nov 29 11:12:39 DEBUG[19852] channel.c: Scheduling timer at 0 sample intervals
Nov 29 11:12:40 DEBUG[19852] rtp.c: Sending dtmf: 55 (7), at 192.168.1.171
Nov 29 11:12:40 DEBUG[19852] channel.c: Set channel Agent/704 to write format ulaw
Nov 29 11:12:40 DEBUG[19852] channel.c: Scheduling timer at 0 sample intervals
Nov 29 11:12:40 DEBUG[19852] rtp.c: Sending dtmf: 48 (0), at 192.168.1.171
Nov 29 11:12:41 DEBUG[19852] rtp.c: Sending dtmf: 49 (1), at 192.168.1.171
Nov 29 11:12:41 DEBUG[19852] channel.c: Not copying variable BRIDGEPEER.
Nov 29 11:12:41 DEBUG[19812] devicestate.c: Changing state for Local/701@callcenter_prueba - state 2 (In use)
Nov 29 11:12:41 DEBUG[19852] channel.c: Driver for channel 'SIP/704-0a112898' does not support indication 3, emulating it
Nov 29 11:12:41 DEBUG[19852] channel.c: Set channel SIP/704-0a112898 to write format slin
Nov 29 11:12:41 DEBUG[19852] channel.c: Scheduling timer at 160 sample intervals
Nov 29 11:12:41 DEBUG[19852] channel.c: Set channel SIP/704-0a112898 to write format ulaw
:
By: Serge Vecher (serge-v) 2006-11-30 09:51:29.000-0600

alright, let's try to reproduce that debug output as per the following instruction set (for completeness):

1) Prepare test environment (reduce the amount of unrelated traffic on the server);
2) Make sure your logger.conf has the following line:
  console => notice,warning,error,debug
3) restart Asterisk with the following command:
  'asterisk -Tvvvvvdddddgc | tee /tmp/verbosedebug.txt'
4) Enable SIP transaction logging with the following CLI commands:
set debug 4
set verbose 4
sip debug
5) Attach verbosedebug.txt to the issue.


By: Miguel Paolino (punkgode) 2006-12-04 06:51:21.000-0600

verbose log attached
By: Joshua C. Colp (jcolp) 2007-02-16 16:21:13.000-0600

Fixed in 1.2 as of revision 54999, 1.4 as of revision 55002, and trunk as of revision 55003. Thanks!