[Freeswitch-users] Problem with originated calls hanging in CS_SOFT_EXEC state

Phillip Boles freeswitch-users at vocalspace.com
Thu Aug 30 22:20:06 MSD 2012


	
	var session =  ManagedSession.OriginateHandleHangup(s, dialString, ts, (y) => {
		try {
			Log.WriteLine(LogLevel.Info, "Hanging UP: "+ y.GetUuid());
			y.SetAutoHangup(true);
			y.destroy();

		} catch( Exception ) {
			Log.WriteLine(LogLevel.Critical, "Exception While Trying to handup");	
		}
	});
			
	
2012-08-28 10:49:12.156172 [INFO] switch_cpp.cpp:1227 Dialing
2012-08-28 10:49:12.156172 [DEBUG] switch_ivr_originate.c:1947 Parsing global variables
2012-08-28 10:49:12.156172 [DEBUG] switch_event.c:1527 Parsing variable [ignore_early_media]=[true]
2012-08-28 10:49:12.156172 [DEBUG] switch_event.c:1527 Parsing variable [origination_caller_id_number]=[2223334444]
2012-08-28 10:49:12.156172 [DEBUG] switch_event.c:1527 Parsing variable [origination_caller_id_name]=[Vocalspace]
2012-08-28 10:49:12.156172 [NOTICE] switch_channel.c:926 New Channel sofia/external/XXXXXXXXXXX [e315f2e8-1fa8-4fd9-849b-f687dad8aed5]
2012-08-28 10:49:12.156172 [DEBUG] mod_sofia.c:4709 (sofia/external/XXXXXXXXXXX) State Change CS_NEW -> CS_INIT
2012-08-28 10:49:12.156172 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:12.156172 [DEBUG] switch_core_state_machine.c:382 (sofia/external/XXXXXXXXXXX) Running State Change CS_INIT
2012-08-28 10:49:12.156172 [DEBUG] switch_core_state_machine.c:421 (sofia/external/XXXXXXXXXXX) State INIT
2012-08-28 10:49:12.156172 [DEBUG] mod_sofia.c:85 sofia/external/XXXXXXXXXXX SOFIA INIT
2012-08-28 10:49:12.216161 [DEBUG] switch_nat.c:511 mapped public port 19628 protocol UDP to localport 19628
2012-08-28 10:49:12.256159 [DEBUG] switch_nat.c:511 mapped public port 19629 protocol UDP to localport 19629
2012-08-28 10:49:12.256159 [DEBUG] mod_sofia.c:129 (sofia/external/XXXXXXXXXXX) State Change CS_INIT -> CS_ROUTING
2012-08-28 10:49:12.256159 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:421 (sofia/external/XXXXXXXXXXX) State INIT going to sleep
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:382 (sofia/external/XXXXXXXXXXX) Running State Change CS_ROUTING
2012-08-28 10:49:12.256159 [DEBUG] switch_channel.c:1887 (sofia/external/XXXXXXXXXXX) Callstate Change DOWN -> RINGING
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:430 (sofia/external/XXXXXXXXXXX) State ROUTING
2012-08-28 10:49:12.256159 [DEBUG] mod_sofia.c:152 sofia/external/XXXXXXXXXXX SOFIA ROUTING
2012-08-28 10:49:12.256159 [DEBUG] switch_ivr_originate.c:67 (sofia/external/XXXXXXXXXXX) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2012-08-28 10:49:12.256159 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:430 (sofia/external/XXXXXXXXXXX) State ROUTING going to sleep
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:382 (sofia/external/XXXXXXXXXXX) Running State Change CS_CONSUME_MEDIA
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:449 (sofia/external/XXXXXXXXXXX) State CONSUME_MEDIA
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:449 (sofia/external/XXXXXXXXXXX) State CONSUME_MEDIA going to sleep
2012-08-28 10:49:12.256159 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:12.256159 [DEBUG] sofia.c:5677 Channel sofia/external/XXXXXXXXXXX entering state [calling][0]
2012-08-28 10:49:12.636131 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:12.636131 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:12.636131 [INFO] sofia.c:890 sofia/external/XXXXXXXXXXX Update Callee ID to "Outbound Call" 
2012-08-28 10:49:12.636131 [DEBUG] sofia.c:5677 Channel sofia/external/XXXXXXXXXXX entering state [proceeding][180]
2012-08-28 10:49:12.636131 [NOTICE] sofia.c:5769 Ring-Ready sofia/external/XXXXXXXXXXX!
2012-08-28 10:49:14.655990 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:14.655990 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:14.655990 [INFO] sofia.c:890 sofia/external/XXXXXXXXXXX Update Callee ID to "Outbound Call" 
2012-08-28 10:49:14.655990 [DEBUG] sofia.c:5677 Channel sofia/external/XXXXXXXXXXX entering state [proceeding][183]
2012-08-28 10:49:14.655990 [DEBUG] sofia.c:5688 Remote SDP:
v=0
o=FreeSWITCH 1346150407 1346150408 IN IP4 8.19.97.6
s=FreeSWITCH
c=IN IP4 8.19.97.6
t=0 0
m=audio 18534 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20

