[Home]

Summary:ASTERISK-09452: Using IAX and speex codec I get a crash with: Out of buffer space
Reporter:Daniel McKeehan (danmckeehan)Labels:
Date Opened:2007-05-15 22:48:58Date Closed:2007-06-29 10:10:24
Priority:CriticalRegression?No
Status:Closed/CompleteComponents:Core/CodecInterface
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:( 0) gdb.txt
Description:Setup is a sip call goes out with allow=speex other end of call goes to IAX channel.

Crashes with and no debug
[May 15 21:07:10] WARNING[2325]: codec_speex.c:237 speextolin_framein: Out of buffer space
[May 15 21:07:10] WARNING[2325]: codec_speex.c:237 speextolin_framein: Out of buffer space


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

[May 15 21:06:38] DEBUG[1156]: res_jabber.c:633 aji_act_hook: JABBER: I Do know how to handle presence!!
'Channel' is 'SIP/danmckeehan_at_gmail.com@gtalk.gtalk2voip.com' at line 1
'MaxRetries' is '0' at line 2
'RetryTime' is '60' at line 3
'WaitTime' is '30' at line 4
'Context' is 'googlestart' at line 5
'Extension' is '100201397' at line 6
'CallerID' is 'danmckeehan <NowLive>' at line 7
'Priority' is '1' at line 8
   -- Attempting call on SIP/danmckeehan_at_gmail.com@gtalk.gtalk2voip.com for 100201397@googlestart:1 (Retry 1)
[May 15 21:06:54] DEBUG[2325]: chan_sip.c:15310 sip_request_call: Asked to create a SIP channel with formats: 0x40 (slin)
[May 15 21:06:54] DEBUG[2325]: chan_sip.c:4310 sip_alloc: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP)
   -- parse_srv: SRV mapped to host gtalk2voip.com, port 5060
