search

plivo / plivoframework

Open Source Telephony Application Prototyping Framework
http://www.plivo.com/open-source/
Other
417 stars 180 forks source link

Dial stops processing after bridge #103

Closed gersmann closed 10 years ago

gersmann commented 11 years ago

Hi,

I have the same problem as described in https://github.com/plivo/plivoframework/issues/26, my issue is maybe going a bit further. Using the dial verb, processing stops after the call has been terminated or ignored by leg B. The action URL is not invoked, I cannot transfer the call via the transfer verb (I get a HTTP 200, but nothing happens, the call is just mute), none of the actions specified after the dial verb get executed.

Any idea on why this might happen?

Cheers, Stefan

gersmann commented 11 years ago

My dialplan is:

<Response>
    <Wait length="1"></Wait>
    <Dial action="http://localhost:3000/callback/call/action" timeout="25" confirmSound="http://localhost:3000/callback/call/sound?type=dial_star_accept" confirmKey="*" dialMusic="http://localhost:3000/callback/call/sound?type=connecting_to" callbackUrl="http://localhost:3000/callback/call/on_bridge">
        <Number gateways="sofia/gateway/sipgate-trunk/" extraDialString="sip_h_P-Preferred-Identity=sip:4989xxxxxx@sipconnect.sipgate.de">+4989xxxxx</Number>
    </Dial>
    <Redirect>http://localhost:3000/callback/call/redirect</Redirect>
</Response>
gersmann commented 11 years ago

Error messages in plivo-outbound.log

2013-08-23 17:36:51,569 plivo-outbound[1339]: WARNING: (83) wait for action end timed out!
2013-08-23 17:36:51,569 plivo-outbound[1339]: DEBUG: (83) wait for action start
2013-08-23 17:36:52,569 plivo-outbound[1339]: WARNING: (123) wait for action end timed out!
2013-08-23 17:36:52,569 plivo-outbound[1339]: DEBUG: (123) wait for action start
2013-08-23 17:37:02,348 plivo-outbound[1339]: WARNING: (90) wait for action end timed out!
2013-08-23 17:37:02,348 plivo-outbound[1339]: DEBUG: (90) wait for action start
2013-08-23 17:37:11,197 plivo-outbound[1339]: WARNING: (119) wait for action end timed out!
2013-08-23 17:37:11,197 plivo-outbound[1339]: DEBUG: (119) wait for action start
2013-08-23 17:37:21,579 plivo-outbound[1339]: WARNING: (83) wait for action end timed out!
2013-08-23 17:37:21,579 plivo-outbound[1339]: DEBUG: (83) wait for action start
2013-08-23 17:37:22,569 plivo-outbound[1339]: WARNING: (123) wait for action end timed out!
2013-08-23 17:37:22,569 plivo-outbound[1339]: DEBUG: (123) wait for action start
govardhan commented 10 years ago

I too find similar behavior. I guess plivo outbound waiting for the event from free-switch to run next action. However freeswitch unable to create channel because B-leg user not registered user. Here are freeswitch logs.

Any idea where the issue?

[WARNING] switch_ivr_originate.c:2041 No origination URL specified! [DEBUG] switch_ivr_originate.c:3533 Originate Resulted in Error Cause: 27 [DESTINATION_OUT_OF_ORDER] [NOTICE] switch_ivr_originate.c:2608 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED] [INFO] switch_ivr_async.c:212 Digit parser DPTOOLS: Setting realm to 'plivo_bda_dial_ab761ec1-907d-4460-ba7c-a40e87f72674' [INFO] mod_dptools.c:3060 Originate Failed. Cause: DESTINATION_OUT_OF_ORDER

gersmann commented 10 years ago

Maybe some more debug information. Apparently Plivo is still waiting for the dial / conference action to finish (which already is finished as the callee hung up).