2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:4911 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:2995 Set Codec sofia/external/XXXXXXXXXXX PCMU/8000 20 ms 160 samples 64000 bits
2012-08-28 10:49:14.655990 [DEBUG] switch_core_codec.c:111 sofia/external/XXXXXXXXXXX Original read codec set to PCMU:0
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:5025 Set 2833 dtmf send payload to 101
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:3244 AUDIO RTP [sofia/external/XXXXXXXXXXX] 10.10.80.33 port 19628 -> 8.19.97.6 port 18534 codec: 0 ms: 20
2012-08-28 10:49:14.655990 [DEBUG] switch_rtp.c:1676 Starting timer [soft] 160 bytes per 20ms
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:3508 Set 2833 dtmf send payload to 101
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:3514 Set 2833 dtmf receive payload to 101
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:3541 sofia/external/XXXXXXXXXXX Set rtp dtmf delay to 40
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:3547 Set comfort noise payload to 13
2012-08-28 10:49:14.655990 [NOTICE] sofia_glue.c:4052 Pre-Answer sofia/external/XXXXXXXXXXX!
2012-08-28 10:49:14.655990 [DEBUG] switch_channel.c:2986 (sofia/external/XXXXXXXXXXX) Callstate Change RINGING -> EARLY
2012-08-28 10:49:22.136467 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:22.136467 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:22.136467 [INFO] sofia.c:890 sofia/external/XXXXXXXXXXX Update Callee ID to "Outbound Call" 
2012-08-28 10:49:22.136467 [DEBUG] sofia.c:5677 Channel sofia/external/XXXXXXXXXXX entering state [completing][200]
2012-08-28 10:49:22.136467 [DEBUG] sofia.c:5685 Duplicate SDP
v=0
o=FreeSWITCH 1346150407 1346150408 IN IP4 8.19.97.6
s=FreeSWITCH
c=IN IP4 8.19.97.6
t=0 0
m=audio 18534 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20