[May 15 21:06:59] DEBUG[2325]: chan_sip.c:3805 sip_new: *** Our native formats are 0x200 (speex)
[May 15 21:06:59] DEBUG[2325]: chan_sip.c:3806 sip_new: *** Joint capabilities are 0x0 (nothing)
[May 15 21:06:59] DEBUG[2325]: chan_sip.c:3807 sip_new: *** Our capabilities are 0x200 (speex)
[May 15 21:06:59] DEBUG[2325]: chan_sip.c:3808 sip_new: *** AST_CODEC_CHOOSE formats are 0x200 (speex)
[May 15 21:06:59] DEBUG[2325]: chan_sip.c:3810 sip_new: *** Our preferred formats from the incoming channel are 0x40 (slin)
[May 15 21:06:59] DEBUG[2325]: chan_sip.c:3831 sip_new: This channel will not be able to handle video.
[May 15 21:06:59] DEBUG[2325]: chan_sip.c:2830 sip_call: Outgoing Call for danmckeehan_at_gmail.com
[May 15 21:06:59] DEBUG[2325]: chan_sip.c:3003 update_call_counter: Updating call counter for outgoing call
[May 15 21:06:59] DEBUG[2325]: chan_sip.c:2845 sip_call: Our T38 capability (0), joint T38 capability (0)
[May 15 21:06:59] DEBUG[2325]: chan_sip.c:6188 add_sdp: ** Our capability: 0x200 (speex) Video flag: False
[May 15 21:06:59] DEBUG[2325]: chan_sip.c:6189 add_sdp: ** Our prefcodec: 0x40 (slin)
[May 15 21:06:59] DEBUG[2325]: chan_sip.c:6320 add_sdp: -- Done with adding codecs to SDP
[May 15 21:06:59] DEBUG[2325]: channel.c:2381 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1)
[May 15 21:06:59] DEBUG[2325]: chan_sip.c:6365 add_sdp: Done building SDP. Settling with this capability: 0x200 (speex)
[May 15 21:07:00] DEBUG[1216]: chan_sip.c:1880 retrans_pkt: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id ASTERISK-3))
[May 15 21:07:00] DEBUG[1216]: chan_sip.c:2010 __sip_autodestruct: Auto destroying SIP dialog '6b928ed815d4d22942f378966e6f538b@127.0.0.1'
[May 15 21:07:00] DEBUG[1216]: chan_sip.c:3109 sip_destroy: Destroying SIP dialog 6b928ed815d4d22942f378966e6f538b@127.0.0.1
Really destroying SIP dialog '6b928ed815d4d22942f378966e6f538b@127.0.0.1' Method: REGISTER
[May 15 21:07:01] DEBUG[1216]: chan_sip.c:1880 retrans_pkt: ** SIP timers: Rescheduling retransmission 3 to 2000 ms (t1 500 ms (Retrans id ASTERISK-3))
[May 15 21:07:01] DEBUG[1216]: chan_sip.c:4361 find_call: = Found Their Call ID: 71795e716e7d5f0537f7ad0a524c67b8@192.168.1.120 Their Tag  Our tag: as708d2250
[May 15 21:07:01] DEBUG[1216]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '71795e716e7d5f0537f7ad0a524c67b8@192.168.1.120' Request 102: Found
[May 15 21:07:01] DEBUG[1216]: chan_sip.c:11641 handle_response_invite: SIP response 100 to standard invite
[May 15 21:07:01] DEBUG[1216]: chan_sip.c:4361 find_call: = Found Their Call ID: 71795e716e7d5f0537f7ad0a524c67b8@192.168.1.120 Their Tag 1179287393161421 Our tag: as708d2250
[May 15 21:07:01] DEBUG[1216]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '71795e716e7d5f0537f7ad0a524c67b8@192.168.1.120' Request 102: Found
[May 15 21:07:01] DEBUG[1216]: chan_sip.c:11641 handle_response_invite: SIP response 180 to standard invite
[May 15 21:07:01] DEBUG[1216]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/gtalk.gtalk2voip.com-0820bb98
[May 15 21:07:01] DEBUG[1150]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - gtalk.gtalk2voip.com
[May 15 21:07:01] DEBUG[1150]: chan_sip.c:15244 sip_devicestate: Checking device state for peer gtalk.gtalk2voip.com
[May 15 21:07:01] DEBUG[1216]: chan_sip.c:4361 find_call: = Found Their Call ID: 71795e716e7d5f0537f7ad0a524c67b8@192.168.1.120 Their Tag 1179287393161421 Our tag: as708d2250
[May 15 21:07:01] DEBUG[1216]: chan_sip.c:2131 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '71795e716e7d5f0537f7ad0a524c67b8@192.168.1.120' Request 102: Found
[May 15 21:07:01] DEBUG[1216]: chan_sip.c:11641 handle_response_invite: SIP response 180 to standard invite
[May 15 21:07:01] DEBUG[1150]: devicestate.c:287 do_state_change: Changing state for SIP/gtalk.gtalk2voip.com - state 6 (Ringing)
[May 15 21:07:01] DEBUG[2597]: app_queue.c:546 changethread: Device 'SIP/gtalk.gtalk2voip.com' changed to state '6' (Ringing) but we don't care because they're not a member of any queue.
[May 15 21:07:08] DEBUG[1216]: chan_sip.c:4361 find_call: = Found Their Call ID: 71795e716e7d5f0537f7ad0a524c67b8@192.168.1.120 Their Tag 1179287393161421 Our tag: as708d2250
[May 15 21:07:08] DEBUG[1216]: chan_sip.c:2071 __sip_ack: Acked pending invite 102
[May 15 21:07:08] DEBUG[1216]: chan_sip.c:2089 __sip_ack: Stopping retransmission on '71795e716e7d5f0537f7ad0a524c67b8@192.168.1.120' of Request 102: Match Not Found
[May 15 21:07:08] DEBUG[1216]: chan_sip.c:11641 handle_response_invite: SIP response 200 to standard invite
[May 15 21:07:08] DEBUG[1216]: chan_sip.c:5129 process_sdp: T38 state changed to 0 on channel SIP/gtalk.gtalk2voip.com-0820bb98
[May 15 21:07:08] DEBUG[1216]: chan_sip.c:5209 process_sdp: We're settling with these formats: 0x200 (speex)
[May 15 21:07:08] DEBUG[1216]: chan_sip.c:5216 process_sdp: We have an owner, now see if we need to change this call
[May 15 21:07:08] DEBUG[1216]: chan_sip.c:3003 update_call_counter: Updating call counter for outgoing call
[May 15 21:07:08] DEBUG[1216]: chan_sip.c:7980 build_route: build_route: Contact hop: <sip:NowLive@213.219.243.49:5060;transport=udp>
[May 15 21:07:08] DEBUG[2325]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel SIP/gtalk.gtalk2voip.com-0820bb98
      > Channel SIP/gtalk.gtalk2voip.com-0820bb98 was answered.
