

/////////////////////////////////////////////////////////////////////////////////

fs_cli

2012-08-10 17:02:29.101113 [DEBUG] switch_ivr_originate.c:1947 Parsing global variables
2012-08-10 17:02:29.101113 [DEBUG] switch_event.c:1527 Parsing variable [plivo_request_uuid]=[7577abca-e33f-11e1-96c0-000c29168f72]
2012-08-10 17:02:29.101113 [DEBUG] switch_event.c:1527 Parsing variable [plivo_answer_url]=[http://192.168.6.29:8008/api/v1/answercall/]
2012-08-10 17:02:29.101113 [DEBUG] switch_event.c:1527 Parsing variable [plivo_hangup_url]=[http://192.168.6.29:8008/api/v1/hangupcall/]
2012-08-10 17:02:29.101113 [DEBUG] switch_event.c:1527 Parsing variable [origination_caller_id_number]=[88888888]
2012-08-10 17:02:29.101113 [DEBUG] switch_event.c:1527 Parsing variable [bridge_early_media]=[true]
2012-08-10 17:02:29.101113 [DEBUG] switch_event.c:1527 Parsing variable [hangup_after_bridge]=[true]
2012-08-10 17:02:29.101113 [DEBUG] switch_event.c:1527 Parsing variable [plivo_from]=[88888888]
2012-08-10 17:02:29.101113 [DEBUG] switch_event.c:1527 Parsing variable [plivo_to]=[40505060]
2012-08-10 17:02:29.101113 [DEBUG] switch_event.c:1527 Parsing variable [plivo_app]=[true]
2012-08-10 17:02:29.101113 [DEBUG] switch_event.c:1527 Parsing variable [absolute_codec_string]=[PCMA]
2012-08-10 17:02:29.101113 [DEBUG] switch_event.c:1527 Parsing variable [originate_timeout]=[1800]
2012-08-10 17:02:29.101113 [DEBUG] switch_event.c:1527 Parsing variable [ignore_early_media]=[true]
2012-08-10 17:02:29.101113 [NOTICE] switch_channel.c:926 New Channel sofia/external/40505060 [7579c96e-e33f-11e1-ba33-d5c5d8e78830]
2012-08-10 17:02:29.101113 [DEBUG] mod_sofia.c:4709 (sofia/external/40505060) State Change CS_NEW -> CS_INIT
2012-08-10 17:02:29.101113 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.101113 [DEBUG] switch_core_state_machine.c:382 (sofia/external/40505060) Running State Change CS_INIT
2012-08-10 17:02:29.101113 [DEBUG] switch_core_state_machine.c:421 (sofia/external/40505060) State INIT
2012-08-10 17:02:29.101113 [DEBUG] mod_sofia.c:85 sofia/external/40505060 SOFIA INIT
2012-08-10 17:02:29.121764 [DEBUG] switch_core_session.c:919 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.121764 [DEBUG] mod_sofia.c:129 (sofia/external/40505060) State Change CS_INIT -> CS_ROUTING
2012-08-10 17:02:29.121764 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.121764 [DEBUG] switch_core_state_machine.c:421 (sofia/external/40505060) State INIT going to sleep
2012-08-10 17:02:29.121764 [DEBUG] switch_core_state_machine.c:382 (sofia/external/40505060) Running State Change CS_ROUTING
2012-08-10 17:02:29.121764 [DEBUG] switch_channel.c:1887 (sofia/external/40505060) Callstate Change DOWN -> RINGING
2012-08-10 17:02:29.121764 [DEBUG] switch_core_session.c:919 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.121764 [DEBUG] switch_core_state_machine.c:430 (sofia/external/40505060) State ROUTING
2012-08-10 17:02:29.121764 [DEBUG] mod_sofia.c:152 sofia/external/40505060 SOFIA ROUTING
2012-08-10 17:02:29.121764 [DEBUG] switch_ivr_originate.c:67 (sofia/external/40505060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2012-08-10 17:02:29.121764 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.121764 [DEBUG] switch_core_state_machine.c:430 (sofia/external/40505060) State ROUTING going to sleep
2012-08-10 17:02:29.121764 [DEBUG] switch_core_state_machine.c:382 (sofia/external/40505060) Running State Change CS_CONSUME_MEDIA
2012-08-10 17:02:29.121764 [DEBUG] switch_core_state_machine.c:449 (sofia/external/40505060) State CONSUME_MEDIA
2012-08-10 17:02:29.121764 [DEBUG] switch_core_state_machine.c:449 (sofia/external/40505060) State CONSUME_MEDIA going to sleep
2012-08-10 17:02:29.141130 [DEBUG] sofia.c:5677 Channel sofia/external/40505060 entering state [calling][0]
2012-08-10 17:02:29.141130 [DEBUG] switch_core_session.c:919 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.141130 [DEBUG] sofia.c:5677 Channel sofia/external/40505060 entering state [calling][0]
2012-08-10 17:02:29.241103 [DEBUG] switch_core_session.c:919 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.241103 [DEBUG] switch_core_session.c:919 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.241103 [DEBUG] sofia.c:5677 Channel sofia/external/40505060 entering state [completing][200]
2012-08-10 17:02:29.241103 [DEBUG] sofia.c:5688 Remote SDP:
v=0
o=root 738656834 738656834 IN IP4 190.7.192.133
s=Asterisk PBX 1.8.11-cert1
c=IN IP4 190.7.192.133
t=0 0
m=audio 11082 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20

2012-08-10 17:02:29.241103 [DEBUG] switch_core_session.c:919 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.241103 [DEBUG] switch_core_session.c:919 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.241103 [DEBUG] sofia.c:5677 Channel sofia/external/40505060 entering state [ready][200]
2012-08-10 17:02:29.241103 [DEBUG] sofia_glue.c:4911 Audio Codec Compare [PCMA:8:8000:20:64000]/[PCMA:8:8000:20:64000]
2012-08-10 17:02:29.241103 [DEBUG] sofia_glue.c:2995 Set Codec sofia/external/40505060 PCMA/8000 20 ms 160 samples 64000 bits
2012-08-10 17:02:29.241103 [DEBUG] switch_core_codec.c:111 sofia/external/40505060 Original read codec set to PCMA:8
2012-08-10 17:02:29.241103 [DEBUG] sofia_glue.c:5025 Set 2833 dtmf send payload to 101
2012-08-10 17:02:29.241103 [DEBUG] sofia_glue.c:3244 AUDIO RTP [sofia/external/40505060] 192.168.6.29 port 23972 -> 190.7.192.133 port 11082 codec: 8 ms: 20
2012-08-10 17:02:29.241103 [DEBUG] switch_rtp.c:1676 Starting timer [soft] 160 bytes per 20ms
2012-08-10 17:02:29.241103 [DEBUG] sofia_glue.c:3508 Set 2833 dtmf send payload to 101
2012-08-10 17:02:29.241103 [DEBUG] sofia_glue.c:3514 Set 2833 dtmf receive payload to 101
2012-08-10 17:02:29.241103 [DEBUG] sofia_glue.c:3541 sofia/external/40505060 Set rtp dtmf delay to 40
2012-08-10 17:02:29.241103 [DEBUG] switch_channel.c:3245 (sofia/external/40505060) Callstate Change RINGING -> ACTIVE
2012-08-10 17:02:29.241103 [NOTICE] sofia.c:6413 Channel [sofia/external/40505060] has been answered
2012-08-10 17:02:29.241103 [DEBUG] switch_ivr_originate.c:3330 Originate Resulted in Success: [sofia/external/40505060]
2012-08-10 17:02:29.241103 [INFO] switch_channel.c:2711 sofia/external/40505060 Flipping CID from "" <88888888> to "Outbound Call" <40505060>
2012-08-10 17:02:29.241103 [DEBUG] mod_commands.c:3577 (sofia/external/40505060) State Change CS_CONSUME_MEDIA -> CS_EXECUTE
2012-08-10 17:02:29.241103 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.241103 [DEBUG] switch_core_state_machine.c:382 (sofia/external/40505060) Running State Change CS_EXECUTE
2012-08-10 17:02:29.241103 [DEBUG] switch_core_state_machine.c:437 (sofia/external/40505060) State EXECUTE
2012-08-10 17:02:29.241103 [DEBUG] mod_sofia.c:245 sofia/external/40505060 SOFIA EXECUTE
2012-08-10 17:02:29.241103 [DEBUG] switch_core_state_machine.c:193 sofia/external/40505060 Standard EXECUTE
EXECUTE sofia/external/40505060 socket(127.0.0.1:8084 async full)
2012-08-10 17:02:29.281114 [DEBUG] switch_core_session.c:1056 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.281114 [DEBUG] switch_core_session.c:1056 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.301121 [DEBUG] switch_ivr.c:598 sofia/external/40505060 Command Execute set(plivo_app=true)
EXECUTE sofia/external/40505060 set(plivo_app=true)
2012-08-10 17:02:29.301121 [DEBUG] mod_dptools.c:1294 sofia/external/40505060 SET [plivo_app]=[true]
2012-08-10 17:02:29.321118 [DEBUG] switch_ivr.c:598 sofia/external/40505060 Command Execute set(hangup_after_bridge=false)
EXECUTE sofia/external/40505060 set(hangup_after_bridge=false)
2012-08-10 17:02:29.321118 [DEBUG] mod_dptools.c:1294 sofia/external/40505060 SET [hangup_after_bridge]=[false]
2012-08-10 17:02:29.341115 [DEBUG] switch_core_session.c:1056 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:29.361105 [DEBUG] switch_ivr.c:598 sofia/external/40505060 Command Execute speak(flite|slt|Hello World)
EXECUTE sofia/external/40505060 speak(flite|slt|Hello World)
2012-08-10 17:02:29.361105 [DEBUG] switch_ivr_play_say.c:2473 OPEN TTS flite
2012-08-10 17:02:29.361105 [DEBUG] switch_ivr_play_say.c:2482 Raw Codec Activated
2012-08-10 17:02:29.541099 [DEBUG] switch_ivr_play_say.c:2164 Speaking text: Hello World
2012-08-10 17:02:29.821105 [DEBUG] switch_rtp.c:3252 Correct ip/port confirmed.
2012-08-10 17:02:31.201100 [DEBUG] switch_ivr_play_say.c:2361 done speaking text
2012-08-10 17:02:31.201100 [DEBUG] switch_core_session.c:1056 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:31.201100 [DEBUG] mod_event_socket.c:2644 (sofia/external/40505060) State Change CS_EXECUTE -> CS_RESET
2012-08-10 17:02:31.201100 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:31.221213 [DEBUG] switch_ivr.c:598 sofia/external/40505060 Command Execute hangup()
EXECUTE sofia/external/40505060 hangup()
2012-08-10 17:02:31.221213 [DEBUG] switch_channel.c:2849 (sofia/external/40505060) Callstate Change ACTIVE -> HANGUP
2012-08-10 17:02:31.221213 [NOTICE] mod_dptools.c:1134 Hangup sofia/external/40505060 [CS_RESET] [NORMAL_CLEARING]
2012-08-10 17:02:31.221213 [DEBUG] switch_channel.c:2872 Send signal sofia/external/40505060 [KILL]
2012-08-10 17:02:31.221213 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:31.221213 [DEBUG] switch_core_session.c:2329 sofia/external/40505060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2012-08-10 17:02:31.221213 [DEBUG] switch_core_session.c:2329 sofia/external/40505060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2012-08-10 17:02:31.221213 [DEBUG] switch_core_state_machine.c:437 (sofia/external/40505060) State EXECUTE going to sleep
2012-08-10 17:02:31.221213 [DEBUG] switch_core_state_machine.c:382 (sofia/external/40505060) Running State Change CS_HANGUP
2012-08-10 17:02:31.221213 [DEBUG] switch_core_state_machine.c:622 (sofia/external/40505060) State HANGUP
2012-08-10 17:02:31.221213 [DEBUG] mod_sofia.c:473 Channel sofia/external/40505060 hanging up, cause: NORMAL_CLEARING
2012-08-10 17:02:31.221213 [DEBUG] mod_sofia.c:521 Sending BYE to sofia/external/40505060
2012-08-10 17:02:31.221213 [DEBUG] switch_core_state_machine.c:47 sofia/external/40505060 Standard HANGUP, cause: NORMAL_CLEARING
2012-08-10 17:02:31.221213 [DEBUG] switch_core_state_machine.c:622 (sofia/external/40505060) State HANGUP going to sleep
2012-08-10 17:02:31.221213 [DEBUG] switch_core_state_machine.c:413 (sofia/external/40505060) State Change CS_HANGUP -> CS_REPORTING
2012-08-10 17:02:31.221213 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:31.221213 [DEBUG] switch_core_state_machine.c:382 (sofia/external/40505060) Running State Change CS_REPORTING
2012-08-10 17:02:31.221213 [DEBUG] switch_core_state_machine.c:682 (sofia/external/40505060) State REPORTING
2012-08-10 17:02:31.221213 [DEBUG] switch_core_state_machine.c:79 sofia/external/40505060 Standard REPORTING, cause: NORMAL_CLEARING
2012-08-10 17:02:31.221213 [DEBUG] switch_core_state_machine.c:682 (sofia/external/40505060) State REPORTING going to sleep
2012-08-10 17:02:31.221213 [DEBUG] switch_core_state_machine.c:407 (sofia/external/40505060) State Change CS_REPORTING -> CS_DESTROY
2012-08-10 17:02:31.241207 [DEBUG] switch_core_session.c:1224 Send signal sofia/external/40505060 [BREAK]
2012-08-10 17:02:31.241207 [DEBUG] switch_core_session.c:1424 Session 1 (sofia/external/40505060) Locked, Waiting on external entities
2012-08-10 17:02:31.241207 [NOTICE] switch_core_session.c:1442 Session 1 (sofia/external/40505060) Ended
2012-08-10 17:02:31.241207 [NOTICE] switch_core_session.c:1444 Close Channel sofia/external/40505060 [CS_DESTROY]
2012-08-10 17:02:31.241207 [DEBUG] switch_core_state_machine.c:511 (sofia/external/40505060) Callstate Change HANGUP -> DOWN
2012-08-10 17:02:31.241207 [DEBUG] switch_core_state_machine.c:514 (sofia/external/40505060) Running State Change CS_DESTROY
2012-08-10 17:02:31.241207 [DEBUG] switch_core_state_machine.c:524 (sofia/external/40505060) State DESTROY
2012-08-10 17:02:31.241207 [DEBUG] mod_sofia.c:378 sofia/external/40505060 SOFIA DESTROY
2012-08-10 17:02:31.241207 [DEBUG] switch_core_state_machine.c:86 sofia/external/40505060 Standard DESTROY
2012-08-10 17:02:31.241207 [DEBUG] switch_core_state_machine.c:524 (sofia/external/40505060) State DESTROY going to sleep
freeswitch@internal>


///////////////////////////////////////////////


/usr/share/plivo/tmp# cat plivo-outbound.log
2012-08-10 13:11:25,671 plivo-outbound[1213]: INFO: OutboundServer started at '127.0.0.1:8084'
2012-08-10 17:02:29,253 plivo-outbound[1213]: INFO: (1) New request from ('127.0.0.1', 36782)
2012-08-10 17:02:29,254 plivo-outbound[1213]: DEBUG: (1) Execute: connect args=''
2012-08-10 17:02:29,268 plivo-outbound[1213]: DEBUG: (1) Response: <CommandResponse headers={'variable_sip_use_codec_rate': '8000', 'Channel-Channel-Progress-Media-Time': '0', 'variable_sip_use_codec_ptime': '20', 'Caller-Screen-Bit': 'true', 'variable_is_outbound': 'true', 'Call-Direction': 'outbound', 'Channel-Read-Codec-Bit-Rate': '64000', 'Event-Calling-Line-Number': '1876', 'variable_sip_req_uri': '40505060@190.7.192.133', 'variable_sip_full_from': '"" <sip:3788910843@190.7.192.133>;tag=H9gKSXSj2DgFc', 'Reply-Text': '+OK\n', 'variable_call_uuid': '7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_sip_contact_uri': '40505060@190.7.192.133:5060', 'Channel-Channel-Created-Time': '1344639749101113', 'Event-Date-GMT': 'Fri, 10 Aug 2012 23:02:29 GMT', 'Event-Date-Timestamp': '1344639749261200', 'Event-Name': 'CHANNEL_DATA', 'FreeSWITCH-Switchname': 'newfies', 'Unique-ID': '7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_originate_early_media': 'false', 'Control': 'full', 'Caller-Caller-ID-Number': '40505060', 'variable_channel_name': 'sofia/external/40505060', 'Caller-Privacy-Hide-Number': 'false', 'variable_sip_audio_recv_pt': '8', 'variable_sip_recover_via': 'SIP/2.0/UDP 192.168.6.29:5080;branch=z9hG4bKKe52aQZ1Ur7gD;received=192.168.6.29;rport=5080', 'Channel-Write-Codec-Bit-Rate': '64000', 'Content-Type': 'command/reply', 'Channel-Write-Codec-Rate': '8000', 'variable_sip_to_user': '40505060', 'Event-Date-Local': '2012-08-10 17:02:29', 'Channel-Channel-Answered-Time': '1344639749241103', 'Event-Calling-Function': 'parse_command', 'variable_socket_host': '127.0.0.1', 'Caller-Destination-Number': '40505060', 'variable_sip_local_sdp_str': 'v=0\no=FreeSWITCH 1344615777 1344615778 IN IP4 192.168.6.29\ns=FreeSWITCH\nc=IN IP4 192.168.6.29\nt=0 0\nm=audio 23972 RTP/AVP 8 101 13\na=rtpmap:101 telephone-event/8000\na=fmtp:101 0-16\na=ptime:20\na=sendrecv\n', 'Caller-Profile-Index': '1', 'Channel-State': 'CS_EXECUTE', 'variable_plivo_to': '40505060', 'variable_plivo_app': 'true', 'variable_sip_contact_port': '5060', 'Caller-Caller-ID-Name': 'Outbound Call', 'Core-UUID': '322ff6d0-e31f-11e1-ba29-d5c5d8e78830', 'Caller-Profile-Created-Time': '1344639749101113', 'variable_sip_call_id': '4cd88b72-5de2-1230-8f91-000c29168f72', 'variable_plivo_from': '88888888', 'Caller-Channel-Answered-Time': '1344639749241103', 'variable_switch_r_sdp': 'v=0\r\no=root 738656834 738656834 IN IP4 190.7.192.133\r\ns=Asterisk PBX 1.8.11-cert1\r\nc=IN IP4 190.7.192.133\r\nt=0 0\r\nm=audio 11082 RTP/AVP 8 101\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-16\r\na=ptime:20\r\n', 'Answer-State': 'answered', 'Caller-Privacy-Hide-Name': 'false', 'variable_plivo_answer_url': 'http://192.168.6.29:8008/api/v1/answercall/', 'variable_remote_media_ip': '190.7.192.133', 'variable_write_codec': 'PCMA', 'Caller-Context': 'default', 'variable_sip_to_uri': '40505060@190.7.192.133', 'variable_sip_reply_port': '5060', 'variable_read_codec': 'PCMA', 'Channel-Channel-Progress-Time': '0', 'Caller-Channel-Created-Time': '1344639749101113', 'variable_endpoint_disposition': 'ANSWER', 'Channel-Context': 'default', 'variable_sip_from_tag': 'H9gKSXSj2DgFc', 'Channel-Channel-Transfer-Time': '0', 'variable_sip_from_uri': '3788910843@190.7.192.133', 'Channel-Channel-Hangup-Time': '0', 'Event-Sequence': '2213', 'Caller-Channel-Progress-Media-Time': '0', 'variable_sip_full_via': 'SIP/2.0/UDP 192.168.6.29:5080;branch=z9hG4bKKe52aQZ1Ur7gD;received=192.168.6.29;rport=5080', 'Channel-Read-Codec-Rate': '8000', 'Channel-Profile-Index': '1', 'Channel-Direction': 'outbound', 'variable_sip_recover_contact': '<sip:40505060@190.7.192.133:5060>', 'Channel-Name': 'sofia/external/40505060', 'variable_sip_reply_host': '190.7.192.133', 'variable_sofia_profile_name': 'external', 'variable_hangup_after_bridge': 'true', 'variable_current_application_data': '127.0.0.1:8084 async full', 'Channel-Privacy-Hide-Name': 'false', 'Channel-State-Number': '4', 'variable_advertised_media_ip': '192.168.6.29', 'variable_sip_destination_url': 'sip:40505060@190.7.192.133', 'Channel-Call-UUID': '7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_bridge_early_media': 'true', 'Channel-Caller-ID-Name': 'Outbound Call', 'variable_absolute_codec_string': 'PCMA', 'variable_local_media_ip': '192.168.6.29', 'variable_rtp_use_ssrc': '2911252312', 'Caller-Source': 'src/switch_ivr_originate.c', 'variable_sip_network_ip': '190.7.192.133', 'Caller-Channel-Name': 'sofia/external/40505060', 'FreeSWITCH-IPv4': '192.168.6.29', 'FreeSWITCH-IPv6': '::1', 'Channel-Network-Addr': '190.7.192.133', 'variable_sip_full_to': '<sip:40505060@190.7.192.133>;tag=as56a3ffc5', 'Channel-HIT-Dialplan': 'true', 'variable_local_media_port': '23972', 'variable_sip_gateway_name': '190.7.192.133', 'variable_originate_timeout': '1800', 'variable_current_application': 'socket', 'variable_sip_profile_name': 'gateway', 'Event-Calling-File': 'mod_event_socket.c', 'Channel-Destination-Number': '40505060', 'variable_remote_media_port': '11082', 'Channel-Write-Codec-Name': 'PCMA', 'variable_sip_from_user': '3788910843', 'Channel-Source': 'src/switch_ivr_originate.c', 'Channel-Profile-Created-Time': '1344639749101113', 'variable_sip_network_port': '5060', 'Caller-Unique-ID': '7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_sip_user_agent': 'Asterisk PBX 1.8.11-cert1', 'Channel-Screen-Bit': 'true', 'variable_origination_caller_id_number': '88888888', 'Presence-Call-Direction': 'outbound', 'variable_sip_to_host': '190.7.192.133', 'variable_sip_2833_send_payload': '101', 'Channel-Read-Codec-Name': 'PCMA', 'variable_write_rate': '8000', 'variable_sip_contact_user': '40505060', 'variable_sip_contact_host': '190.7.192.133', 'variable_pre_transfer_caller_id_number': '88888888', 'variable_sip_local_network_addr': '192.168.6.29', 'variable_plivo_request_uuid': '7577abca-e33f-11e1-96c0-000c29168f72', 'variable_sip_cseq': '31983811', 'variable_read_rate': '8000', 'variable_sip_from_host': '190.7.192.133', 'variable_sip_to_tag': 'as56a3ffc5', 'Caller-Channel-Hangup-Time': '0', 'variable_sip_2833_recv_payload': '101', 'Channel-Caller-ID-Number': '40505060', 'Channel-Channel-Name': 'sofia/external/40505060', 'variable_sip_use_pt': '8', 'Channel-Privacy-Hide-Number': 'false', 'Caller-Direction': 'outbound', 'variable_uuid': '7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_direction': 'outbound', 'variable_sip_outgoing_contact_uri': '<sip:gw+190.7.192.133@192.168.6.29:5080;transport=udp;gw=190.7.192.133>', 'Caller-Network-Addr': '190.7.192.133', 'variable_plivo_hangup_url': 'http://192.168.6.29:8008/api/v1/hangupcall/', 'Channel-Unique-ID': '7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_ignore_early_media': 'true', 'Caller-Channel-Transfer-Time': '0', 'variable_session_id': '1', 'Socket-Mode': 'async', 'variable_sip_use_codec_name': 'PCMA', 'Caller-Channel-Progress-Time': '0', 'FreeSWITCH-Hostname': 'newfies', 'Channel-Call-State': 'ACTIVE'}, body=>
2012-08-10 17:02:29,268 plivo-outbound[1213]: DEBUG: (1) Execute: resume args=''
2012-08-10 17:02:29,273 plivo-outbound[1213]: DEBUG: (1) Response: <CommandResponse headers={'Content-Type': 'command/reply', 'Reply-Text': '+OK'}, body=>
2012-08-10 17:02:29,273 plivo-outbound[1213]: DEBUG: (1) Execute: linger args=''
2012-08-10 17:02:29,277 plivo-outbound[1213]: DEBUG: (1) Response: <CommandResponse headers={'Content-Type': 'command/reply', 'Reply-Text': '+OK will linger 0 seconds'}, body=>
2012-08-10 17:02:29,278 plivo-outbound[1213]: DEBUG: (1) Execute: myevents json args=''
2012-08-10 17:02:29,282 plivo-outbound[1213]: DEBUG: (1) Response: <CommandResponse headers={'Content-Type': 'command/reply', 'Reply-Text': '+OK Events Enabled'}, body=>
2012-08-10 17:02:29,282 plivo-outbound[1213]: DEBUG: (1) Execute: divert_events args='on'
2012-08-10 17:02:29,285 plivo-outbound[1213]: DEBUG: (1) Response: <CommandResponse headers={'Content-Type': 'command/reply', 'Reply-Text': '+OK events diverted'}, body=>
2012-08-10 17:02:29,285 plivo-outbound[1213]: DEBUG: (1) Execute: event json args='CUSTOM conference::maintenance plivo::dial'
2012-08-10 17:02:29,286 plivo-outbound[1213]: DEBUG: (1) Response: <CommandResponse headers={'Content-Type': 'command/reply', 'Reply-Text': '+OK event listener enabled json'}, body=>
2012-08-10 17:02:29,286 plivo-outbound[1213]: DEBUG: (1) Execute: set args=plivo_app=true, uuid='', lock=True, loops=1
2012-08-10 17:02:29,287 plivo-outbound[1213]: DEBUG: (1) Response: <CommandResponse headers={'Content-Type': 'command/reply', 'Reply-Text': '+OK'}, body=>
2012-08-10 17:02:29,288 plivo-outbound[1213]: DEBUG: (1) Execute: set args=hangup_after_bridge=false, uuid='', lock=True, loops=1
2012-08-10 17:02:29,289 plivo-outbound[1213]: DEBUG: (1) Response: <CommandResponse headers={'Content-Type': 'command/reply', 'Reply-Text': '+OK'}, body=>
2012-08-10 17:02:29,289 plivo-outbound[1213]: INFO: (1) Using AnswerUrl http://192.168.6.29:8008/api/v1/answercall/
2012-08-10 17:02:29,289 plivo-outbound[1213]: INFO: (1) Processing Call
2012-08-10 17:02:29,290 plivo-outbound[1213]: INFO: (1) Fetching RESTXML from http://192.168.6.29:8008/api/v1/answercall/
2012-08-10 17:02:29,291 plivo-outbound[1213]: INFO: (1) Fetching POST http://192.168.6.29:8008/api/v1/answercall/ with {'variable_waitmsec': '', 'variable_progress_mediamsec': '', 'variable_billmsec': '', 'variable_user_context': '', 'To': '40505060', 'variable_progressmsec': '', 'From': '88888888', 'variable_plivo_app': 'true', 'CallStatus': 'in-progress', 'variable_mduration': '', 'Channel-Read-Codec-Bit-Rate': '64000', 'variable_call_uuid': '7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_hangup_cause': '', 'variable_answersec': '', 'variable_plivo_answer_url': 'http://192.168.6.29:8008/api/v1/answercall/', 'variable_caller_id': '', 'CallerName': 'Outbound Call', 'Direction': 'outbound', 'variable_origination_caller_id_number': '88888888', 'variable_direction': 'outbound', 'variable_answermsec': '', 'CallUUID': '7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'ALegRequestUUID': '7577abca-e33f-11e1-96c0-000c29168f72', 'variable_hangup_cause_q850': '', 'variable_progresssec': '', 'variable_answer_uepoch': '', 'ALegUUID': '7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_answer_epoch': '', 'variable_waitsec': '', 'variable_billsec': '', 'variable_duration': '', 'variable_endpoint_disposition': 'ANSWER'}
2012-08-10 17:02:29,355 plivo-outbound[1213]: INFO: (1) Sent to POST http://192.168.6.29:8008/api/v1/answercall/ with {'variable_waitmsec': '', 'variable_progress_mediamsec': '', 'variable_billmsec': '', 'variable_user_context': '', 'To': '40505060', 'variable_progressmsec': '', 'From': '88888888', 'variable_plivo_app': 'true', 'CallStatus': 'in-progress', 'variable_mduration': '', 'Channel-Read-Codec-Bit-Rate': '64000', 'variable_call_uuid': '7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_hangup_cause': '', 'variable_answersec': '', 'variable_plivo_answer_url': 'http://192.168.6.29:8008/api/v1/answercall/', 'variable_caller_id': '', 'CallerName': 'Outbound Call', 'Direction': 'outbound', 'variable_origination_caller_id_number': '88888888', 'variable_direction': 'outbound', 'variable_answermsec': '', 'CallUUID': '7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'ALegRequestUUID': '7577abca-e33f-11e1-96c0-000c29168f72', 'variable_hangup_cause_q850': '', 'variable_progresssec': '', 'variable_answer_uepoch': '', 'ALegUUID': '7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_answer_epoch': '', 'variable_waitsec': '', 'variable_billsec': '', 'variable_duration': '', 'variable_endpoint_disposition': 'ANSWER'} -- Result: <?xml version="1.0" encoding="utf-8"?>
<Response><Speak>Hello World</Speak></Response>
2012-08-10 17:02:29,355 plivo-outbound[1213]: INFO: (1) Requested RESTXML to http://192.168.6.29:8008/api/v1/answercall/
2012-08-10 17:02:29,356 plivo-outbound[1213]: INFO: (1) [Speak] Hello World {'engine': 'flite', 'language': 'en', 'voice': 'slt', 'type': '', 'method': '', 'loop': 1}
2012-08-10 17:02:29,356 plivo-outbound[1213]: DEBUG: (1) Execute: speak args=flite|slt|Hello World, uuid='', lock=True, loops=1
2012-08-10 17:02:29,357 plivo-outbound[1213]: DEBUG: (1) Response: <CommandResponse headers={'Content-Type': 'command/reply', 'Reply-Text': '+OK'}, body=>
2012-08-10 17:02:29,357 plivo-outbound[1213]: DEBUG: (1) Speaking 1 times ...
2012-08-10 17:02:29,357 plivo-outbound[1213]: DEBUG: (1) wait for action start
2012-08-10 17:02:31,204 plivo-outbound[1213]: DEBUG: (1) wait for action end <JsonEvent headers={u'variable_sip_use_codec_rate': u'8000', u'variable_sip_use_codec_ptime': u'20', u'Caller-Screen-Bit': u'true', u'variable_is_outbound': u'true', u'Call-Direction': u'outbound', u'Channel-Read-Codec-Bit-Rate': u'64000', u'Event-Calling-Line-Number': u'2319', u'variable_sip_req_uri': u'40505060@190.7.192.133', u'variable_sip_full_from': u'"" <sip:3788910843@190.7.192.133>;tag=H9gKSXSj2DgFc', u'variable_plivo_from': u'88888888', u'variable_call_uuid': u'7579c96e-e33f-11e1-ba33-d5c5d8e78830', u'variable_sip_contact_uri': u'40505060@190.7.192.133:5060', u'Event-Date-GMT': u'Fri, 10 Aug 2012 23:02:31 GMT', u'Event-Date-Timestamp': u'1344639751201100', u'Event-Name': u'CHANNEL_EXECUTE_COMPLETE', u'FreeSWITCH-Switchname': u'newfies', u'Application-Response': u'_none_', u'Unique-ID': u'7579c96e-e33f-11e1-ba33-d5c5d8e78830', u'Application-Data': u'flite|slt|Hello World', u'Caller-Caller-ID-Number': u'40505060', u'variable_channel_name': u'sofia/external/40505060', u'Caller-Privacy-Hide-Number': u'false', u'variable_sip_audio_recv_pt': u'8', u'variable_sip_recover_via': u'SIP/2.0/UDP 192.168.6.29:5080;branch=z9hG4bKKe52aQZ1Ur7gD;received=192.168.6.29;rport=5080', u'Channel-Write-Codec-Bit-Rate': u'64000', u'Channel-Write-Codec-Rate': u'8000', u'variable_sip_to_user': u'40505060', u'Event-Date-Local': u'2012-08-10 17:02:31', u'Event-Calling-Function': u'switch_core_session_exec', u'variable_socket_host': u'127.0.0.1', u'Caller-Destination-Number': u'40505060', u'variable_sip_local_sdp_str': u'v=0\no=FreeSWITCH 1344615777 1344615778 IN IP4 192.168.6.29\ns=FreeSWITCH\nc=IN IP4 192.168.6.29\nt=0 0\nm=audio 23972 RTP/AVP 8 101 13\na=rtpmap:101 telephone-event/8000\na=fmtp:101 0-16\na=ptime:20\na=sendrecv\n', u'Caller-Profile-Index': u'1', u'Channel-State': u'CS_EXECUTE', u'variable_plivo_to': u'40505060', u'variable_sip_contact_port': u'5060', u'Core-UUID': u'322ff6d0-e31f-11e1-ba29-d5c5d8e78830', u'Caller-Profile-Created-Time': u'1344639749101113', u'variable_sip_call_id': u'4cd88b72-5de2-1230-8f91-000c29168f72', u'variable_ignore_early_media': u'true', u'Caller-Channel-Answered-Time': u'1344639749241103', u'variable_switch_r_sdp': u'v=0\r\no=root 738656834 738656834 IN IP4 190.7.192.133\r\ns=Asterisk PBX 1.8.11-cert1\r\nc=IN IP4 190.7.192.133\r\nt=0 0\r\nm=audio 11082 RTP/AVP 8 101\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-16\r\na=ptime:20\r\n', u'Answer-State': u'answered', u'Caller-Privacy-Hide-Name': u'false', u'variable_plivo_answer_url': u'http://192.168.6.29:8008/api/v1/answercall/', u'variable_remote_media_ip': u'190.7.192.133', u'variable_write_codec': u'PCMA', u'Caller-Context': u'default', u'variable_sip_to_uri': u'40505060@190.7.192.133', u'variable_sip_reply_port': u'5060', u'variable_read_codec': u'PCMA', u'Caller-Channel-Created-Time': u'1344639749101113', u'variable_endpoint_disposition': u'ANSWER', u'variable_sip_from_tag': u'H9gKSXSj2DgFc', u'Application': u'speak', u'variable_sip_from_uri': u'3788910843@190.7.192.133', u'Event-Sequence': u'2228', u'Caller-Channel-Progress-Media-Time': u'0', u'variable_sip_full_via': u'SIP/2.0/UDP 192.168.6.29:5080;branch=z9hG4bKKe52aQZ1Ur7gD;received=192.168.6.29;rport=5080', u'Channel-Read-Codec-Rate': u'8000', u'variable_plivo_app': u'true', u'Caller-Caller-ID-Name': u'Outbound Call', u'variable_sip_recover_contact': u'<sip:40505060@190.7.192.133:5060>', u'Channel-Name': u'sofia/external/40505060', u'variable_sip_reply_host': u'190.7.192.133', u'variable_sofia_profile_name': u'external', u'variable_hangup_after_bridge': u'false', u'variable_current_application_data': u'flite|slt|Hello World', u'variable_local_media_ip': u'192.168.6.29', u'Channel-State-Number': u'4', u'variable_advertised_media_ip': u'192.168.6.29', u'variable_sip_destination_url': u'sip:40505060@190.7.192.133', u'Channel-Call-UUID': u'7579c96e-e33f-11e1-ba33-d5c5d8e78830', u'variable_bridge_early_media': u'true', u'variable_absolute_codec_string': u'PCMA', u'variable_rtp_use_ssrc': u'2911252312', u'Caller-Source': u'src/switch_ivr_originate.c', u'variable_sip_network_ip': u'190.7.192.133', u'Caller-Channel-Name': u'sofia/external/40505060', u'FreeSWITCH-IPv4': u'192.168.6.29', u'FreeSWITCH-IPv6': u'::1', u'variable_originate_early_media': u'false', u'variable_sip_full_to': u'<sip:40505060@190.7.192.133>;tag=as56a3ffc5', u'Channel-HIT-Dialplan': u'true', u'variable_local_media_port': u'23972', u'variable_sip_gateway_name': u'190.7.192.133', u'variable_originate_timeout': u'1800', u'variable_current_application': u'speak', u'variable_sip_profile_name': u'gateway', u'Event-Calling-File': u'switch_core_session.c', u'variable_remote_media_port': u'11082', u'Channel-Write-Codec-Name': u'PCMA', u'variable_session_id': u'1', u'variable_sip_network_port': u'5060', u'Caller-Unique-ID': u'7579c96e-e33f-11e1-ba33-d5c5d8e78830', u'variable_sip_user_agent': u'Asterisk PBX 1.8.11-cert1', u'variable_origination_caller_id_number': u'88888888', u'Presence-Call-Direction': u'outbound', u'variable_sip_to_host': u'190.7.192.133', u'variable_sip_2833_send_payload': u'101', u'Channel-Read-Codec-Name': u'PCMA', u'variable_write_rate': u'8000', u'variable_sip_contact_user': u'40505060', u'variable_sip_contact_host': u'190.7.192.133', u'variable_pre_transfer_caller_id_number': u'88888888', u'variable_sip_local_network_addr': u'192.168.6.29', u'variable_plivo_request_uuid': u'7577abca-e33f-11e1-96c0-000c29168f72', u'variable_sip_cseq': u'31983811', u'variable_read_rate': u'8000', u'variable_sip_from_host': u'190.7.192.133', u'variable_sip_to_tag': u'as56a3ffc5', u'Caller-Channel-Hangup-Time': u'0', u'variable_sip_2833_recv_payload': u'101', u'variable_sip_use_pt': u'8', u'Caller-Direction': u'outbound', u'variable_uuid': u'7579c96e-e33f-11e1-ba33-d5c5d8e78830', u'variable_direction': u'outbound', u'variable_sip_outgoing_contact_uri': u'<sip:gw+190.7.192.133@192.168.6.29:5080;transport=udp;gw=190.7.192.133>', u'Caller-Network-Addr': u'190.7.192.133', u'variable_plivo_hangup_url': u'http://192.168.6.29:8008/api/v1/hangupcall/', u'Caller-Channel-Transfer-Time': u'0', u'variable_sip_from_user': u'3788910843', u'variable_sip_use_codec_name': u'PCMA', u'Caller-Channel-Progress-Time': u'0', u'FreeSWITCH-Hostname': u'newfies', u'Channel-Call-State': u'ACTIVE', u'variable_socket_resume': u'true'}, body=>
2012-08-10 17:02:31,204 plivo-outbound[1213]: DEBUG: (1) Speak 1 times done (_none_)
2012-08-10 17:02:31,213 plivo-outbound[1213]: INFO: (1) Speak Finished
2012-08-10 17:02:31,214 plivo-outbound[1213]: INFO: (1) [Speak] Done
2012-08-10 17:02:31,214 plivo-outbound[1213]: WARNING: (1) No more Elements !
2012-08-10 17:02:31,214 plivo-outbound[1213]: DEBUG: (1) Execute: api args='uuid_getvar 7579c96e-e33f-11e1-ba33-d5c5d8e78830 plivo_transfer_progress'
2012-08-10 17:02:31,215 plivo-outbound[1213]: DEBUG: (1) Response: <ApiResponse headers={'Content-Length': '7', 'Content-Type': 'api/response'}, body=_undef_>
2012-08-10 17:02:31,215 plivo-outbound[1213]: INFO: (1) No more Elements, Hangup Now !
2012-08-10 17:02:31,215 plivo-outbound[1213]: DEBUG: (1) Execute: hangup args=, uuid='', lock=True, loops=1
2012-08-10 17:02:31,216 plivo-outbound[1213]: DEBUG: (1) Response: <CommandResponse headers={'Content-Type': 'command/reply', 'Reply-Text': '+OK'}, body=>
2012-08-10 17:02:31,216 plivo-outbound[1213]: INFO: (1) End of RESTXML
2012-08-10 17:02:31,216 plivo-outbound[1213]: INFO: (1) Processing Call Ended
2012-08-10 17:02:31,216 plivo-outbound[1213]: DEBUG: (1) Releasing Connection ...
2012-08-10 17:02:31,217 plivo-outbound[1213]: DEBUG: (1) Releasing Connection Done
2012-08-10 17:02:31,217 plivo-outbound[1213]: INFO: (1) End request from ('127.0.0.1', 36782)


///////////////////////////////////////

/usr/share/plivo/tmp# cat plivo-rest.log
2012-08-10 12:34:46,967 plivo-rest[6942]: INFO: Starting ...
2012-08-10 12:34:46,967 plivo-rest[6942]: WARNING: Logger <plivo.utils.logger.FileLogger object at 0x1653a10>
2012-08-10 12:34:46,968 plivo-rest[6942]: INFO: Config : {'rest_server': {'LOG_LEVEL': 'DEBUG', 'HTTP_ADDRESS': '127.0.0.1:8088', 'CALL_HEARTBEAT_URL': 'http://127.0.0.1:5000/heartbeat/', 'ALLOWED_IPS': '127.0.0.1', 'FS_INBOUND_PASSWORD': 'ClueCon', 'FS_INBOUND_ADDRESS': '127.0.0.1:8021', 'SECRET_KEY': '\\xae$\\xce:k\\x06\\x9d\\n5o\\xb3\\\\xdb\\xa7p1\\xd1(\\xb5\\xad\\xb0\\xe9\\xfe', 'LOG_FILE': '/usr/share/plivo/tmp/plivo-rest.log', 'LOG_TYPE': 'file'}, 'common': {'DEFAULT_ANSWER_URL': 'http://127.0.0.1:5000/answered/', 'CACHE_URL': 'http://127.0.0.1:8089', 'DEFAULT_HTTP_METHOD': 'POST', 'AUTH_TOKEN': 'YYYYYYYYYYYYYYYYYYYYYYYYYYYYYYYY', 'EXTRA_FS_VARS': 'variable_user_context,Channel-Read-Codec-Bit-Rate,variable_plivo_answer_url,variable_plivo_app,variable_direction,variable_endpoint_disposition,variable_hangup_cause,variable_hangup_cause_q850,variable_duration,variable_billsec,variable_progresssec,variable_answersec,variable_waitsec,variable_mduration,variable_billmsec,variable_progressmsec,variable_answermsec,variable_waitmsec,variable_progress_mediamsec,variable_call_uuid,variable_origination_caller_id_number,variable_caller_id,variable_answer_epoch,variable_answer_uepoch', 'CACHE_SCRIPT': '/usr/share/plivo/bin/wavstream.sh', 'AUTH_ID': 'XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX'}, 'outbound_server': {'FS_OUTBOUND_ADDRESS': '127.0.0.1:8084', 'LOG_FILE': '/usr/share/plivo/tmp/plivo-outbound.log', 'LOG_LEVEL': 'DEBUG', 'LOG_TYPE': 'file'}}
2012-08-10 12:34:46,981 plivo-rest[6942]: INFO: Listening HTTP
2012-08-10 12:34:46,981 plivo-rest[6942]: INFO: <class 'gevent.pywsgi.WSGIServer'> mode set
2012-08-10 12:34:46,982 plivo-rest[6942]: INFO: RESTServer starting ...
2012-08-10 12:34:46,986 plivo-rest[6949]: INFO: RESTServer started at: 'http://127.0.0.1:8088'
2012-08-10 12:34:46,986 plivo-rest[6949]: INFO: Trying to connect to FreeSWITCH at: 127.0.0.1:8021
2012-08-10 12:34:47,035 plivo-rest[6949]: INFO: Connected to FreeSWITCH
2012-08-10 13:10:40,148 plivo-rest[6949]: ERROR: Reconnecting in 10 seconds
2012-08-10 13:10:42,274 plivo-rest[6949]: WARNING: Shutdown ...
2012-08-10 13:10:42,275 plivo-rest[6949]: INFO: RESTServer Exited
2012-08-10 13:11:25,257 plivo-rest[1162]: INFO: Starting ...
2012-08-10 13:11:25,269 plivo-rest[1162]: WARNING: Logger <plivo.utils.logger.FileLogger object at 0x12fe990>
2012-08-10 13:11:25,269 plivo-rest[1162]: INFO: Config : {'rest_server': {'LOG_LEVEL': 'DEBUG', 'HTTP_ADDRESS': '127.0.0.1:8088', 'CALL_HEARTBEAT_URL': 'http://127.0.0.1:5000/heartbeat/', 'ALLOWED_IPS': '127.0.0.1', 'FS_INBOUND_PASSWORD': 'ClueCon', 'FS_INBOUND_ADDRESS': '127.0.0.1:8021', 'SECRET_KEY': '\\xae$\\xce:k\\x06\\x9d\\n5o\\xb3\\\\xdb\\xa7p1\\xd1(\\xb5\\xad\\xb0\\xe9\\xfe', 'LOG_FILE': '/usr/share/plivo/tmp/plivo-rest.log', 'LOG_TYPE': 'file'}, 'common': {'DEFAULT_ANSWER_URL': 'http://127.0.0.1:5000/answered/', 'CACHE_URL': 'http://127.0.0.1:8089', 'DEFAULT_HTTP_METHOD': 'POST', 'AUTH_TOKEN': 'YYYYYYYYYYYYYYYYYYYYYYYYYYYYYYYY', 'EXTRA_FS_VARS': 'variable_user_context,Channel-Read-Codec-Bit-Rate,variable_plivo_answer_url,variable_plivo_app,variable_direction,variable_endpoint_disposition,variable_hangup_cause,variable_hangup_cause_q850,variable_duration,variable_billsec,variable_progresssec,variable_answersec,variable_waitsec,variable_mduration,variable_billmsec,variable_progressmsec,variable_answermsec,variable_waitmsec,variable_progress_mediamsec,variable_call_uuid,variable_origination_caller_id_number,variable_caller_id,variable_answer_epoch,variable_answer_uepoch', 'CACHE_SCRIPT': '/usr/share/plivo/bin/wavstream.sh', 'AUTH_ID': 'XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX'}, 'outbound_server': {'FS_OUTBOUND_ADDRESS': '127.0.0.1:8084', 'LOG_FILE': '/usr/share/plivo/tmp/plivo-outbound.log', 'LOG_LEVEL': 'DEBUG', 'LOG_TYPE': 'file'}}
2012-08-10 13:11:25,283 plivo-rest[1162]: INFO: Listening HTTP
2012-08-10 13:11:25,283 plivo-rest[1162]: INFO: <class 'gevent.pywsgi.WSGIServer'> mode set
2012-08-10 13:11:25,284 plivo-rest[1162]: INFO: RESTServer starting ...
2012-08-10 13:11:25,287 plivo-rest[1194]: INFO: RESTServer started at: 'http://127.0.0.1:8088'
2012-08-10 13:11:25,288 plivo-rest[1194]: INFO: Trying to connect to FreeSWITCH at: 127.0.0.1:8021
2012-08-10 13:11:25,334 plivo-rest[1194]: ERROR: Connect failed: Transport failure: [Errno 111] Connection refused
2012-08-10 13:11:25,335 plivo-rest[1194]: ERROR: Reconnecting in 10 seconds
2012-08-10 13:11:35,341 plivo-rest[1194]: INFO: Trying to connect to FreeSWITCH at: 127.0.0.1:8021
2012-08-10 13:11:35,351 plivo-rest[1194]: INFO: Connected to FreeSWITCH
2012-08-10 17:02:29,101 plivo-rest[1194]: DEBUG: RESTAPI Call with [('HangupUrl', u'http://192.168.6.29:8008/api/v1/hangupcall/'), ('From', u'88888888'), ('GatewayTimeouts', u'1800'), ('GatewayCodecs', u"'PCMA,PCMU'"), ('To', u'40505060'), ('GatewayRetries', u'1'), ('AnswerUrl', u'http://192.168.6.29:8008/api/v1/answercall/'), ('ExtraDialString', u'bridge_early_media=true,hangup_after_bridge=true'), ('Gateways', u'sofia/gateway/external::190.7.192.133/')]
2012-08-10 17:02:29,105 plivo-rest[1194]: WARNING: Call Request Spawned for RequestUUID 7577abca-e33f-11e1-96c0-000c29168f72
2012-08-10 17:02:29,105 plivo-rest[1194]: INFO: Call Request Executed
2012-08-10 17:02:29,110 plivo-rest[1194]: INFO: 127.0.0.1 - - [2012-08-10 17:02:29] "POST /v0.1/Call/ HTTP/1.1" 200 227 0.012546

2012-08-10 17:02:29,111 plivo-rest[1194]: DEBUG: Call try for RequestUUID 7577abca-e33f-11e1-96c0-000c29168f72 with Gateway sofia/gateway/external::190.7.192.133/
2012-08-10 17:02:29,112 plivo-rest[1194]: DEBUG: spawn_originate: originate {plivo_request_uuid=7577abca-e33f-11e1-96c0-000c29168f72,plivo_answer_url=http://192.168.6.29:8008/api/v1/answercall/,plivo_ring_url=,plivo_hangup_url=http://192.168.6.29:8008/api/v1/hangupcall/,origination_caller_id_number=88888888,bridge_early_media=true,hangup_after_bridge=true,plivo_from=88888888,plivo_to=40505060,plivo_app=true,absolute_codec_string='PCMA,PCMU',originate_timeout=1800,ignore_early_media=true}sofia/gateway/external::190.7.192.133/40505060 &socket('127.0.0.1:8084 async full')
2012-08-10 17:02:29,123 plivo-rest[1194]: DEBUG: Waiting Call attempt for RequestUUID 7577abca-e33f-11e1-96c0-000c29168f72 ...
2012-08-10 17:02:31,243 plivo-rest[1194]: DEBUG: Notify Call success for RequestUUID 7577abca-e33f-11e1-96c0-000c29168f72
2012-08-10 17:02:31,243 plivo-rest[1194]: INFO: Hangup for Outgoing CallUUID 7579c96e-e33f-11e1-ba33-d5c5d8e78830 Completed, HangupCause NORMAL_CLEARING, RequestUUID 7577abca-e33f-11e1-96c0-000c29168f72
2012-08-10 17:02:31,243 plivo-rest[1194]: DEBUG: Call Cleaned up for RequestUUID 7577abca-e33f-11e1-96c0-000c29168f72
2012-08-10 17:02:31,244 plivo-rest[1194]: INFO: Fetching POST http://192.168.6.29:8008/api/v1/hangupcall/ with {'variable_waitmsec': u'0', 'variable_progress_mediamsec': u'0', 'variable_billmsec': u'1980', 'variable_user_context': '', 'To': u'40505060', 'variable_progressmsec': u'0', 'From': u'88888888', 'variable_plivo_app': u'true', 'CallStatus': 'completed', 'variable_mduration': u'2120', 'Channel-Read-Codec-Bit-Rate': u'64000', 'variable_call_uuid': u'7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_hangup_cause': u'NORMAL_CLEARING', 'variable_answersec': u'0', 'variable_plivo_answer_url': u'http://192.168.6.29:8008/api/v1/answercall/', 'variable_caller_id': u'"Outbound Call" <40505060>', 'HangupCause': u'NORMAL_CLEARING', 'Direction': 'outbound', 'variable_origination_caller_id_number': u'88888888', 'variable_direction': u'outbound', 'variable_answermsec': u'140', 'CallUUID': u'7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'ALegRequestUUID': u'7577abca-e33f-11e1-96c0-000c29168f72', 'variable_hangup_cause_q850': u'16', 'variable_progresssec': u'0', 'variable_answer_uepoch': u'1344639749241103', 'ALegUUID': u'7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_answer_epoch': u'1344639749', 'variable_waitsec': u'0', 'variable_billsec': u'2', 'variable_duration': u'2', 'RequestUUID': u'7577abca-e33f-11e1-96c0-000c29168f72', 'variable_endpoint_disposition': u'ANSWER'}
2012-08-10 17:02:31,267 plivo-rest[1194]: INFO: Call Attempt OK for RequestUUID 7577abca-e33f-11e1-96c0-000c29168f72
2012-08-10 17:02:31,318 plivo-rest[1194]: INFO: Sent to POST http://192.168.6.29:8008/api/v1/hangupcall/ with {'variable_waitmsec': u'0', 'variable_progress_mediamsec': u'0', 'variable_billmsec': u'1980', 'variable_user_context': '', 'To': u'40505060', 'variable_progressmsec': u'0', 'From': u'88888888', 'variable_plivo_app': u'true', 'CallStatus': 'completed', 'variable_mduration': u'2120', 'Channel-Read-Codec-Bit-Rate': u'64000', 'variable_call_uuid': u'7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_hangup_cause': u'NORMAL_CLEARING', 'variable_answersec': u'0', 'variable_plivo_answer_url': u'http://192.168.6.29:8008/api/v1/answercall/', 'variable_caller_id': u'"Outbound Call" <40505060>', 'HangupCause': u'NORMAL_CLEARING', 'Direction': 'outbound', 'variable_origination_caller_id_number': u'88888888', 'variable_direction': u'outbound', 'variable_answermsec': u'140', 'CallUUID': u'7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'ALegRequestUUID': u'7577abca-e33f-11e1-96c0-000c29168f72', 'variable_hangup_cause_q850': u'16', 'variable_progresssec': u'0', 'variable_answer_uepoch': u'1344639749241103', 'ALegUUID': u'7579c96e-e33f-11e1-ba33-d5c5d8e78830', 'variable_answer_epoch': u'1344639749', 'variable_waitsec': u'0', 'variable_billsec': u'2', 'variable_duration': u'2', 'RequestUUID': u'7577abca-e33f-11e1-96c0-000c29168f72', 'variable_endpoint_disposition': u'ANSWER'} -- Result: <?xml version="1.0" encoding="utf-8"?>
<Response><result>OK</result></Response>



////////////////////////////

/usr/share/plivo/tmp# cat plivo-cache.log
2012-08-10 12:34:48,458 plivo-cache[6976]: INFO: Starting ...
2012-08-10 12:34:48,458 plivo-cache[6976]: WARNING: Logger <plivo.utils.logger.FileLogger object at 0x12b3890>
2012-08-10 12:34:48,458 plivo-cache[6976]: WARNING: Cache <plivo.rest.freeswitch.cacheapi.ResourceCache object at 0x16045d0>
2012-08-10 12:34:48,459 plivo-cache[6976]: INFO: Config : {'cache_server': {'LOG_LEVEL': 'DEBUG', 'HTTP_ADDRESS': '127.0.0.1:8089', 'ALLOWED_IPS': '127.0.0.1', 'REDIS_HOST': 'localhost', 'REDIS_DB': '0', 'REDIS_PORT': '6379', 'SECRET_KEY': '\\xee\\xe3\\xf1\\x8a\\xd1;\\xc96|O\\x8d\\xafx5\\xbb\\x18\\x1d\\x8f*\\x93$f_a', 'LOG_FILE': '/usr/share/plivo/tmp/plivo-cache.log', 'LOG_TYPE': 'file'}, 'common': {'AUTH_TOKEN': 'YYYYYYYYYYYYYYYYYYYYYYYYYYYYYYYY', 'AUTH_ID': 'XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX'}}
2012-08-10 12:34:48,460 plivo-cache[6976]: INFO: Listening HTTP
2012-08-10 12:34:48,460 plivo-cache[6976]: INFO: <class 'gevent.pywsgi.WSGIServer'> mode set
2012-08-10 12:34:48,461 plivo-cache[6976]: INFO: CacheServer starting ...
2012-08-10 12:34:48,465 plivo-cache[6983]: INFO: CacheServer started at: 'http://127.0.0.1:8089'
2012-08-10 13:10:42,280 plivo-cache[6983]: WARNING: Shutdown ...
2012-08-10 13:10:42,281 plivo-cache[6983]: INFO: CacheServer Exited
2012-08-10 13:11:27,364 plivo-cache[1302]: INFO: Starting ...
2012-08-10 13:11:27,369 plivo-cache[1302]: WARNING: Logger <plivo.utils.logger.FileLogger object at 0x1c60850>
2012-08-10 13:11:27,369 plivo-cache[1302]: WARNING: Cache <plivo.rest.freeswitch.cacheapi.ResourceCache object at 0x1fb2450>
2012-08-10 13:11:27,369 plivo-cache[1302]: INFO: Config : {'cache_server': {'LOG_LEVEL': 'DEBUG', 'HTTP_ADDRESS': '127.0.0.1:8089', 'ALLOWED_IPS': '127.0.0.1', 'REDIS_HOST': 'localhost', 'REDIS_DB': '0', 'REDIS_PORT': '6379', 'SECRET_KEY': '\\xee\\xe3\\xf1\\x8a\\xd1;\\xc96|O\\x8d\\xafx5\\xbb\\x18\\x1d\\x8f*\\x93$f_a', 'LOG_FILE': '/usr/share/plivo/tmp/plivo-cache.log', 'LOG_TYPE': 'file'}, 'common': {'AUTH_TOKEN': 'YYYYYYYYYYYYYYYYYYYYYYYYYYYYYYYY', 'AUTH_ID': 'XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX'}}
2012-08-10 13:11:27,371 plivo-cache[1302]: INFO: Listening HTTP
2012-08-10 13:11:27,371 plivo-cache[1302]: INFO: <class 'gevent.pywsgi.WSGIServer'> mode set
2012-08-10 13:11:27,371 plivo-cache[1302]: INFO: CacheServer starting ...
2012-08-10 13:11:27,375 plivo-cache[1309]: INFO: CacheServer started at: 'http://127.0.0.1:8089'