2012-08-28 10:49:22.136467 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:22.136467 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:22.136467 [DEBUG] sofia.c:5677 Channel sofia/external/XXXXXXXXXXX entering state [ready][200]
2012-08-28 10:49:22.136467 [DEBUG] switch_channel.c:3245 (sofia/external/XXXXXXXXXXX) Callstate Change EARLY -> ACTIVE
2012-08-28 10:49:22.136467 [NOTICE] sofia.c:6352 Channel [sofia/external/XXXXXXXXXXX] has been answered
2012-08-28 10:49:22.136467 [DEBUG] switch_ivr_originate.c:3330 Originate Resulted in Success: [sofia/external/XXXXXXXXXXX]
2012-08-28 10:49:22.136467 [DEBUG] switch_cpp.cpp:1083 (sofia/external/XXXXXXXXXXX) State Change CS_CONSUME_MEDIA -> CS_SOFT_EXECUTE
2012-08-28 10:49:22.136467 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:22.136467 [DEBUG] switch_core_state_machine.c:382 (sofia/external/XXXXXXXXXXX) Running State Change CS_SOFT_EXECUTE
2012-08-28 10:49:22.136467 [DEBUG] switch_core_state_machine.c:443 (sofia/external/XXXXXXXXXXX) State SOFT_EXECUTE
2012-08-28 10:49:22.136467 [DEBUG] mod_sofia.c:592 SOFIA SOFT_EXECUTE
2012-08-28 10:49:22.136467 [DEBUG] switch_core_state_machine.c:261 sofia/external/XXXXXXXXXXX Standard SOFT_EXECUTE
2012-08-28 10:49:22.136467 [DEBUG] switch_core_state_machine.c:443 (sofia/external/XXXXXXXXXXX) State SOFT_EXECUTE going to sleep
2012-08-28 10:49:22.136467 [DEBUG] switch_cpp.cpp:1172 CoreSession::seHangupHook, hangup_func: (nil)
2012-08-28 10:49:22.136467 [INFO] switch_cpp.cpp:1227 Connected
2012-08-28 10:49:23.136397 [INFO] switch_cpp.cpp:1227 Session Ready
2012-08-28 10:49:23.136397 [INFO] switch_cpp.cpp:1227 Call Initialized
2012-08-28 10:49:23.136397 [INFO] switch_cpp.cpp:1227 Trying To Run
2012-08-28 10:49:23.136397 [INFO] switch_cpp.cpp:1227 Running
2012-08-28 10:49:23.160407 [NOTICE] switch_cpp.cpp:1227 Checking for file /svc/prod/product/2167/phone/2167.a74e3d86b1f93f0a1f2fc9ad4f6ef2f4.ulaw.ulaw
2012-08-28 10:49:23.160407 [ERR] mod_sndfile.c:197 Error Opening File [/svc/prod/product/2167/phone/2167.a74e3d86b1f93f0a1f2fc9ad4f6ef2f4.ulaw.ulaw] [System error : No such file or directory.]
2012-08-28 10:49:23.160407 [NOTICE] switch_cpp.cpp:1227 Transcoding xfile /svc/prod/product/2167/phone/2167.a74e3d86b1f93f0a1f2fc9ad4f6ef2f4.ulaw.ulaw
2012-08-28 10:49:23.160407 [NOTICE] switch_cpp.cpp:1227 Sending MQ Message
2012-08-28 10:49:23.296392 [NOTICE] switch_cpp.cpp:1227 Creating a channel...
2012-08-28 10:49:23.296392 [NOTICE] switch_cpp.cpp:1227 Defining Exchange FS...
2012-08-28 10:49:23.316389 [NOTICE] switch_cpp.cpp:1227 Binding Exchange and Queue..
2012-08-28 10:49:23.336389 [NOTICE] switch_cpp.cpp:1227 Sending message..
2012-08-28 10:49:23.356388 [NOTICE] switch_cpp.cpp:1227 shout://www.product.com/files/media/e53bc5bf-4e00-ab8d-4e4d-b201699628d1.mp3
2012-08-28 10:49:25.916204 [DEBUG] mod_shout.c:472 Read Thread Done
2012-08-28 10:49:26.356173 [DEBUG] switch_ivr_play_say.c:1309 Codec Activated L16 at 8000hz 1 channels 20ms
2012-08-28 10:49:26.596156 [DEBUG] switch_rtp.c:3252 Correct ip/port confirmed.
2012-08-28 10:49:27.296108 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:27.296108 [DEBUG] switch_channel.c:2849 (sofia/external/XXXXXXXXXXX) Callstate Change ACTIVE -> HANGUP
2012-08-28 10:49:27.296108 [NOTICE] sofia.c:694 Hangup sofia/external/XXXXXXXXXXX [CS_SOFT_EXECUTE] [NORMAL_CLEARING]
2012-08-28 10:49:27.296108 [DEBUG] switch_channel.c:2872 Send signal sofia/external/XXXXXXXXXXX [KILL]
2012-08-28 10:49:27.296108 [DEBUG] switch_cpp.cpp:1227 AppFunction is in hangupCallback.
2012-08-28 10:49:27.296108 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:382 (sofia/external/XXXXXXXXXXX) Running State Change CS_HANGUP
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:622 (sofia/external/XXXXXXXXXXX) State HANGUP
2012-08-28 10:49:27.296108 [DEBUG] mod_sofia.c:473 Channel sofia/external/XXXXXXXXXXX hanging up, cause: NORMAL_CLEARING
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:47 sofia/external/XXXXXXXXXXX Standard HANGUP, cause: NORMAL_CLEARING
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:622 (sofia/external/XXXXXXXXXXX) State HANGUP going to sleep
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:413 (sofia/external/XXXXXXXXXXX) State Change CS_HANGUP -> CS_REPORTING
2012-08-28 10:49:27.296108 [DEBUG] switch_cpp.cpp:1227 AppFunction is in hangupCallback.
2012-08-28 10:49:27.296108 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:382 (sofia/external/XXXXXXXXXXX) Running State Change CS_REPORTING
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:682 (sofia/external/XXXXXXXXXXX) State REPORTING
2012-08-28 10:49:27.296108 [INFO] switch_cpp.cpp:1227 Handing UP: e315f2e8-1fa8-4fd9-849b-f687dad8aed5
2012-08-28 10:49:27.296108 [DEBUG] switch_cpp.cpp:1007 sofia/external/XXXXXXXXXXX destroy/unlink session from object
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:79 sofia/external/XXXXXXXXXXX Standard REPORTING, cause: NORMAL_CLEARING
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:682 (sofia/external/XXXXXXXXXXX) State REPORTING going to sleep
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:407 (sofia/external/XXXXXXXXXXX) State Change CS_REPORTING -> CS_DESTROY
2012-08-28 10:49:27.296108 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:27.296108 [DEBUG] switch_core_session.c:1424 Session 4 (sofia/external/XXXXXXXXXXX) Locked, Waiting on external entities
2012-08-28 10:49:27.316110 [DEBUG] switch_ivr_play_say.c:1682 done playing file shout://www.product.com/files/media/e53bc5bf-4e00-ab8d-4e4d-b201699628d1.mp3

freeswitch at fs03.int.colo> show channels