[May 15 21:07:08] DEBUG[2325]: pbx.c:1795 pbx_extension_helper: Launching 'Answer'
   -- Executing [100201397@googlestart:1] Answer("SIP/gtalk.gtalk2voip.com-0820bb98", "") in new stack
[May 15 21:07:08] DEBUG[2325]: pbx.c:1795 pbx_extension_helper: Launching 'NoOp'
   -- Executing [100201397@googlestart:2] NoOp("SIP/gtalk.gtalk2voip.com-0820bb98", "Got call from ingoogle 100201397") in new stack
[May 15 21:07:08] DEBUG[2325]: pbx.c:1795 pbx_extension_helper: Launching 'Wait'
   -- Executing [100201397@googlestart:3] Wait("SIP/gtalk.gtalk2voip.com-0820bb98", "1") in new stack
[May 15 21:07:08] DEBUG[1150]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - gtalk.gtalk2voip.com
[May 15 21:07:08] DEBUG[1150]: chan_sip.c:15244 sip_devicestate: Checking device state for peer gtalk.gtalk2voip.com
[May 15 21:07:09] DEBUG[1150]: devicestate.c:287 do_state_change: Changing state for SIP/gtalk.gtalk2voip.com - state 2 (In use)
[May 15 21:07:09] DEBUG[2905]: app_queue.c:546 changethread: Device 'SIP/gtalk.gtalk2voip.com' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[May 15 21:07:09] DEBUG[2325]: pbx.c:1795 pbx_extension_helper: Launching 'Dial'
   -- Executing [100201397@googlestart:4] Dial("SIP/gtalk.gtalk2voip.com-0820bb98", "IAX2/gtalkstartshow:skypeme123@192.168.1.2/100201397") in new stack
[May 15 21:07:09] DEBUG[2325]: rtp.c:1551 ast_rtp_make_compatible: Channel 'IAX2/192.168.1.2:4569-1' has no RTP, not doing anything
[May 15 21:07:09] DEBUG[2325]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-googlestart-100201397-4.
[May 15 21:07:09] DEBUG[2325]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-googlestart-100201397-3.
[May 15 21:07:09] DEBUG[2325]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-googlestart-100201397-2.
[May 15 21:07:09] DEBUG[2325]: channel.c:3301 ast_channel_inherit_variables: Not copying variable STACK-googlestart-100201397-1.
[May 15 21:07:09] DEBUG[2325]: channel.c:3301 ast_channel_inherit_variables: Not copying variable SIPCALLID.
[May 15 21:07:09] DEBUG[2325]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel IAX2/192.168.1.2:4569-1
   -- Called gtalkstartshow:skypeme123@192.168.1.2/100201397