2013-10-15 18:14:06,947 plivo-outbound[25269]: DEBUG: (2) wait for action start
2013-10-15 18:14:06,948 plivo-outbound[25269]: DEBUG: (2) wait for action end <JsonEvent headers=
{
   u'variable_plivo_dial_rang':u'true',
   u'Caller-Orig-Caller-ID-Name':u'08995453xxx',
   u'variable_recovery_profile_name':u'external',
   u'variable_rtp_use_codec_string':u'G722,
   PCMU,
   PCMA,
   GSM',
   u'Caller-Screen-Bit':u'true',
   u'Call-Direction':u'inbound',
   u'Channel-Read-Codec-Bit-Rate':u'64000',
   u'variable_sip_received_port':u'5060',
   u'Event-Calling-Line-Number':u'2803',
   u'variable_sip_req_uri':   u'4989xxxxxx@10.211.55.8:5080   ', u'   Caller-Source':u'mod_sofia',
   u'variable_sip_full_from':   u'"08995453xxx" <sip:08995453xxx   @sipconnect.sipgate.de>;tag=as2349d448',
   u'variable_call_uuid':u'c253febc-35b4-11e3-b1b8-a10414604d98',
   u'Caller-Channel-Resurrect-Time':u'0',
   u'Caller-ANI':u'08995453xxx',
   u'variable_bridge_channel':u'sofia/external/+491783xxxxxx',
   u'variable_sip_contact_uri':   u'08995453xxx@212.9.44.4:5060   ', u'   variable_playback_seconds':u'1',
   u'Event-Date-GMT':u'Tue,
   15   Oct 2013 16:14:06   GMT',
   u'Event-Date-Timestamp':u'1381853646927283',
   u'Event-Name':u'CHANNEL_EXECUTE_COMPLETE',
   u'FreeSWITCH-Switchname':u'Linxbox',
   u'variable_signal_bond':u'c5059bc0-35b4-11e3-b1d1-a10414604d98',
   u'variable_last_sent_callee_id_name':u'Outbound Call',
   u'Application-Data':u"<api_on_ring='uuid_setvar c253febc-35b4-11e3-b1b8-a10414604d98 plivo_dial_rang true',
   api_on_pre_answer='uuid_setvar c253febc-35b4-11e3-b1b8-a10414604d98 plivo_dial_rang true',
   api_on_answer_1='sched_api +14400 c4ffe98c-35b4-11e3-b921-001c42cefed9 uuid_transfer c253febc-35b4-11e3-b1b8-a10414604d98 -bleg hangup:   ALLOTTED_TIMEOUT inline'>sofia/gateway/sipgate-trunk/+491783xxxxxx:   _:", u'Caller-Channel-Bridged-Time': u'1381853632607086', u'Caller-Callee-ID-Number': u'+491783xxxxx', u'Unique-ID': u'c253febc-35b4-11e3-b1b8-a10414604d98', u'variable_sip_via_host': u'217.10.68.150', u'variable_last_bridge_proto_specific_hangup_cause': u'sip:200', u'Caller-Caller-ID-Number': u'08995453xxx', u'Caller-Username': u'08995453xxx', u'variable_sip_received_ip': u'217.10.68.150', u'Caller-Privacy-Hide-Number': u'false', u'Channel-Write-Codec-Bit-Rate': u'64000', u'Channel-Write-Codec-Rate': u'8000', u'variable_sip_to_user': u'00498941xxxxxx', u'Event-Date-Local': u'2013-10-15 18:14:06', u'Event-Calling-Function': u'switch_core_session_exec', u'variable_socket_host': u'127.0.0.1', u'variable_sip_req_user': u'498941xxxxxx', u'Caller-Destination-Number': u'4989416xxxxxx', u'variable_bridge_uuid': u'c5059bc0-35b4-11e3-b1d1-a10414604d98', u'variable_ep_codec_string': u'PCMA@8000h@20i@64000b,PCMU@8000h@20i@64000b,GSM@8000h@20i@13200b', u'Caller-Profile-Index': u'1', u'Channel-State': u'CS_EXECUTE', u'variable_playback_samples': u'10000', u'variable_plivo_app': u'true', u'variable_sip_contact_port': u'5060', u'variable_rtp_local_sdp_str': u'v=0\no=FreeSWITCH 1381822495 1381822497 IN IP4 10.211.55.8\ns=FreeSWITCH\nc=IN IP4 10.211.55.8\nt=0 0\nm=audio 31130 RTP/AVP 8 101\na=rtpmap:8 PCMA/8000\na=rtpmap:101 telephone-event/8000\na=fmtp:101 0-16\na=ptime:20\na=sendrecv\n', u'variable_rtp_audio_recv_pt': u'8', u'Core-UUID': u'ce10ed3c-35af-11e3-b0ac-a10414604d98', u'Caller-Profile-Created-Time': u'1381853622207128', u'variable_sip_call_id': u'1d8642cc7d4096db7b2523530916307b@sipconnect.sipgate.de', u'variable_sip_via_protocol': u'udp', u'variable_channel_name': u'sofia/external/08995453xxx@sipconnect.sipgate.de', u'Caller-Channel-Answered-Time': u'1381853632607086', u'variable_switch_r_sdp': u'v=0\r\no=root 1507121238 1507121239 IN IP4 217.10.77.23\r\ns=sipgate VoIP GW\r\nc=IN IP4 217.10.77.23\r\nt=0 0\r\nm=audio 54706 RTP/AVP 8 0 3 97 18 112 101\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:3 GSM/8000\r\na=rtpmap:97 iLBC/8000\r\na=fmtp:97 mode=30\r\na=rtpmap:18 G729/8000\r\na=fmtp:18 annexb=no\r\na=rtpmap:112 G726-32/8000\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101 0-16\r\na=silenceSupp:off - - - -\r\na=ptime:20\r\na=direction:active\r\na=nortpproxy:yes\r\n', u'Answer-State': u'answered', u'variable_remote_media_ip': u'217.10.77.23', u'variable_ringback': u'%(2000,4000,440,480)', u'Caller-Context': u'public', u'variable_max_forwards': u'67', u'variable_sip_gateway': u'sipgate-trunk', u'variable_sip_to_uri': u'0049894xxxxxxx@sipconnect.sipgate.de', u'Caller-Channel-Hold-Accum': u'0', u'variable_sip_bye_h_X-hint': u'rr-enforced', u'variable_playback_ms': u'1250', u'variable_rtp_2833_recv_payload': u'101', u'variable_last_sent_callee_id_number': u'+491783xxxxxx', u'Caller-Callee-ID-Name': u'Outbound Call', u'variable_sip_req_params': u'transport=udp;gw=sipgate-trunk', u'variable_sip_invite_record_route': u'<sip:217.10.68.150;lr;ftag=as2349d448>,<sip:172.20.40.5;lr>,<sip:217.10.68.150;lr;ftag=as2349d448>', u'Caller-Channel-Created-Time': u'1381853622207128', u'variable_endpoint_disposition': u'ANSWER', u'variable_sip_from_tag': u'as2349d448', u'variable_continue_on_fail': u'true', u'variable_sip_from_display': u'08995453xxx', u'variable_rtp_use_pt': u'8', u'variable_sip_from_uri': u'08995453xxx@sipconnect.sipgate.de', u'Event-Sequence': u'2037', u'Caller-Channel-Progress-Media-Time': u'1381853625406850', u'Caller-Orig-Caller-ID-Number': u'08995453xxx', u'variable_sofia_profile_name': u'external', u'Channel-Read-Codec-Rate': u'8000', u'variable_sip_via_port': u'5060', u'Caller-Caller-ID-Name': u'08995453xxx', u'Channel-Name': u'sofia/external/08995453xxx@sipconnect.sipgate.de', u'variable_sip_req_port': u'5080', u'variable_outside_call': u'true', u'Caller-Channel-Last-Hold': u'0', u'variable_hangup_after_bridge': u'false', u'variable_current_application_data': u"   <api_on_ring='uuid_setvar c253febc-35b4-11e3-b1b8-a10414604d98 plivo_dial_rang true',
   api_on_pre_answer='uuid_setvar c253febc-35b4-11e3-b1b8-a10414604d98 plivo_dial_rang true',
   api_on_answer_1='sched_api +14400 c4ffe98c-35b4-11e3-b921-001c42cefed9 uuid_transfer c253febc-35b4-11e3-b1b8-a10414604d98 -bleg hangup:   ALLOTTED_TIMEOUT inline'>sofia/gateway/sipgate-trunk/+491783xxxxxx:   _:,
   u'variable_local_media_ip':u'10.211.55.8',
   u'variable_last_bridge_hangup_cause':u'NORMAL_CLEARING',
   u'Channel-State-Number':u'4',
   u'variable_advertised_media_ip':u'10.211.55.8',
   u'Channel-Call-UUID':u'c253febc-35b4-11e3-b1b8-a10414604d98',
   u'variable_bridge_early_media':u'false',
   u'Caller-Dialplan':u'XML',
   u'variable_socket_resume':u'true',
   u'variable_sip_req_host':u'10.211.55.8',
   u'variable_sip_network_ip':u'217.10.68.150',
   u'Caller-Channel-Name':u'sofia/external/08995453xxx@sipconnect.sipgate.de',
   u'FreeSWITCH-IPv4':u'10.211.55.8',
   u'FreeSWITCH-IPv6':   u'::1   ', u'   variable_sip_full_to':   u'<sip:004989xxxxxx   @sipconnect.sipgate.de>;tag=K4pyF27r42ZBp',
   u'variable_bridge_hangup_cause':u'NORMAL_CLEARING',
   u'variable_sip_hangup_phrase':u'OK',
   u'variable_rtp_last_audio_codec_string':u'PCMA@8000h@20i',
   u'Channel-HIT-Dialplan':u'true',
   u'variable_rtp_2833_send_payload':u'101',
   u'variable_local_media_port':u'31130',
   u'Caller-Privacy-Hide-Name':u'false',
   u'variable_sip_to_tag':u'K4pyF27r42ZBp',
   u'variable_current_application':u'bridge',
   u'Application':u'bridge',
   u'Event-Calling-File':u'switch_core_session.c',
   u'variable_remote_media_port':u'54706',
   u'Channel-Write-Codec-Name':u'PCMA',
   u'variable_read_codec':u'PCMA',
   u'variable_session_id':u'20',
   u'variable_originate_disposition':u'success',
   u'variable_DP_MATCH':[
      u'4989416129xxx',
      u'4989416129xxx'
   ],
   u'variable_sip_network_port':u'5060',
   u'Caller-Unique-ID':u'c253febc-35b4-11e3-b1b8-a10414604d98',
   u'variable_sip_to_host':u'sipconnect.sipgate.de',
   u'Presence-Call-Direction':u'inbound',
   u'variable_sip_full_via':   u'SIP/2.0/UDP 217.10.68.150:5060   ;branch=z9hG4bKdc06.1650af22e90ea725ce92123e667649a6.0,
   SIP/2.0/UDP 172.20.40.5;branch=z9hG4bKdc06.baf91408e83a7db98440275dfb07c30e.0,
   SIP/2.0/UDP 217.10.68.150:5060   ;received=217.10.68.178;branch=z9hG4bKdc06.a5bd9cae49ade9709622706905963a07.0,
   SIP/2.0/UDP 212.9.44.4:5060   ;branch=z9hG4bK74ab437e',
   u'Application-UUID':u'c5058874-35b4-11e3-b1cd-a10414604d98',
   u'Channel-Read-Codec-Name':u'PCMA',
   u'variable_write_rate':u'8000',
   u'variable_instant_ringback':u'true',
   u'variable_sip_contact_user':u'08995453xxx',
   u'variable_sip_contact_host':u'212.9.44.4',
   u'variable_sip_local_network_addr':u'10.211.55.8',
   u'variable_sip_cseq':u'103',
   u'variable_read_rate':u'8000',
   u'variable_sip_from_host':u'sipconnect.sipgate.de',
   u'variable_last_bridge_to':u'c5059bc0-35b4-11e3-b1d1-a10414604d98',
   u'Caller-Channel-Hangup-Time':u'0',
   u'variable_RFC2822_DATE':u'Tue,
   15   Oct 2013 18:13:42   +0200',
   u'variable_dtmf_type':u'rfc2833',
   u'Caller-Direction':u'inbound',
   u'variable_uuid':u'c253febc-35b4-11e3-b1b8-a10414604d98',
   u'variable_direction':u'inbound',
   u'Caller-Network-Addr':u'217.10.68.150',
   u'variable_playback_terminators':u'none',
   u'variable_rtp_use_codec_ptime':u'20',
   u'Caller-Channel-Transfer-Time':u'0',
   u'variable_sip_from_user_stripped':u'08995453xxx',
   u'variable_sip_from_user':u'08995453xxx',
   u'Application-Response':u'_none_',
   u'variable_write_codec':u'PCMA',
   u'Caller-Channel-Progress-Time':u'0',
   u'FreeSWITCH-Hostname':u'Linxbox',
   u'Channel-Call-State':u'ACTIVE',
   u'variable_rtp_use_codec_rate':u'8000',
   u'variable_rtp_use_ssrc':u'1314958086',
   u'variable_rtp_use_codec_name':u'PCMA'
}
, body=>
2013-10-15 18:14:06,948 plivo-outbound[25269]: DEBUG: (2) wait for action start
lylepratt commented 10 years ago