uuid,direction,created,created_epoch,name,state,cid_name,cid_num,ip_addr,dest,application,application_data,dialplan,context,read_codec,read_rate,read_bit_rate,write_codec,write_rate,write_bit_rate,secure,hostname,presence_id,presence_data,callstate,callee_name,callee_num,callee_direction,call_uuid,sent_callee_name,sent_callee_num
e315f2e8-1fa8-4fd9-849b-f687dad8aed5,outbound,2012-08-28 10:49:12,1346168952,sofia/external/XXXXXXXXXXX,CS_SOFT_EXECUTE,Vocalspace,2223334444,,XXXXXXXXXXX,,,,default,PCMU,8000,64000,PCMU,8000,64000,,fs03.int.colo,,,ACTIVE,Outbound Call,XXXXXXXXXXX,,,,

1 total.

2012-08-28 10:58:10.256585 [DEBUG] switch_nat.c:511 mapped public port 5060 protocol TCP to localport 5060
2012-08-28 10:58:10.296583 [DEBUG] switch_nat.c:511 mapped public port 5080 protocol UDP to localport 5080
2012-08-28 10:58:10.336580 [DEBUG] switch_nat.c:511 mapped public port 5080 protocol TCP to localport 5080
2012-08-28 10:58:10.396576 [DEBUG] switch_nat.c:511 mapped public port 19628 protocol UDP to localport 19628
2012-08-28 10:58:10.436573 [DEBUG] switch_nat.c:511 mapped public port 19629 protocol UDP to localport 19629
2012-08-28 10:58:10.476570 [DEBUG] switch_nat.c:511 mapped public port 22013 protocol UDP to localport 22013
2012-08-28 10:58:10.536566 [DEBUG] switch_nat.c:511 mapped public port 22191 protocol UDP to localport 22191
2012-08-28 10:58:10.576563 [DEBUG] switch_nat.c:511 mapped public port 25326 protocol UDP to localport 25326
2012-08-28 10:58:10.636559 [DEBUG] switch_nat.c:511 mapped public port 25327 protocol UDP to localport 25327
Loading /usr/lib64/freeswitch/mod/managed/Enyim.Caching.dll from domain Enyim.Caching.dll_63
2012-08-28 11:00:02.097780 [DEBUG] switch_cpp.cpp:1227 Assembly Enyim.Caching, Version=1.2.0.0, Culture=neutral, PublicKeyToken=null doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/Jint.dll from domain Jint.dll_64
2012-08-28 11:00:02.316760 [DEBUG] switch_cpp.cpp:1227 Assembly Jint, Version=0.9.2.0, Culture=neutral, PublicKeyToken=null doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/log4net.dll from domain log4net.dll_65
2012-08-28 11:00:02.536745 [DEBUG] switch_cpp.cpp:1227 Assembly log4net, Version=1.2.10.0, Culture=neutral, PublicKeyToken=1b44e1d426115821 doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/Antlr3.Runtime.dll from domain Antlr3.Runtime.dll_66
2012-08-28 11:00:02.756720 [DEBUG] switch_cpp.cpp:1227 Assembly Antlr3.Runtime, Version=3.3.1.7705, Culture=neutral, PublicKeyToken=eb42632606e9261f doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/RabbitMQ.Client.dll from domain RabbitMQ.Client.dll_67
2012-08-28 11:00:02.996708 [DEBUG] switch_cpp.cpp:1227 Assembly RabbitMQ.Client, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/ManagedEsl.dll from domain ManagedEsl.dll_68
2012-08-28 11:00:03.216689 [DEBUG] switch_cpp.cpp:1227 Assembly ManagedEsl, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/FreeSWITCH.Managed.dll from domain FreeSWITCH.Managed.dll_69
2012-08-28 11:00:03.436678 [DEBUG] switch_cpp.cpp:1227 Assembly FreeSWITCH.Managed, Version=1.0.5.0, Culture=neutral, PublicKeyToken=null doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/FreeSwitch.EventSocket.dll from domain FreeSwitch.EventSocket.dll_70
2012-08-28 11:00:03.657671 [DEBUG] switch_cpp.cpp:1227 Assembly FreeSwitch.EventSocket, Version=1.0.0.0, Culture=neutral, PublicKeyToken=94d8a22cdb4b7713 doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/Newtonsoft.Json.dll from domain Newtonsoft.Json.dll_71
2012-08-28 11:00:03.876655 [DEBUG] switch_cpp.cpp:1227 Assembly Newtonsoft.Json, Version=4.5.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/Freeswitch.UUID.dll from domain Freeswitch.UUID.dll_72
2012-08-28 11:00:04.096628 [DEBUG] switch_cpp.cpp:1227 Assembly Freeswitch.UUID, Version=1.0.0.0, Culture=neutral, PublicKeyToken=f758751257b2cdaf doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/Product.dll from domain Product.dll_73

freeswitch at fs03.int.colo> show channels


0 total.

	
	var session =  ManagedSession.OriginateHandleHangup(s, dialString, ts, (y) => {
		try {
			Log.WriteLine(LogLevel.Info, "Hanging UP: "+ y.GetUuid());
			y.SetAutoHangup(true);
			y.destroy();

		} catch( Exception ) {
			Log.WriteLine(LogLevel.Critical, "Exception While Trying to handup");	
		}
	});
			
	