[May 15 21:07:09] DEBUG[2325]: channel.c:2845 set_format: Set channel IAX2/192.168.1.2:4569-1 to read format speex
[May 15 21:07:09] DEBUG[2325]: channel.c:2845 set_format: Set channel IAX2/192.168.1.2:4569-1 to write format speex
[May 15 21:07:09] DEBUG[1150]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for IAX2 - 192.168.1.2:4569
[May 15 21:07:09] DEBUG[1150]: chan_iax2.c:9636 iax2_devicestate: Checking device state for device 192.168.1.2
[May 15 21:07:09] DEBUG[1150]: devicestate.c:287 do_state_change: Changing state for IAX2/192.168.1.2:4569 - state 4 (Invalid)
[May 15 21:07:09] DEBUG[2947]: app_queue.c:546 changethread: Device 'IAX2/192.168.1.2:4569' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
   -- Call accepted by 192.168.1.2 (format ulaw)
   -- Format for call is ulaw
[May 15 21:07:09] DEBUG[1204]: channel.c:2845 set_format: Set channel IAX2/192.168.1.2:4569-1 to write format speex
[May 15 21:07:09] DEBUG[1204]: channel.c:2845 set_format: Set channel IAX2/192.168.1.2:4569-1 to read format speex
[May 15 21:07:10] DEBUG[2325]: devicestate.c:303 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel IAX2/192.168.1.2:4569-1
   -- IAX2/192.168.1.2:4569-1 answered SIP/gtalk.gtalk2voip.com-0820bb98
[May 15 21:07:10] DEBUG[2325]: rtp.c:1476 ast_rtp_early_bridge: Channel 'IAX2/192.168.1.2:4569-1' has no RTP, not doing anything
[May 15 21:07:10] DEBUG[2325]: channel.c:2845 set_format: Set channel SIP/gtalk.gtalk2voip.com-0820bb98 to read format slin
[May 15 21:07:10] DEBUG[2325]: channel.c:2845 set_format: Set channel IAX2/192.168.1.2:4569-1 to write format slin
[May 15 21:07:10] DEBUG[2325]: channel.c:2845 set_format: Set channel IAX2/192.168.1.2:4569-1 to read format slin
[May 15 21:07:10] DEBUG[2325]: channel.c:2845 set_format: Set channel SIP/gtalk.gtalk2voip.com-0820bb98 to write format slin
[May 15 21:07:10] DEBUG[1150]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for IAX2 - 192.168.1.2:4569
[May 15 21:07:10] DEBUG[1150]: chan_iax2.c:9636 iax2_devicestate: Checking device state for device 192.168.1.2
[May 15 21:07:10] DEBUG[1150]: devicestate.c:287 do_state_change: Changing state for IAX2/192.168.1.2:4569 - state 4 (Invalid)
[May 15 21:07:10] DEBUG[2948]: app_queue.c:546 changethread: Device 'IAX2/192.168.1.2:4569' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[May 15 21:07:10] WARNING[2325]: codec_speex.c:237 speextolin_framein: Out of buffer space
[May 15 21:07:10] WARNING[2325]: codec_speex.c:237 speextolin_framein: Out of buffer space
Comments:By: Daniel McKeehan (danmckeehan) 2007-05-31 16:07:16

The out of buffer space error was caused by bug ASTERISK-9436 patch.  However removing the patch still produced no audio just with out the error messages.
By: Russell Bryant (russell) 2007-06-06 09:49:06

Does it still crash without that patch?
By: Russell Bryant (russell) 2007-06-06 10:34:14

Also, please update to the latest code in the 1.4 branch and try again.  There have been a lot of fixes recently.
By: Daniel McKeehan (danmckeehan) 2007-06-07 16:20:56

Doesn't crash after removing the patch however, I don't get any audio.
By: Russell Bryant (russell) 2007-06-20 14:22:54

Can you try again with the latest code in the 1.4 branch.  file just fixed some issues relatex to speex with the use of RTP.
By: Russell Bryant (russell) 2007-06-29 10:10:13

I'm going to assume this was fixed by file's changes due to the lack of feedback.  Feel free to reopen if you still have a problem.