Details
-
Type:
Bug
-
Status: Closed
-
Severity:
Minor
-
Resolution: Fixed
-
Affects Version/s: None
-
Target Release Version/s: None
-
Component/s: Codecs/codec_gsm
-
Labels:None
-
Source Revision Number:89241
-
Mantis ID:11243
-
Regression:No
Description
On one of my Asterisk boxes, I am getting distortion on playback of .gsm sound files. Distortion is heard when transcoding is used to a non-GSM channel. Connecting over a GSM channel is fine.
The other Asterisk server running the same Asterisk SVN version is OK, so it may be related to dual-processor or OS version.
-
-
-
-
-
- ADDITIONAL INFORMATION ******
-
-
-
-
I have two Asterisk servers, both currently running tip of branches/1.4
svn checkout http://svn.digium.com/svn/asterisk/branches/1.4 asterisk-1.4
svn checkout http://svn.digium.com/svn/zaptel/branches/1.4 zaptel-1.4
svn checkout http://svn.digium.com/svn/libpri/branches/1.4 libpri-1.4
One is running Debian "Testing" on a twin-processor Pentium III. The other is running Ubuntu "Feisty Fawn" on a single-processor Pentium III. Both are fully updated to today.
uname -a:
Debian (2-processor):
Linux alambil 2.6.22-2-686 #1 SMP Fri Aug 31 00:24:01 UTC 2007 i686 GNU/Linux
Ubuntu (1-processor):
Linux network 2.6.20-16-server #2 SMP Sun Sep 23 19:57:25 UTC 2007 i686 GNU/Linux
Playback of .gsm files on the Debian-based server started to be distorted the last time I upgraded Asterisk. There are no errors reported. My SIP phone is a Sipura ATA with alaw preferred.
Debug is shown below. Should the channel write format change as frequently as it does or is this normal?
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:4468 sip_alloc: Allocating new SIP dialog for 29a21a37-e0b1061e@158.234.80.17 - INVITE (With RTP)
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:15028 handle_request: **** Received INVITE (5) - Command in SIP INVITE
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:2702 do_setnat: Setting NAT on RTP to Off
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:2707 do_setnat: Setting NAT on VRTP to Off
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:4521 find_call: = Found Their Call ID: 29a21a37-e0b1061e@158.234.80.17 Their Tag 394d336356dee2o0 Our tag: as009b4bc0
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:15028 handle_request: **** Received ACK (6) - Command in SIP ACK
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:2165 __sip_ack: Stopping retransmission on '29a21a37-e0b1061e@158.234.80.17' of Response 101: Match Not Found
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:4521 find_call: = Found Their Call ID: 29a21a37-e0b1061e@158.234.80.17 Their Tag 394d336356dee2o0 Our tag: as009b4bc0
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:15028 handle_request: **** Received INVITE (5) - Command in SIP INVITE
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:2702 do_setnat: Setting NAT on RTP to Off
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:2707 do_setnat: Setting NAT on VRTP to Off
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:5319 process_sdp: T38 state changed to 0 on channel <none>
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:5399 process_sdp: We're settling with these formats: 0x8 (alaw)
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:13708 handle_request_invite: Checking SIP call limits for device 230
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:3140 update_call_counter: Updating call counter for incoming call
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:3957 sip_new: *** Our native formats are 0x8 (alaw)
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:3958 sip_new: *** Joint capabilities are 0x8 (alaw)
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:3959 sip_new: *** Our capabilities are 0x8 (alaw)
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:3960 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw)
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:3983 sip_new: This channel will not be able to handle video.
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:8176 build_route: build_route: Contact hop: 230 <sip:230@158.234.80.17:5060>
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:13787 handle_request_invite: SIP/230-081b06b8: New call is still down.... Trying...
[Nov 14 12:16:39] DEBUG[3865]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/230-081b06b8
[Nov 14 12:16:39] DEBUG[3996]: pbx.c:1814 pbx_extension_helper: Launching 'Answer'
– Executing [124@passworded:1] Answer("SIP/230-081b06b8", "") in new stack
[Nov 14 12:16:39] DEBUG[3863]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 230
[Nov 14 12:16:39] DEBUG[3996]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/230-081b06b8
[Nov 14 12:16:39] DEBUG[3863]: chan_sip.c:15655 sip_devicestate: Checking device state for peer 230
[Nov 14 12:16:39] DEBUG[3996]: chan_sip.c:3611 sip_answer: SIP answering channel: SIP/230-081b06b8
[Nov 14 12:16:39] DEBUG[3863]: devicestate.c:287 do_state_change: Changing state for SIP/230 - state 1 (Not in use)
[Nov 14 12:16:39] DEBUG[3996]: chan_sip.c:6592 transmit_response_with_sdp: Setting framing from config on incoming call
[Nov 14 12:16:39] DEBUG[3881]: app_queue.c:575 handle_statechange: Device 'SIP/230' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Nov 14 12:16:39] DEBUG[3996]: chan_sip.c:6356 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True
[Nov 14 12:16:39] DEBUG[3996]: chan_sip.c:6357 add_sdp: ** Our prefcodec: 0x0 (nothing)
[Nov 14 12:16:39] DEBUG[3863]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 230
[Nov 14 12:16:39] DEBUG[3996]: chan_sip.c:6488 add_sdp: – Done with adding codecs to SDP
[Nov 14 12:16:39] DEBUG[3863]: chan_sip.c:15655 sip_devicestate: Checking device state for peer 230
[Nov 14 12:16:39] DEBUG[3996]: channel.c:2553 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=21)
[Nov 14 12:16:39] DEBUG[3863]: devicestate.c:287 do_state_change: Changing state for SIP/230 - state 1 (Not in use)
[Nov 14 12:16:39] DEBUG[3996]: chan_sip.c:6533 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw)
[Nov 14 12:16:39] DEBUG[3881]: app_queue.c:575 handle_statechange: Device 'SIP/230' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Nov 14 12:16:39] DEBUG[3996]: pbx.c:1814 pbx_extension_helper: Launching 'SayUnixTime'
– Executing [124@passworded:2] SayUnixTime("SIP/230-081b06b8", "|GMT0BST|AdBY 'digits/at' IM") in new stack
[Nov 14 12:16:39] DEBUG[3996]: say.c:3010 ast_say_date_with_format_en: Parsing A (offset 0) in AdBY 'digits/at' IM
[Nov 14 12:16:39] DEBUG[3996]: channel.c:3041 set_format: Set channel SIP/230-081b06b8 to write format gsm
[Nov 14 12:16:39] DEBUG[3996]: rtp.c:2731 ast_rtp_write: Ooh, format changed from unknown to alaw
[Nov 14 12:16:39] DEBUG[3996]: rtp.c:2748 ast_rtp_write: Created smoother: format: 8 ms: 20 len: 160
[Nov 14 12:16:39] DEBUG[3996]: channel.c:2072 ast_settimeout: Scheduling timer at 160 sample intervals
– <SIP/230-081b06b8> Playing 'digits/day-3' (language 'en')
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:4521 find_call: = Found Their Call ID: 29a21a37-e0b1061e@158.234.80.17 Their Tag 394d336356dee2o0 Our tag: as56a124e1
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:15028 handle_request: **** Received ACK (6) - Command in SIP ACK
[Nov 14 12:16:39] DEBUG[3865]: chan_sip.c:2165 __sip_ack: Stopping retransmission on '29a21a37-e0b1061e@158.234.80.17' of Response 102: Match Not Found
[Nov 14 12:16:40] DEBUG[3996]: channel.c:2072 ast_settimeout: Scheduling timer at 0 sample intervals
[Nov 14 12:16:40] DEBUG[3996]: channel.c:2072 ast_settimeout: Scheduling timer at 0 sample intervals
[Nov 14 12:16:40] DEBUG[3996]: channel.c:3041 set_format: Set channel SIP/230-081b06b8 to write format alaw
[Nov 14 12:16:40] DEBUG[3996]: say.c:3010 ast_say_date_with_format_en: Parsing d (offset 1) in AdBY 'digits/at' IM
[Nov 14 12:16:40] DEBUG[3996]: channel.c:3041 set_format: Set channel SIP/230-081b06b8 to write format gsm
[Nov 14 12:16:40] DEBUG[3996]: channel.c:2072 ast_settimeout: Scheduling timer at 160 sample intervals
– <SIP/230-081b06b8> Playing 'digits/h-14' (language 'en')
[Nov 14 12:16:41] DEBUG[3996]: channel.c:2072 ast_settimeout: Scheduling timer at 0 sample intervals
[Nov 14 12:16:41] DEBUG[3996]: channel.c:2072 ast_settimeout: Scheduling timer at 0 sample intervals
[Nov 14 12:16:41] DEBUG[3996]: channel.c:3041 set_format: Set channel SIP/230-081b06b8 to write format alaw
[Nov 14 12:16:41] DEBUG[3996]: say.c:3010 ast_say_date_with_format_en: Parsing B (offset 2) in AdBY 'digits/at' IM
[Nov 14 12:16:41] DEBUG[3996]: channel.c:3041 set_format: Set channel SIP/230-081b06b8 to write format gsm
[Nov 14 12:16:41] DEBUG[3996]: channel.c:2072 ast_settimeout: Scheduling timer at 160 sample intervals
Are you sure this isn't a bandwidth problem? alaw uses a significantly higher amount of bandwidth than gsm. One thing to try is to run 'make menuselect' and install the alaw sounds, and try again. If you're still getting distortion, then the problem is bandwidth, not transcoding.