@gersmann I'm running into this as well...still having this problem?

gersmann commented 10 years ago

Hi @lylepratt,

regrettably yes. I have a feeling it's some change in Freeswitch which breaks processing the FS events in Plivo. But I don't know enough about Freeswitch to figure out what the root cause is. I just invested some time into figuring out how to use Twilio in combination with a local SIP provider, so I guess I'll make a switch. Spent to many hours on fixing small things with Plivo & Freeswitch already.

Sorry I couldn't help. Good luck.

govardhan commented 10 years ago

Hi Guys,

I tried couple of fixes (shown below) to the latest git repo in my local machine and seems to be working. Let me know your feedback. I have been testing from past couple of weeks, I don't have this issue anymore.

  1. outboundsocket.py – line 185

From

def on_channel_execute_complete(self, event):
    if event['Application'] in self.WAIT_FOR_ACTIONS:

To 

def on_channel_execute_complete(self, event):
    if event['Application'] in self.WAIT_FOR_ACTIONS or event['variable_current_application'] in self.WAIT_FOR_ACTIONS:
  1. elements.py line 929

From

        # waiting event
        for x in range(10000):
            event = outbound_socket.wait_for_action(timeout=30, raise_on_hangup=True)
            if event.is_empty():
                continue

To

        # waiting event
        for x in range(10000):
            event = outbound_socket.wait_for_action(timeout=30, raise_on_hangup=True)
            if event.is_empty():
                continue
            else:
                break