2012-08-28 10:49:12.156172 [INFO] switch_cpp.cpp:1227 Dialing
2012-08-28 10:49:12.156172 [DEBUG] switch_ivr_originate.c:1947 Parsing global variables
2012-08-28 10:49:12.156172 [DEBUG] switch_event.c:1527 Parsing variable [ignore_early_media]=[true]
2012-08-28 10:49:12.156172 [DEBUG] switch_event.c:1527 Parsing variable [origination_caller_id_number]=[2223334444]
2012-08-28 10:49:12.156172 [DEBUG] switch_event.c:1527 Parsing variable [origination_caller_id_name]=[Vocalspace]
2012-08-28 10:49:12.156172 [NOTICE] switch_channel.c:926 New Channel sofia/external/XXXXXXXXXXX [e315f2e8-1fa8-4fd9-849b-f687dad8aed5]
2012-08-28 10:49:12.156172 [DEBUG] mod_sofia.c:4709 (sofia/external/XXXXXXXXXXX) State Change CS_NEW -> CS_INIT
2012-08-28 10:49:12.156172 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:12.156172 [DEBUG] switch_core_state_machine.c:382 (sofia/external/XXXXXXXXXXX) Running State Change CS_INIT
2012-08-28 10:49:12.156172 [DEBUG] switch_core_state_machine.c:421 (sofia/external/XXXXXXXXXXX) State INIT
2012-08-28 10:49:12.156172 [DEBUG] mod_sofia.c:85 sofia/external/XXXXXXXXXXX SOFIA INIT
2012-08-28 10:49:12.216161 [DEBUG] switch_nat.c:511 mapped public port 19628 protocol UDP to localport 19628
2012-08-28 10:49:12.256159 [DEBUG] switch_nat.c:511 mapped public port 19629 protocol UDP to localport 19629
2012-08-28 10:49:12.256159 [DEBUG] mod_sofia.c:129 (sofia/external/XXXXXXXXXXX) State Change CS_INIT -> CS_ROUTING
2012-08-28 10:49:12.256159 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:421 (sofia/external/XXXXXXXXXXX) State INIT going to sleep
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:382 (sofia/external/XXXXXXXXXXX) Running State Change CS_ROUTING
2012-08-28 10:49:12.256159 [DEBUG] switch_channel.c:1887 (sofia/external/XXXXXXXXXXX) Callstate Change DOWN -> RINGING
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:430 (sofia/external/XXXXXXXXXXX) State ROUTING
2012-08-28 10:49:12.256159 [DEBUG] mod_sofia.c:152 sofia/external/XXXXXXXXXXX SOFIA ROUTING
2012-08-28 10:49:12.256159 [DEBUG] switch_ivr_originate.c:67 (sofia/external/XXXXXXXXXXX) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2012-08-28 10:49:12.256159 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:430 (sofia/external/XXXXXXXXXXX) State ROUTING going to sleep
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:382 (sofia/external/XXXXXXXXXXX) Running State Change CS_CONSUME_MEDIA
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:449 (sofia/external/XXXXXXXXXXX) State CONSUME_MEDIA
2012-08-28 10:49:12.256159 [DEBUG] switch_core_state_machine.c:449 (sofia/external/XXXXXXXXXXX) State CONSUME_MEDIA going to sleep
2012-08-28 10:49:12.256159 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:12.256159 [DEBUG] sofia.c:5677 Channel sofia/external/XXXXXXXXXXX entering state [calling][0]
2012-08-28 10:49:12.636131 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:12.636131 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:12.636131 [INFO] sofia.c:890 sofia/external/XXXXXXXXXXX Update Callee ID to "Outbound Call" 
2012-08-28 10:49:12.636131 [DEBUG] sofia.c:5677 Channel sofia/external/XXXXXXXXXXX entering state [proceeding][180]
2012-08-28 10:49:12.636131 [NOTICE] sofia.c:5769 Ring-Ready sofia/external/XXXXXXXXXXX!
2012-08-28 10:49:14.655990 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:14.655990 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:14.655990 [INFO] sofia.c:890 sofia/external/XXXXXXXXXXX Update Callee ID to "Outbound Call" 
2012-08-28 10:49:14.655990 [DEBUG] sofia.c:5677 Channel sofia/external/XXXXXXXXXXX entering state [proceeding][183]
2012-08-28 10:49:14.655990 [DEBUG] sofia.c:5688 Remote SDP:
v=0
o=FreeSWITCH 1346150407 1346150408 IN IP4 8.19.97.6
s=FreeSWITCH
c=IN IP4 8.19.97.6
t=0 0
m=audio 18534 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20

