Re: [Freeswitch-users] 100% cpu load on incoming call, only during ringing!

Wed, 27 Aug 2008 08:41:02 -0700 

please file a bug on http://jira.freeswitch.org for this.

Mike

On Aug 27, 2008, at 9:44 AM, Sluschny, Thomas wrote:


Hi,
i want to use the new FreeSwitch version 1.0 (Rev8701) and yes, i tested also the new one today (Rev9371): if an incoming call received, cpu load goes to 100%. And if i answer this incoming call, cpu load goes down. Every other thing works great. So i ask you: has no one ever had this problem? 

I use WinXP 3.0GHz Pentium, and also mod_PortAudio.
In dialplan-directory in public.xml i added:
  <extension name="99901">
     <condition field="destination_number" expression="^99901$">
      <action application="ring_ready"/>
      <action application="bridge" data="portaudio"/>
     </condition>
  </extension>
In console everything seems to be ok (with debug):
[EMAIL PROTECTED]> 2008-08-27 15:02:13 [NOTICE] switch_channel.c: 538 switch_channel_set_name() New Channel sofia/internal/[EMAIL PROTECTED] [e79a8e3c-98f2-7f4f-a625-13cfa855b7a8] 2008-08-27 15:02:13 [DEBUG] sofia.c:3653 sofia_handle_sip_i_invite() Setting NAT mode based on rfc1918 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:365 switch_core_session_run() sofia/internal/[EMAIL PROTECTED] Running State Change CS_NEW 2008-08-27 15:02:13 [DEBUG] sofia.c:2157 sofia_handle_sip_i_state() Channel sofia/internal/[EMAIL PROTECTED] entering state [received] 2008-08-27 15:02:13 [DEBUG] sofia.c:2161 sofia_handle_sip_i_state() Remote SDP: 
v=0
o=10221 1698418623 1698418623 IN IP4 192.168.102.51
s=SIPa Session
c=IN IP4 192.168.102.51
t=0 0
m=audio 23450 RTP/AVP 9 0 41 111 8 127 126 2 125
a=rtpmap:9 g722/8000/1
a=rtpmap:0 pcmu/8000/1
a=rtpmap:41 pcma16/16000/1
a=rtpmap:111 pcma32/32000/1
a=rtpmap:8 pcma/8000/1
a=rtpmap:127 g726-16/8000/1
a=rtpmap:126 g726-24/8000/1
a=rtpmap:2 g726-32/8000/1
a=rtpmap:125 g726-40/8000/1
2008-08-27 15:02:13 [DEBUG] sofia_glue.c:2298 sofia_glue_negotiate_sdp() Audio Codec Compare [g722:9:8000]/[PCMU: 0:8000] 2008-08-27 15:02:13 [DEBUG] sofia_glue.c:2298 sofia_glue_negotiate_sdp() Audio Codec Compare [g722:9:8000]/[PCMA: 8:8000] 2008-08-27 15:02:13 [DEBUG] sofia_glue.c:2298 sofia_glue_negotiate_sdp() Audio Codec Compare [g722:9:8000]/[GSM: 3:8000] 2008-08-27 15:02:13 [DEBUG] sofia_glue.c:2298 sofia_glue_negotiate_sdp() Audio Codec Compare [pcmu:0:8000]/[PCMU: 0:8000] 2008-08-27 15:02:13 [DEBUG] sofia_glue.c:1547 sofia_glue_tech_set_codec() Set Codec sofia/internal/[EMAIL PROTECTED] PCMU/8000 20 ms 160 samples 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:369 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State NEW 2008-08-27 15:02:13 [DEBUG] sofia.c:2298 sofia_handle_sip_i_state() sofia/internal/[EMAIL PROTECTED] State Change CS_NEW -> CS_INIT 2008-08-27 15:02:13 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Kill sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:365 switch_core_session_run() sofia/internal/[EMAIL PROTECTED] Running State Change CS_INIT 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:415 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State INIT 2008-08-27 15:02:13 [DEBUG] mod_sofia.c:80 sofia_on_init() sofia/internal/[EMAIL PROTECTED] SOFIA INIT 2008-08-27 15:02:13 [DEBUG] mod_sofia.c:107 sofia_on_init() sofia/internal/[EMAIL PROTECTED] State Change CS_INIT -> CS_ROUTING 2008-08-27 15:02:13 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Kill sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:415 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State INIT going to sleep 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:365 switch_core_session_run() sofia/internal/[EMAIL PROTECTED] Running State Change CS_ROUTING 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:420 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State ROUTING 2008-08-27 15:02:13 [DEBUG] mod_sofia.c:119 sofia_on_routing() sofia/internal/[EMAIL PROTECTED] SOFIA ROUTING 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:64 switch_core_standard_on_routing() Standard ROUTING sofia/internal/[EMAIL PROTECTED] 2008-08-27 15:02:13 [INFO] mod_dialplan_xml.c:228 dialplan_hunt() Processing 10221->[EMAIL PROTECTED] 2008-08-27 15:02:13 [DEBUG] mod_dialplan_xml.c:113 parse_exten() test conditions destination_number(99901) =~ /^99901$/ 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:97 switch_core_standard_on_routing() sofia/internal/ [EMAIL PROTECTED] State Change CS_ROUTING -> CS_EXECUTE 2008-08-27 15:02:13 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Kill sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:420 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State ROUTING going to sleep 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:365 switch_core_session_run() sofia/internal/[EMAIL PROTECTED] Running State Change CS_EXECUTE 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:430 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State EXECUTE 2008-08-27 15:02:13 [DEBUG] mod_sofia.c:156 sofia_on_execute() sofia/internal/[EMAIL PROTECTED] SOFIA EXECUTE 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:129 switch_core_standard_on_execute() Standard EXECUTE 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:140 switch_core_standard_on_execute() sofia/internal/ [EMAIL PROTECTED] Execute ring_ready() 2008-08-27 15:02:13 [NOTICE] mod_sofia.c:1071 sofia_receive_message() Ring-Ready sofia/internal/ [EMAIL PROTECTED] 2008-08-27 15:02:13 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Kill sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-08-27 15:02:13 [NOTICE] mod_dptools.c:373 ring_ready_function() Ring Ready sofia/internal/[EMAIL PROTECTED] 2008-08-27 15:02:13 [DEBUG] sofia.c:200 sofia_event_callback() event [nua_i_state] status [180][Ringing] session: sofia/internal/[EMAIL PROTECTED] 2008-08-27 15:02:13 [DEBUG] sofia.c:2157 sofia_handle_sip_i_state() Channel sofia/internal/[EMAIL PROTECTED] entering state [early] 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:140 switch_core_standard_on_execute() sofia/internal/ [EMAIL PROTECTED] Execute bridge(portaudio) 2008-08-27 15:02:13 [NOTICE] switch_channel.c:538 switch_channel_set_name() New Channel PortAudio/10221 [8af6d26a-4dc4- c841-8dec-5271424b23d4] 2008-08-27 15:02:13 [DEBUG] mod_PortAudio.c:693 channel_outgoing_channel() PortAudio/10221 State Change CS_NEW -> CS_INIT 2008-08-27 15:02:13 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Kill PortAudio/10221 [BREAK] 2008-08-27 15:02:13 [DEBUG] mod_PortAudio.c:444 channel_kill_channel() PortAudio/10221 CHANNEL KILL 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:365 switch_core_session_run() PortAudio/10221 Running State Change CS_INIT 2008-08-27 15:02:13 [DEBUG] switch_core_state_machine.c:415 switch_core_session_run() (PortAudio/10221) State INIT 2008-08-27 15:02:13 [DEBUG] mod_PortAudio.c:194 channel_on_init() PortAudio/10221 CHANNEL INIT 1 0 
Pa_StartStream: waveInStart returned = 0x0.
2008-08-27 15:02:13 [NOTICE] mod_PortAudio.c:235 channel_on_init() Ring-Ready PortAudio/10221! 2008-08-27 15:02:13 [DEBUG] mod_PortAudio.c:252 channel_on_init() BRRRRING! BRRRRING! call 5 ------------------------------------------------------------------------------------------- here we have 100% cpu load --------------------------------------------------------------------------------------------- 2008-08-27 15:02:18 [DEBUG] mod_PortAudio.c:252 channel_on_init() BRRRRING! BRRRRING! call 5 ------------------------------------------------------------------------------------------- here we have 100% cpu load --------------------------------------------------------------------------------------------- 
pa answer
------------------------------------------------------------------------------------------- and now cpu load goes down again --------------------------------------------------------------------------------------------- 2008-08-27 15:02:22 [DEBUG] mod_PortAudio.c:289 channel_on_init() PortAudio/10221 State Change CS_INIT -> CS_ROUTING 2008-08-27 15:02:22 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Kill PortAudio/10221 [BREAK] 2008-08-27 15:02:22 [DEBUG] mod_PortAudio.c:444 channel_kill_channel() PortAudio/10221 CHANNEL KILL 2008-08-27 15:02:22 [DEBUG] switch_core_state_machine.c:415 switch_core_session_run() (PortAudio/10221) State INIT going to sleep 2008-08-27 15:02:22 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Kill PortAudio/10221 [BREAK] 2008-08-27 15:02:22 [DEBUG] mod_PortAudio.c:444 channel_kill_channel() PortAudio/10221 CHANNEL KILL 2008-08-27 15:02:22 [DEBUG] switch_core_state_machine.c:365 switch_core_session_run() PortAudio/10221 Running State Change CS_ROUTING 2008-08-27 15:02:22 [DEBUG] switch_channel.c:1547 switch_channel_perform_mark_answered() Kill sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-08-27 15:02:22 [NOTICE] mod_PortAudio.c:1371 answer_call() Channel [PortAudio/10221] has been answered 
API CALL [pa(answer)] output:
Answered 1 channels.
[EMAIL PROTECTED]> 2008-08-27 15:02:22 [DEBUG] switch_core_state_machine.c:420 switch_core_session_run() (PortAudio/ 10221) State ROUTING 2008-08-27 15:02:22 [DEBUG] mod_PortAudio.c:296 channel_on_routing() PortAudio/10221 CHANNEL ROUTING 2008-08-27 15:02:22 [DEBUG] switch_ivr_originate.c:57 originate_on_routing() PortAudio/10221 State Change CS_ROUTING -> CS_CONSUME_MEDIA 2008-08-27 15:02:22 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Kill PortAudio/10221 [BREAK] 2008-08-27 15:02:22 [DEBUG] mod_PortAudio.c:444 channel_kill_channel() PortAudio/10221 CHANNEL KILL 2008-08-27 15:02:22 [DEBUG] switch_core_state_machine.c:420 switch_core_session_run() (PortAudio/10221) State ROUTING going to sleep 2008-08-27 15:02:22 [DEBUG] switch_core_state_machine.c:365 switch_core_session_run() PortAudio/10221 Running State Change CS_CONSUME_MEDIA 2008-08-27 15:02:22 [DEBUG] switch_core_state_machine.c:442 switch_core_session_run() (PortAudio/10221) State CONSUME_MEDIA 2008-08-27 15:02:22 [DEBUG] sofia_glue.c:1756 sofia_glue_activate_rtp() AUDIO RTP [sofia/internal/[EMAIL PROTECTED] ] 192.168.101.60 port 29652 -> 192.168.102.51 port 23450 codec: 0 ms: 20 2008-08-27 15:02:22 [DEBUG] switch_rtp.c:813 switch_rtp_create() Starting timer [soft] 160 bytes per 20000ms 2008-08-27 15:02:22 [DEBUG] mod_sofia.c:439 sofia_answer_channel() Local SDP sofia/internal/[EMAIL PROTECTED]: 
v=0
o=FreeSWITCH 1219812490 1219812491 IN IP4 192.168.101.60
s=FreeSWITCH
c=IN IP4 192.168.101.60
t=0 0
a=sendrecv
m=audio 29652 RTP/AVP 0 101
a=rtpmap:0 pcmu/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
2008-08-27 15:02:22 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Kill sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-08-27 15:02:22 [NOTICE] switch_ivr_originate.c:1327 switch_ivr_originate() Channel [sofia/internal/[EMAIL PROTECTED] has been answered 2008-08-27 15:02:22 [DEBUG] switch_ivr_originate.c:1365 switch_ivr_originate() Originate Resulted in Success: [PortAudio/ 10221] 2008-08-27 15:02:22 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Kill PortAudio/10221 [BREAK] 2008-08-27 15:02:22 [DEBUG] mod_PortAudio.c:444 channel_kill_channel() PortAudio/10221 CHANNEL KILL 2008-08-27 15:02:22 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Kill sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-08-27 15:02:22 [DEBUG] switch_ivr_bridge.c:786 switch_ivr_multi_threaded_bridge() PortAudio/10221 State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2008-08-27 15:02:22 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Kill PortAudio/10221 [BREAK] 2008-08-27 15:02:22 [DEBUG] mod_PortAudio.c:444 channel_kill_channel() PortAudio/10221 CHANNEL KILL 2008-08-27 15:02:22 [DEBUG] switch_core_state_machine.c:442 switch_core_session_run() (PortAudio/10221) State CONSUME_MEDIA going to sleep 2008-08-27 15:02:22 [DEBUG] switch_core_state_machine.c:365 switch_core_session_run() PortAudio/10221 Running State Change CS_EXCHANGE_MEDIA 2008-08-27 15:02:22 [DEBUG] switch_core_state_machine.c:433 switch_core_session_run() (PortAudio/10221) State EXCHANGE_MEDIA 2008-08-27 15:02:22 [DEBUG] mod_PortAudio.c:457 channel_on_exchange_media() CHANNEL LOOPBACK 2008-08-27 15:02:22 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Kill sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-08-27 15:02:22 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Kill sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-08-27 15:02:22 [DEBUG] sofia.c:2157 sofia_handle_sip_i_state() Channel sofia/internal/[EMAIL PROTECTED] entering state [completed] 2008-08-27 15:02:22 [DEBUG] sofia.c:2157 sofia_handle_sip_i_state() Channel sofia/internal/[EMAIL PROTECTED] entering state [ready] 2008-08-27 15:02:23 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Kill PortAudio/10221 [BREAK] 2008-08-27 15:02:23 [DEBUG] mod_PortAudio.c:444 channel_kill_channel() PortAudio/10221 CHANNEL KILL 
pa hangup
2008-08-27 15:02:30 [NOTICE] mod_PortAudio.c:1332 hangup_call() Hangup PortAudio/10221 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2008-08-27 15:02:30 [DEBUG] switch_channel.c:1368 switch_channel_perform_hangup() Kill PortAudio/10221 [KILL] 2008-08-27 15:02:30 [DEBUG] mod_PortAudio.c:444 channel_kill_channel() PortAudio/10221 CHANNEL KILL 2008-08-27 15:02:30 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Kill PortAudio/10221 [BREAK] 2008-08-27 15:02:30 [DEBUG] mod_PortAudio.c:444 channel_kill_channel() PortAudio/10221 CHANNEL KILL 2008-08-27 15:02:30 [DEBUG] switch_ivr_bridge.c:352 audio_bridge_thread() Kill sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-08-27 15:02:30 [DEBUG] switch_core_session.c:435 switch_core_session_receive_message() Kill sofia/internal/[EMAIL PROTECTED] [BREAK] 
API CALL [pa(hangup)] output:
OK
[EMAIL PROTECTED]> 2008-08-27 15:02:30 [DEBUG] switch_ivr_bridge.c: 352 audio_bridge_thread() Kill PortAudio/10221 [BREAK] 2008-08-27 15:02:30 [DEBUG] mod_PortAudio.c:444 channel_kill_channel() PortAudio/10221 CHANNEL KILL 2008-08-27 15:02:30 [DEBUG] switch_ivr_bridge.c:355 audio_bridge_thread() BRIDGE THREAD DONE [PortAudio/10221] 2008-08-27 15:02:30 [DEBUG] switch_core_state_machine.c:433 switch_core_session_run() (PortAudio/10221) State EXCHANGE_MEDIA going to sleep 2008-08-27 15:02:30 [DEBUG] switch_core_state_machine.c:365 switch_core_session_run() PortAudio/10221 Running State Change CS_HANGUP 2008-08-27 15:02:30 [DEBUG] switch_core_state_machine.c:393 switch_core_session_run() (PortAudio/10221) State HANGUP 2008-08-27 15:02:30 [DEBUG] mod_PortAudio.c:394 remove_pvt() No more channels, deactivating audio 2008-08-27 15:02:30 [DEBUG] switch_ivr_bridge.c:355 audio_bridge_thread() BRIDGE THREAD DONE [sofia/internal/[EMAIL PROTECTED] ] 2008-08-27 15:02:30 [NOTICE] switch_core_state_machine.c:157 switch_core_standard_on_execute() Hangup sofia/internal/[EMAIL PROTECTED] [CS_EXECUTE] [NORMAL_CLEARING] 2008-08-27 15:02:30 [DEBUG] switch_channel.c:1368 switch_channel_perform_hangup() Kill sofia/internal/[EMAIL PROTECTED] [KILL] 2008-08-27 15:02:30 [DEBUG] switch_core_session.c:727 switch_core_session_signal_state_change() Kill sofia/internal/[EMAIL PROTECTED] [BREAK] 2008-08-27 15:02:30 [DEBUG] switch_core_state_machine.c:430 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State EXECUTE going to sleep 2008-08-27 15:02:30 [DEBUG] switch_core_state_machine.c:365 switch_core_session_run() sofia/internal/[EMAIL PROTECTED] Running State Change CS_HANGUP 2008-08-27 15:02:30 [DEBUG] switch_core_state_machine.c:393 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State HANGUP 2008-08-27 15:02:30 [DEBUG] mod_sofia.c:264 sofia_on_hangup() Channel sofia/internal/[EMAIL PROTECTED] hanging up, cause: NORMAL_CLEARING 2008-08-27 15:02:30 [DEBUG] mod_sofia.c:321 sofia_on_hangup() Sending BYE to sofia/internal/[EMAIL PROTECTED] 2008-08-27 15:02:30 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP sofia/internal/[EMAIL PROTECTED] , cause: NORMAL_CLEARING 2008-08-27 15:02:30 [DEBUG] switch_core_state_machine.c:393 switch_core_session_run() (sofia/internal/[EMAIL PROTECTED]) State HANGUP going to sleep 2008-08-27 15:02:30 [DEBUG] switch_core_session.c:794 switch_core_session_thread() Session 9 (sofia/internal/[EMAIL PROTECTED] ) Locked, Waiting on external entities 2008-08-27 15:02:30 [NOTICE] switch_core_session.c:812 switch_core_session_thread() Session 9 (sofia/internal/[EMAIL PROTECTED] ) Ended 2008-08-27 15:02:30 [NOTICE] switch_core_session.c:814 switch_core_session_thread() Close Channel sofia/internal/[EMAIL PROTECTED] [CS_HANGUP] 
WinMME StopStream: waiting for background thread.
2008-08-27 15:02:30 [DEBUG] mod_PortAudio.c:425 channel_on_hangup() PortAudio/10221 CHANNEL HANGUP 2008-08-27 15:02:30 [DEBUG] switch_core_state_machine.c:46 switch_core_standard_on_hangup() Standard HANGUP PortAudio/10221, cause: NORMAL_CLEARING 2008-08-27 15:02:30 [DEBUG] switch_core_state_machine.c:393 switch_core_session_run() (PortAudio/10221) State HANGUP going to sleep 2008-08-27 15:02:30 [DEBUG] switch_core_session.c:794 switch_core_session_thread() Session 10 (PortAudio/10221) Locked, Waiting on external entities 2008-08-27 15:02:30 [NOTICE] switch_core_session.c:812 switch_core_session_thread() Session 10 (PortAudio/10221) Ended 2008-08-27 15:02:30 [NOTICE] switch_core_session.c:814 switch_core_session_thread() Close Channel PortAudio/10221 [CS_HANGUP] 2008-08-27 15:02:31 [DEBUG] sofia.c:200 sofia_event_callback() event [nua_r_options] status [405][Method Not Allowed] session: n/a 2008-08-27 15:02:31 [DEBUG] sofia.c:200 sofia_event_callback() event [nua_r_options] status [405][Method Not Allowed] session: n/a 


Thanks in advance,
Thomas










































_______________________________________________
Freeswitch-users mailing list
Freeswitch-users@lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org



_______________________________________________
Freeswitch-users mailing list
Freeswitch-users@lists.freeswitch.org
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
http://www.freeswitch.org

Reply via email to