mike-plivo commented 10 years ago

Try the dev branch :

cd /usr/local/plivo/src/plivo git checkout dev

and restart plivo

On Fri, Oct 18, 2013 at 1:43 AM, Admin notifications@github.com wrote:

Hi Guys,

I tried couple of fixes (shown below) to the latest git repo in my local machine and seems to be working. Let me know your feedback. I have been testing from past couple of weeks, I don't have this issue anymore.

  1. outboundsocket.py – line 185

From def on_channel_execute_complete(self, event): if event['Application'] in self.WAIT_FOR_ACTIONS:

To

def on_channel_execute_complete(self, event): if event['Application'] in self.WAIT_FOR_ACTIONS or event['variable_current_application'] in self.WAIT_FOR_ACTIONS:

  1. outboundsocket.py line 929

From

waiting event

for x in range(10000): event = outbound_socket.wait_for_action(timeout=30, raise_on_hangup=True) if event.is_empty(): continue

To

    # waiting event
    for x in range(10000):
        event = outbound_socket.wait_for_action(timeout=30, raise_on_hangup=True)
        if event.is_empty():
            continue
        else:
            break

— Reply to this email directly or view it on GitHubhttps://github.com/plivo/plivoframework/issues/103#issuecomment-26562340 .

lylepratt commented 10 years ago