2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:4911 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:2995 Set Codec sofia/external/XXXXXXXXXXX PCMU/8000 20 ms 160 samples 64000 bits
2012-08-28 10:49:14.655990 [DEBUG] switch_core_codec.c:111 sofia/external/XXXXXXXXXXX Original read codec set to PCMU:0
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:5025 Set 2833 dtmf send payload to 101
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:3244 AUDIO RTP [sofia/external/XXXXXXXXXXX] 10.10.80.33 port 19628 -> 8.19.97.6 port 18534 codec: 0 ms: 20
2012-08-28 10:49:14.655990 [DEBUG] switch_rtp.c:1676 Starting timer [soft] 160 bytes per 20ms
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:3508 Set 2833 dtmf send payload to 101
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:3514 Set 2833 dtmf receive payload to 101
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:3541 sofia/external/XXXXXXXXXXX Set rtp dtmf delay to 40
2012-08-28 10:49:14.655990 [DEBUG] sofia_glue.c:3547 Set comfort noise payload to 13
2012-08-28 10:49:14.655990 [NOTICE] sofia_glue.c:4052 Pre-Answer sofia/external/XXXXXXXXXXX!
2012-08-28 10:49:14.655990 [DEBUG] switch_channel.c:2986 (sofia/external/XXXXXXXXXXX) Callstate Change RINGING -> EARLY
2012-08-28 10:49:22.136467 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:22.136467 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:22.136467 [INFO] sofia.c:890 sofia/external/XXXXXXXXXXX Update Callee ID to "Outbound Call" 
2012-08-28 10:49:22.136467 [DEBUG] sofia.c:5677 Channel sofia/external/XXXXXXXXXXX entering state [completing][200]
2012-08-28 10:49:22.136467 [DEBUG] sofia.c:5685 Duplicate SDP
v=0
o=FreeSWITCH 1346150407 1346150408 IN IP4 8.19.97.6
s=FreeSWITCH
c=IN IP4 8.19.97.6
t=0 0
m=audio 18534 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20

2012-08-28 10:49:22.136467 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:22.136467 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:22.136467 [DEBUG] sofia.c:5677 Channel sofia/external/XXXXXXXXXXX entering state [ready][200]
2012-08-28 10:49:22.136467 [DEBUG] switch_channel.c:3245 (sofia/external/XXXXXXXXXXX) Callstate Change EARLY -> ACTIVE
2012-08-28 10:49:22.136467 [NOTICE] sofia.c:6352 Channel [sofia/external/XXXXXXXXXXX] has been answered
2012-08-28 10:49:22.136467 [DEBUG] switch_ivr_originate.c:3330 Originate Resulted in Success: [sofia/external/XXXXXXXXXXX]
2012-08-28 10:49:22.136467 [DEBUG] switch_cpp.cpp:1083 (sofia/external/XXXXXXXXXXX) State Change CS_CONSUME_MEDIA -> CS_SOFT_EXECUTE
2012-08-28 10:49:22.136467 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:22.136467 [DEBUG] switch_core_state_machine.c:382 (sofia/external/XXXXXXXXXXX) Running State Change CS_SOFT_EXECUTE
2012-08-28 10:49:22.136467 [DEBUG] switch_core_state_machine.c:443 (sofia/external/XXXXXXXXXXX) State SOFT_EXECUTE
2012-08-28 10:49:22.136467 [DEBUG] mod_sofia.c:592 SOFIA SOFT_EXECUTE
2012-08-28 10:49:22.136467 [DEBUG] switch_core_state_machine.c:261 sofia/external/XXXXXXXXXXX Standard SOFT_EXECUTE
2012-08-28 10:49:22.136467 [DEBUG] switch_core_state_machine.c:443 (sofia/external/XXXXXXXXXXX) State SOFT_EXECUTE going to sleep
2012-08-28 10:49:22.136467 [DEBUG] switch_cpp.cpp:1172 CoreSession::seHangupHook, hangup_func: (nil)
2012-08-28 10:49:22.136467 [INFO] switch_cpp.cpp:1227 Connected
2012-08-28 10:49:23.136397 [INFO] switch_cpp.cpp:1227 Session Ready
2012-08-28 10:49:23.136397 [INFO] switch_cpp.cpp:1227 Call Initialized
2012-08-28 10:49:23.136397 [INFO] switch_cpp.cpp:1227 Trying To Run
2012-08-28 10:49:23.136397 [INFO] switch_cpp.cpp:1227 Running
2012-08-28 10:49:23.160407 [NOTICE] switch_cpp.cpp:1227 Checking for file /svc/prod/product/2167/phone/2167.a74e3d86b1f93f0a1f2fc9ad4f6ef2f4.ulaw.ulaw
2012-08-28 10:49:23.160407 [ERR] mod_sndfile.c:197 Error Opening File [/svc/prod/product/2167/phone/2167.a74e3d86b1f93f0a1f2fc9ad4f6ef2f4.ulaw.ulaw] [System error : No such file or directory.]
2012-08-28 10:49:23.160407 [NOTICE] switch_cpp.cpp:1227 Transcoding xfile /svc/prod/product/2167/phone/2167.a74e3d86b1f93f0a1f2fc9ad4f6ef2f4.ulaw.ulaw
2012-08-28 10:49:23.160407 [NOTICE] switch_cpp.cpp:1227 Sending MQ Message
2012-08-28 10:49:23.296392 [NOTICE] switch_cpp.cpp:1227 Creating a channel...
2012-08-28 10:49:23.296392 [NOTICE] switch_cpp.cpp:1227 Defining Exchange FS...
2012-08-28 10:49:23.316389 [NOTICE] switch_cpp.cpp:1227 Binding Exchange and Queue..
2012-08-28 10:49:23.336389 [NOTICE] switch_cpp.cpp:1227 Sending message..
2012-08-28 10:49:23.356388 [NOTICE] switch_cpp.cpp:1227 shout://www.product.com/files/media/e53bc5bf-4e00-ab8d-4e4d-b201699628d1.mp3
2012-08-28 10:49:25.916204 [DEBUG] mod_shout.c:472 Read Thread Done
2012-08-28 10:49:26.356173 [DEBUG] switch_ivr_play_say.c:1309 Codec Activated L16 at 8000hz 1 channels 20ms
2012-08-28 10:49:26.596156 [DEBUG] switch_rtp.c:3252 Correct ip/port confirmed.
2012-08-28 10:49:27.296108 [DEBUG] switch_core_session.c:919 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:27.296108 [DEBUG] switch_channel.c:2849 (sofia/external/XXXXXXXXXXX) Callstate Change ACTIVE -> HANGUP
2012-08-28 10:49:27.296108 [NOTICE] sofia.c:694 Hangup sofia/external/XXXXXXXXXXX [CS_SOFT_EXECUTE] [NORMAL_CLEARING]
2012-08-28 10:49:27.296108 [DEBUG] switch_channel.c:2872 Send signal sofia/external/XXXXXXXXXXX [KILL]
2012-08-28 10:49:27.296108 [DEBUG] switch_cpp.cpp:1227 AppFunction is in hangupCallback.
2012-08-28 10:49:27.296108 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:382 (sofia/external/XXXXXXXXXXX) Running State Change CS_HANGUP
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:622 (sofia/external/XXXXXXXXXXX) State HANGUP
2012-08-28 10:49:27.296108 [DEBUG] mod_sofia.c:473 Channel sofia/external/XXXXXXXXXXX hanging up, cause: NORMAL_CLEARING
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:47 sofia/external/XXXXXXXXXXX Standard HANGUP, cause: NORMAL_CLEARING
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:622 (sofia/external/XXXXXXXXXXX) State HANGUP going to sleep
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:413 (sofia/external/XXXXXXXXXXX) State Change CS_HANGUP -> CS_REPORTING
2012-08-28 10:49:27.296108 [DEBUG] switch_cpp.cpp:1227 AppFunction is in hangupCallback.
2012-08-28 10:49:27.296108 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:382 (sofia/external/XXXXXXXXXXX) Running State Change CS_REPORTING
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:682 (sofia/external/XXXXXXXXXXX) State REPORTING
2012-08-28 10:49:27.296108 [INFO] switch_cpp.cpp:1227 Handing UP: e315f2e8-1fa8-4fd9-849b-f687dad8aed5
2012-08-28 10:49:27.296108 [DEBUG] switch_cpp.cpp:1007 sofia/external/XXXXXXXXXXX destroy/unlink session from object
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:79 sofia/external/XXXXXXXXXXX Standard REPORTING, cause: NORMAL_CLEARING
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:682 (sofia/external/XXXXXXXXXXX) State REPORTING going to sleep
2012-08-28 10:49:27.296108 [DEBUG] switch_core_state_machine.c:407 (sofia/external/XXXXXXXXXXX) State Change CS_REPORTING -> CS_DESTROY
2012-08-28 10:49:27.296108 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/XXXXXXXXXXX [BREAK]
2012-08-28 10:49:27.296108 [DEBUG] switch_core_session.c:1424 Session 4 (sofia/external/XXXXXXXXXXX) Locked, Waiting on external entities
2012-08-28 10:49:27.316110 [DEBUG] switch_ivr_play_say.c:1682 done playing file shout://www.product.com/files/media/e53bc5bf-4e00-ab8d-4e4d-b201699628d1.mp3

freeswitch at fs03.int.colo> show channels