There doesn't seem to be a dev branch for me...

mike-plivo commented 10 years ago

So try :

cd /usr/local/plivo/src/plivo git pull git checkout -b dev origin/dev

On Fri, Oct 18, 2013 at 2:10 AM, Lyle Pratt notifications@github.comwrote:

There doesn't seem to be a dev branch for me...

— Reply to this email directly or view it on GitHubhttps://github.com/plivo/plivoframework/issues/103#issuecomment-26563558 .

mike-plivo commented 10 years ago

ok should work now, it needed an explicit git push : git push origin dev

On Fri, Oct 18, 2013 at 2:16 AM, Michael Ricordeau < michael.ricordeau@gmail.com> wrote:

So try :

cd /usr/local/plivo/src/plivo git pull git checkout -b dev origin/dev

On Fri, Oct 18, 2013 at 2:10 AM, Lyle Pratt notifications@github.comwrote:

There doesn't seem to be a dev branch for me...

— Reply to this email directly or view it on GitHubhttps://github.com/plivo/plivoframework/issues/103#issuecomment-26563558 .

lylepratt commented 10 years ago

Thanks so much for helping!

I Just tried again, but unfortunately it still doesn't seem to work for me.

My action URL is getting hit, but the call just seems to stall and then finally times out.

lylepratt commented 10 years ago

Actually...I don't think my plivo server is restarting:

Plivo-Rest [default] stopping failed Plivo-Outbound [default] stopping failed Traceback (most recent call last): File "/usr/local/plivo/bin/plivo-rest", line 4, in from pkg_resources import require; require('plivo==0.1.0') File "/usr/local/plivo/local/lib/python2.7/site-packages/pkg_resources.py", line 3011, in parse_requirements(requires), Environment() File "/usr/local/plivo/local/lib/python2.7/site-packages/pkg_resources.py", line 626, in resolve raise DistributionNotFound(req) pkg_resources.DistributionNotFound: plivo==0.1.0 Traceback (most recent call last): File "/usr/local/plivo/bin/plivo-outbound", line 4, in from pkg_resources import require; require('plivo==0.1.1') File "/usr/local/plivo/local/lib/python2.7/site-packages/pkg_resources.py", line 3011, in parse_requirements(requires), Environment() File "/usr/local/plivo/local/lib/python2.7/site-packages/pkg_resources.py", line 626, in resolve raise DistributionNotFound(req) pkg_resources.DistributionNotFound: plivo==0.1.0 Plivo-Rest [default] start failed Plivo-Outbound [default] start failed

lylepratt commented 10 years ago

Ok, I fixed that, but sadly, still no continuation after bridge hangup or reject.

lylepratt commented 10 years ago

I believe this issue is stemming from the fact that if you ignore a call by not pressing a key "variable_hangup_cause" is set to "DESTINATION_OUT_OF_ORDER".

    "variable_current_application": "bridge",
    "variable_plivo_dial_rang": "true",
    "variable_originate_disposition":   "failure",
    "variable_hangup_cause":    "DESTINATION_OUT_OF_ORDER"
govardhan commented 10 years ago

@lylepratt I forked the code and committed changes. These changes solved the issue. You can give a try.

lylepratt commented 10 years ago

@govardhan your changes prevent callers from accepting calls by pressing a key. So, while it fixes the issue with Plivo not following action redirects, it now redirects whether you accept or not.

lylepratt commented 10 years ago

I was able to get it to work properly (whether accepting the call by pressing a key, or hanging up and rejecting it) by adding one addition to elements.py on line 939 on @tamiel 's DEV branch:

                elif event['Event-Name'] == 'CHANNEL_BRIDGE':
                    outbound_socket.log.info("Dial bridged")
                elif event['Event-Name'] == 'CHANNEL_UNBRIDGE':
                    outbound_socket.log.info("Dial unbridged")
                    break
                elif event['Event-Name'] == 'CHANNEL_EXECUTE_COMPLETE':
                    outbound_socket.log.info("Dial complete")
                    break
mike-plivo commented 10 years ago

Thanks Lyle .

Can you add the details of the CHANNEL_EXECUTE_COMPLETE event and paste it here ?

    elif event['Event-Name'] == 'CHANNEL_EXECUTE_COMPLETE':
       outbound_socket.log.info("Dial complete %s" % str(event))
       break
gersmann commented 10 years ago

Thanks a lot, @lylepratt. This was causing me a lot of headache, your patch fixes the issue for me.

mike-plivo commented 10 years ago

merged to master branch, closing the issue, reopen it if needed .

emamirazavi commented 10 years ago

I check out last source but i can not continue to next elements correctly!!! I play goodbye sound and it's processed but after you press any key on your phone this sound plays but on no existed uuid! channel has hunged up already! It's very important that why dial element annoys me by wait for action?!!! I want to continue parsing and processing on my own XMLs but it stays on that bridge already being hunged up and does not give it up! Other problem here is that it may exist some variables passed by b leg in current case we don't get extra variables from channel on unbridge event! i'm wrong?!

I want to continue without pressing any key, just at unbridging b leg this may occur by b leg referring a leg to other user or extension or any other events or give a leg to plivo XMLs

plivo-outbound log: Dial element on Redirect goes here:

2014-01-22 12:00:01,323 plivo-outbound[15833]: INFO: (1) Sent to POST http://192.168.54.2/broadcast/app/ctrl/app_id/3382/log_id/224030 with {'Direction': 'outbound', 'From': '02196669287', 'ALegUUID': '5831a632-833f-11e3-9bdc-f3b864f23f8c', 'CallerName': 'Outbound Call', 'ScheduledHangupId': '5830a8b8-833f-11e3-afc5-000c29ae8315', 'To': '2001', 'ALegRequestUUID': '5830a066-833f-11e3-afc5-000c29ae8315', 'CallUUID': '5831a632-833f-11e3-9bdc-f3b864f23f8c', 'CallStatus': 'in-progress'} -- Result: <?xml version="1.0" encoding="UTF-8"?>

/usr/local/freeswitch/sounds/goodbye.wav

2014-01-22 12:00:01,323 plivo-outbound[15833]: INFO: (1) Requested RESTXML to http://192.168.54.2/broadcast/app/ctrl/app_id/3382/log_id/224030 2014-01-22 12:00:01,324 plivo-outbound[15833]: INFO: (1) [Play] /usr/local/freeswitch/sounds/goodbye.wav {'loop': 1} 2014-01-22 12:00:01,324 plivo-outbound[15833]: DEBUG: (1) Execute: set args=playback_sleep_val=0, uuid='', lock=True, loops=1 2014-01-22 12:00:01,326 plivo-outbound[15833]: DEBUG: (1) Response: <CommandResponse headers={'Content-Type': 'command/reply', 'Reply-Text': '+OK'}, body=> 2014-01-22 12:00:01,326 plivo-outbound[15833]: DEBUG: (1) Playing 1 times 2014-01-22 12:00:01,326 plivo-outbound[15833]: DEBUG: (1) Execute: set args=playback_terminators=None, uuid='', lock=True, loops=1 2014-01-22 12:00:01,327 plivo-outbound[15833]: DEBUG: (1) Response: <CommandResponse headers={'Content-Type': 'command/reply', 'Reply-Text': '+OK'}, body=> 2014-01-22 12:00:01,328 plivo-outbound[15833]: DEBUG: (1) Execute: playback args=/usr/local/freeswitch/sounds/goodbye.wav, uuid='', lock=True, loops=1 2014-01-22 12:00:01,329 plivo-outbound[15833]: DEBUG: (1) Response: <CommandResponse headers={'Content-Type': 'command/reply', 'Reply-Text': '+OK'}, body=> 2014-01-22 12:00:01,329 plivo-outbound[15833]: DEBUG: (1) wait for action start

stay for key pressing, after i press any key:

2014-01-22 12:00:19,584 plivo-outbound[15833]: INFO: (1) Event: channel 5831a632-833f-11e3-9bdc-f3b864f23f8c has hung up (NORMAL_CLEARING) 2014-01-22 12:00:19,585 plivo-outbound[15833]: DEBUG: (1) wait for action end <Event headers={}, body=> 2014-01-22 12:00:19,585 plivo-outbound[15833]: WARNING: (1) Play Break (empty event) 2014-01-22 12:00:19,585 plivo-outbound[15833]: INFO: (1) [Play] Done 2014-01-22 12:00:19,586 plivo-outbound[15833]: INFO: (1) [Hangup] {'reason': '', 'schedule': 0} 2014-01-22 12:00:19,586 plivo-outbound[15833]: INFO: (1) Hanging up now (NORMAL_CLEARING) 2014-01-22 12:00:19,586 plivo-outbound[15833]: DEBUG: (1) Execute: hangup args=NORMAL_CLEARING, uuid='', lock=True, loops=1 2014-01-22 12:00:19,587 plivo-outbound[15833]: DEBUG: (1) Response: <CommandResponse headers={'Content-Type': 'command/reply', 'Reply-Text': '+OK'}, body=> 2014-01-22 12:00:19,588 plivo-outbound[15833]: INFO: (1) [Hangup] Done (hangup) 2014-01-22 12:00:19,588 plivo-outbound[15833]: WARNING: (1) Channel has hung up, breaking Processing Call 2014-01-22 12:00:19,588 plivo-outbound[15833]: INFO: (1) Processing Call Ended 2014-01-22 12:00:19,589 plivo-outbound[15833]: DEBUG: (1) Releasing Connection ... 2014-01-22 12:00:19,589 plivo-outbound[15833]: DEBUG: (1) Releasing Connection Done 2014-01-22 12:00:19,589 plivo-outbound[15833]: INFO: (1) End request from ('127.0.0.1', 59322)