uuid,direction,created,created_epoch,name,state,cid_name,cid_num,ip_addr,dest,application,application_data,dialplan,context,read_codec,read_rate,read_bit_rate,write_codec,write_rate,write_bit_rate,secure,hostname,presence_id,presence_data,callstate,callee_name,callee_num,callee_direction,call_uuid,sent_callee_name,sent_callee_num
e315f2e8-1fa8-4fd9-849b-f687dad8aed5,outbound,2012-08-28 10:49:12,1346168952,sofia/external/XXXXXXXXXXX,CS_SOFT_EXECUTE,Vocalspace,2223334444,,XXXXXXXXXXX,,,,default,PCMU,8000,64000,PCMU,8000,64000,,fs03.int.colo,,,ACTIVE,Outbound Call,XXXXXXXXXXX,,,,

1 total.

2012-08-28 10:58:10.256585 [DEBUG] switch_nat.c:511 mapped public port 5060 protocol TCP to localport 5060
2012-08-28 10:58:10.296583 [DEBUG] switch_nat.c:511 mapped public port 5080 protocol UDP to localport 5080
2012-08-28 10:58:10.336580 [DEBUG] switch_nat.c:511 mapped public port 5080 protocol TCP to localport 5080
2012-08-28 10:58:10.396576 [DEBUG] switch_nat.c:511 mapped public port 19628 protocol UDP to localport 19628
2012-08-28 10:58:10.436573 [DEBUG] switch_nat.c:511 mapped public port 19629 protocol UDP to localport 19629
2012-08-28 10:58:10.476570 [DEBUG] switch_nat.c:511 mapped public port 22013 protocol UDP to localport 22013
2012-08-28 10:58:10.536566 [DEBUG] switch_nat.c:511 mapped public port 22191 protocol UDP to localport 22191
2012-08-28 10:58:10.576563 [DEBUG] switch_nat.c:511 mapped public port 25326 protocol UDP to localport 25326
2012-08-28 10:58:10.636559 [DEBUG] switch_nat.c:511 mapped public port 25327 protocol UDP to localport 25327
Loading /usr/lib64/freeswitch/mod/managed/Enyim.Caching.dll from domain Enyim.Caching.dll_63
2012-08-28 11:00:02.097780 [DEBUG] switch_cpp.cpp:1227 Assembly Enyim.Caching, Version=1.2.0.0, Culture=neutral, PublicKeyToken=null doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/Jint.dll from domain Jint.dll_64
2012-08-28 11:00:02.316760 [DEBUG] switch_cpp.cpp:1227 Assembly Jint, Version=0.9.2.0, Culture=neutral, PublicKeyToken=null doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/log4net.dll from domain log4net.dll_65
2012-08-28 11:00:02.536745 [DEBUG] switch_cpp.cpp:1227 Assembly log4net, Version=1.2.10.0, Culture=neutral, PublicKeyToken=1b44e1d426115821 doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/Antlr3.Runtime.dll from domain Antlr3.Runtime.dll_66
2012-08-28 11:00:02.756720 [DEBUG] switch_cpp.cpp:1227 Assembly Antlr3.Runtime, Version=3.3.1.7705, Culture=neutral, PublicKeyToken=eb42632606e9261f doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/RabbitMQ.Client.dll from domain RabbitMQ.Client.dll_67
2012-08-28 11:00:02.996708 [DEBUG] switch_cpp.cpp:1227 Assembly RabbitMQ.Client, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/ManagedEsl.dll from domain ManagedEsl.dll_68
2012-08-28 11:00:03.216689 [DEBUG] switch_cpp.cpp:1227 Assembly ManagedEsl, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/FreeSWITCH.Managed.dll from domain FreeSWITCH.Managed.dll_69
2012-08-28 11:00:03.436678 [DEBUG] switch_cpp.cpp:1227 Assembly FreeSWITCH.Managed, Version=1.0.5.0, Culture=neutral, PublicKeyToken=null doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/FreeSwitch.EventSocket.dll from domain FreeSwitch.EventSocket.dll_70
2012-08-28 11:00:03.657671 [DEBUG] switch_cpp.cpp:1227 Assembly FreeSwitch.EventSocket, Version=1.0.0.0, Culture=neutral, PublicKeyToken=94d8a22cdb4b7713 doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/Newtonsoft.Json.dll from domain Newtonsoft.Json.dll_71
2012-08-28 11:00:03.876655 [DEBUG] switch_cpp.cpp:1227 Assembly Newtonsoft.Json, Version=4.5.0.0, Culture=neutral, PublicKeyToken=30ad4fe6b2a6aeed doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/Freeswitch.UUID.dll from domain Freeswitch.UUID.dll_72
2012-08-28 11:00:04.096628 [DEBUG] switch_cpp.cpp:1227 Assembly Freeswitch.UUID, Version=1.0.0.0, Culture=neutral, PublicKeyToken=f758751257b2cdaf doesn't reference FreeSWITCH.Managed, not loading.
Loading /usr/lib64/freeswitch/mod/managed/Product.dll from domain Product.dll_73

freeswitch at fs03.int.colo> show channels


0 total.

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20120830/ef7cf421/attachment-0001.html 


Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-users mailing list