Skip to content

Instantly share code, notes, and snippets.

@ik5

ik5/ahn Secret

Created February 22, 2015 20:30
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save ik5/c4fb6d532d8afd821cc8 to your computer and use it in GitHub Desktop.
Save ik5/c4fb6d532d8afd821cc8 to your computer and use it in GitHub Desktop.
when using interruptible with DTMF, it react to every dtmf
[root@devpbx2 lib]# ahn start
Starting Adhearsion server at /tmp/input_record
[2015-02-22 19:58:12.309] INFO Adhearsion::Initializer: Setting RAILS_ENV to "development"
[2015-02-22 19:58:12.314] INFO Adhearsion::Console: Launching Adhearsion Console
AHN> [2015-02-22 19:58:12.339] INFO Adhearsion::PunchblockPlugin::Initializer: Starting connection to server
[2015-02-22 19:58:12.398] INFO Punchblock::Connection::XMPP: Connected to XMPP as usera@10.8.0.2/localhost.localdomain-15574
[2015-02-22 19:58:12.399] INFO Adhearsion::PunchblockPlugin::Initializer: Connected to Punchblock server
[2015-02-22 19:58:12.404] INFO Adhearsion::Process: Transitioning from booting to running with 0 active calls due to booted event.
AHN> [2015-02-22 19:58:12.406] INFO Adhearsion::Initializer: Adhearsion v2.6.0 initialized in "development"!
AHN> [2015-02-22 19:58:37.663] DEBUG Adhearsion::Call: @: Receiving message: #<Punchblock::Event::Offer target_call_id="30a3ec3a-bacd-11e4-af07-27e56b8f8f11", target_mixer_name=nil, component_id=nil, source_uri="xmpp:30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2", domain="10.8.0.2", transport="xmpp", timestamp=Sun, 22 Feb 2015 19:58:37 +0000, headers={"from"=>"<sip:3000@10.8.0.2>;tag=122714607", "to"=>"<sip:3001@10.8.0.2>", "via"=>"SIP/2.0/UDP 10.8.0.5:5060;rport=5060;branch=z9hG4bK1040058760"}, to="sip:3001@10.8.0.2", from="sip:3000@10.8.0.2">
[2015-02-22 19:58:37.670] INFO Adhearsion::Router: Call 30a3ec3a-bacd-11e4-af07-27e56b8f8f11 selected route "default" (Test)
[2015-02-22 19:58:37.713] DEBUG Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Executing command #<Punchblock::Command::Accept target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Sun, 22 Feb 2015 19:58:37 +0000, request_id="c397da6e-bbfb-4b91-ae54-5ce4a5c04ab5", headers={}>
[2015-02-22 19:58:37.758] INFO Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Executing controller #<Test call=30a3ec3a-bacd-11e4-af07-27e56b8f8f11, metadata={}>
[2015-02-22 19:58:37.760] DEBUG Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Receiving message: #<Punchblock::Event::Offer target_call_id="30a3ec3a-bacd-11e4-af07-27e56b8f8f11", target_mixer_name=nil, component_id=nil, source_uri="xmpp:30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2", domain="10.8.0.2", transport="xmpp", timestamp=Sun, 22 Feb 2015 19:58:37 +0000, headers={"from"=>"<sip:3000@10.8.0.2>;tag=122714607", "to"=>"<sip:3001@10.8.0.2>", "via"=>"SIP/2.0/UDP 10.8.0.5:5060;rport=5060;branch=z9hG4bK1040058760"}, to="sip:3001@10.8.0.2", from="sip:3000@10.8.0.2">
[2015-02-22 19:58:37.766] DEBUG Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Executing command #<Punchblock::Command::Answer target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Sun, 22 Feb 2015 19:58:37 +0000, request_id="61932aec-7d4e-484c-be27-06ab2de2e3a6", headers={}>
[2015-02-22 19:58:37.828] DEBUG Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Executing command #<Punchblock::Component::Input target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Sun, 22 Feb 2015 19:58:37 +0000, request_id="5aebbd63-4669-4551-8ef4-2dc6492ffc6e", headers={}, max_silence=nil, min_confidence=nil, mode=:dtmf, recognizer=nil, language=nil, terminator=nil, sensitivity=nil, initial_timeout=nil, inter_digit_timeout=nil, recognition_timeout=nil, grammars=[#<Punchblock::Component::Input::Grammar target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Sun, 22 Feb 2015 19:58:37 +0000, value=<grammar xmlns="http://www.w3.org/2001/06/grammar" version="1.0" xml:lang="en-US" mode="dtmf" root="inputdigits">
<rule id="inputdigits" scope="public">
<one-of>
<item>#</item>
</one-of>
</rule>
</grammar>, content_type="application/srgs+xml", url=nil>]>
[2015-02-22 19:58:37.839] DEBUG Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Receiving message: #<Punchblock::Event::Answered target_call_id="30a3ec3a-bacd-11e4-af07-27e56b8f8f11", target_mixer_name=nil, component_id=nil, source_uri="xmpp:30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2", domain="10.8.0.2", transport="xmpp", timestamp=Sun, 22 Feb 2015 19:58:37 +0000, headers={}>
[2015-02-22 19:58:37.844] DEBUG Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Executing command #<Punchblock::Component::Record target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Sun, 22 Feb 2015 19:58:37 +0000, request_id="b8f587d1-0153-4fc1-94d7-d4659979cdf2", format=nil, initial_timeout=nil, final_timeout=nil, max_duration=60000, start_beep=true, stop_beep=nil, start_paused=nil, direction=nil, mix=nil>
[2015-02-22 19:58:41.044] DEBUG Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Receiving message: #<Punchblock::Event::Complete target_call_id="30a3ec3a-bacd-11e4-af07-27e56b8f8f11", target_mixer_name=nil, component_id="input-1", source_uri="xmpp:30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/input-1", domain="10.8.0.2", transport="xmpp", timestamp=Sun, 22 Feb 2015 19:58:41 +0000, reason=#<Punchblock::Component::Input::Complete::NoMatch target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Sun, 22 Feb 2015 19:58:41 +0000, name=:nomatch>, recording=nil, fax=nil, fax_metadata={}>
[2015-02-22 19:58:41.070] DEBUG Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Receiving message: #<Punchblock::Event::Complete target_call_id="30a3ec3a-bacd-11e4-af07-27e56b8f8f11", target_mixer_name=nil, component_id="record-3", source_uri="xmpp:30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3", domain="10.8.0.2", transport="xmpp", timestamp=Sun, 22 Feb 2015 19:58:41 +0000, reason=#<Punchblock::Event::Complete::Stop target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Sun, 22 Feb 2015 19:58:41 +0000, name=:stop>, recording=#<Punchblock::Component::Record::Recording target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Sun, 22 Feb 2015 19:58:41 +0000, uri="file:///usr/local/freeswitch/recordings/30a3ec3a-bacd-11e4-af07-27e56b8f8f11-2.wav", duration=3179, size=0>, fax=nil, fax_metadata={}>
[2015-02-22 19:58:41.071] DEBUG Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: rec: #<Punchblock::Component::Record target_call_id="30a3ec3a-bacd-11e4-af07-27e56b8f8f11", target_mixer_name=nil, component_id="record-3", source_uri="xmpp:30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3", domain="10.8.0.2", transport=nil, timestamp=Sun, 22 Feb 2015 19:58:37 +0000, request_id="b8f587d1-0153-4fc1-94d7-d4659979cdf2", format=nil, initial_timeout=nil, final_timeout=nil, max_duration=60000, start_beep=true, stop_beep=nil, start_paused=nil, direction=nil, mix=nil>
[2015-02-22 19:58:41.071] INFO Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Hanging up
[2015-02-22 19:58:41.074] DEBUG Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Executing command #<Punchblock::Command::Hangup target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, timestamp=Sun, 22 Feb 2015 19:58:41 +0000, request_id="8775176c-9752-4133-8508-3e3e7f6887b3", headers={}>
[2015-02-22 19:58:41.121] DEBUG Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Receiving message: #<Punchblock::Event::End target_call_id="30a3ec3a-bacd-11e4-af07-27e56b8f8f11", target_mixer_name=nil, component_id=nil, source_uri="xmpp:30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2", domain="10.8.0.2", transport="xmpp", timestamp=Sun, 22 Feb 2015 19:58:41 +0000, headers={}, reason=:"hangup-command", platform_code=nil>
[2015-02-22 19:58:41.122] INFO Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Call sip:3000@10.8.0.2 -> sip:3001@10.8.0.2 ended due to hangup-command
[2015-02-22 19:58:41.125] DEBUG Adhearsion::Call: 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: Finished executing controller #<Test call=30a3ec3a-bacd-11e4-af07-27e56b8f8f11, metadata={}>
[2015-02-22 19:58:41.127] INFO Adhearsion::Router::Route: Call 30a3ec3a-bacd-11e4-af07-27e56b8f8f11 routing completed. Call was already hung up.
21aac87a-bacd-11e4-af05-27e56b8f8f11 2015-02-22 19:58:12.369322 [DEBUG] xmpp_streams.c:1189 10.8.0.2:51392, New c2s_in stream
21aac87a-bacd-11e4-af05-27e56b8f8f11 2015-02-22 19:58:12.369322 [DEBUG] xmpp_streams.c:190 (null), 10.8.0.2:51392, c2s_in RECV <stream:stream to=10.8.0.2 xmlns=jabber:client xmlns:stream=http://etherx.jabber.org/streams version=1.0 xml:lang=en>
21aac87a-bacd-11e4-af05-27e56b8f8f11 2015-02-22 19:58:12.369322 [DEBUG] xmpp_streams.c:1058 (null), 10.8.0.2:51392, state = CONNECT, node type = NODE_START
21aac87a-bacd-11e4-af05-27e56b8f8f11 2015-02-22 19:58:12.369322 [DEBUG] xmpp_streams.c:190 (null), 10.8.0.2:51392, c2s_in SEND <stream:stream xmlns=jabber:client xmlns:db=jabber:server:dialback from=10.8.0.2 id=21aac87a-bacd-11e4-af05-27e56b8f8f11 xml:lang=en version=1.0 xmlns:stream=http://etherx.jabber.org/streams><stream:features><mechanisms xmlns=urn:ietf:params:xml:ns:xmpp-sasl><mechanism>PLAIN</mechanism></mechanisms></stream:features>
21aac87a-bacd-11e4-af05-27e56b8f8f11 2015-02-22 19:58:12.369322 [DEBUG] xmpp_streams.c:190 (null), 10.8.0.2:51392, c2s_in RECV <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">dXNlcmFAMzcuMTM5LjMxLjE4NQB1c2VyYQAx</auth>
21aac87a-bacd-11e4-af05-27e56b8f8f11 2015-02-22 19:58:12.369322 [DEBUG] xmpp_streams.c:1058 (null), 10.8.0.2:51392, state = SECURE, node type = NODE_NORMAL
21aac87a-bacd-11e4-af05-27e56b8f8f11 2015-02-22 19:58:12.369322 [DEBUG] xmpp_streams.c:471 (null), 10.8.0.2:51392, auth, state = SECURE
21aac87a-bacd-11e4-af05-27e56b8f8f11 2015-02-22 19:58:12.369322 [DEBUG] xmpp_streams.c:505 (null), 10.8.0.2:51392, auth, state = SECURE, SASL/PLAIN decoded authzid = "usera@10.8.0.2" authcid = "usera"
21aac87a-bacd-11e4-af05-27e56b8f8f11 2015-02-22 19:58:12.369322 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2, 10.8.0.2:51392, c2s_in SEND <success xmlns=urn:ietf:params:xml:ns:xmpp-sasl/>
21aac87a-bacd-11e4-af05-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2, 10.8.0.2:51392, c2s_in RECV <stream:stream to=10.8.0.2 xmlns=jabber:client xmlns:stream=http://etherx.jabber.org/streams version=1.0 xml:lang=en>
21aac87a-bacd-11e4-af05-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2, 10.8.0.2:51392, state = AUTHENTICATED, node type = NODE_START
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2, 10.8.0.2:51392, c2s_in SEND <stream:stream xmlns=jabber:client xmlns:db=jabber:server:dialback from=10.8.0.2 id=21ab53da-bacd-11e4-af06-27e56b8f8f11 xml:lang=en version=1.0 xmlns:stream=http://etherx.jabber.org/streams><stream:features><bind xmlns=urn:ietf:params:xml:ns:xmpp-bind/><session xmlns=urn:ietf:params:xml:ns:xmpp-session/></stream:features>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2, 10.8.0.2:51392, c2s_in RECV <iq type="set" id="blather0002"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource>localhost.localdomain-15574</resource></bind></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2, 10.8.0.2:51392, state = AUTHENTICATED, node type = NODE_NORMAL
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <iq type=result id=blather0002><bind xmlns=urn:ietf:params:xml:ns:xmpp-bind><jid>usera@10.8.0.2/localhost.localdomain-15574</jid></bind></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in RECV <iq type="set" id="blather0004" to="10.8.0.2"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, state = RESOURCE_BOUND, node type = NODE_NORMAL
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:1549 Init usera@10.8.0.2/localhost.localdomain-15574
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <iq from=10.8.0.2 type=result id=blather0004/>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in RECV <iq type="get" id="blather0006"><query xmlns="jabber:iq:roster"/></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, state = READY, node type = NODE_NORMAL
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:3995 Lock usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:3119 usera@10.8.0.2/localhost.localdomain-15574, recv iq, availability = OFFLINE
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:4066 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:828 Locate (jid) 10.8.0.2: ref count = 2
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:3122 Deliver usera@10.8.0.2/localhost.localdomain-15574 => 10.8.0.2 <iq type='get' id='blather0006' to='10.8.0.2' from='usera@10.8.0.2/localhost.localdomain-15574'><query xmlns='jabber:iq:roster'/></iq>
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:709 10.8.0.2, looking for SERVER::get:jabber:iq:roster:query command
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:1793 usera@10.8.0.2/localhost.localdomain-15574, no handler function for command to 10.8.0.2
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:835 Release 10.8.0.2: ref count = 1
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:828 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:1795 Deliver 10.8.0.2 => usera@10.8.0.2/localhost.localdomain-15574 <iq type='error' id='blather0006' to='usera@10.8.0.2/localhost.localdomain-15574' from='10.8.0.2'><query xmlns='jabber:iq:roster'/><error type='modify'><feature-not-implemented xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/></error></iq>
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:835 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <iq type=error id=blather0006 to=usera@10.8.0.2/localhost.localdomain-15574 from=10.8.0.2><query xmlns=jabber:iq:roster/><error type=modify><feature-not-implemented xmlns=urn:ietf:params:xml:ns:xmpp-stanzas/></error></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in RECV <presence/>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, state = READY, node type = NODE_NORMAL
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:287 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, presence, state = READY
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:3995 Lock usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:3062 usera@10.8.0.2/localhost.localdomain-15574 got empty presence
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:3083 usera@10.8.0.2/localhost.localdomain-15574 is ONLINE
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:4073 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in RECV <presence to="10.8.0.2"><show>chat</show></presence>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, state = READY, node type = NODE_NORMAL
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:12.389325 [DEBUG] xmpp_streams.c:287 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, presence, state = READY
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:3995 Lock usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:3054 usera@10.8.0.2/localhost.localdomain-15574 got chat presence
2015-02-22 19:58:12.389325 [DEBUG] mod_rayo.c:4073 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.489394 [NOTICE] switch_channel.c:1055 New Channel sofia/internal/3000@10.8.0.2 [30a3ec3a-bacd-11e4-af07-27e56b8f8f11]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.489394 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.489394 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.489394 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/3000@10.8.0.2) Running State Change CS_NEW
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.489394 [DEBUG] sofia.c:8844 sofia/internal/3000@10.8.0.2 receiving invite from 10.8.0.5:5060 version: 1.5.15b git 1a181f0 2015-02-20 18:05:23Z 64bit
2015-02-22 19:58:37.489394 [DEBUG] sofia.c:9011 IP 10.8.0.5 Rejected by acl "domains". Falling back to Digest auth.
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.489394 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
2015-02-22 19:58:37.489394 [DEBUG] sofia.c:2065 detaching session 30a3ec3a-bacd-11e4-af07-27e56b8f8f11
2015-02-22 19:58:37.489394 [DEBUG] sofia_reg.c:1738 Send challenge for [3001@10.8.0.2]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.489394 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/3000@10.8.0.2) State NEW
2015-02-22 19:58:37.609425 [DEBUG] sofia.c:2173 Re-attaching to session 30a3ec3a-bacd-11e4-af07-27e56b8f8f11
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] sofia.c:8844 sofia/internal/3000@10.8.0.2 receiving invite from 10.8.0.5:5060 version: 1.5.15b git 1a181f0 2015-02-20 18:05:23Z 64bit
2015-02-22 19:58:37.609425 [DEBUG] sofia.c:9011 IP 10.8.0.5 Rejected by acl "domains". Falling back to Digest auth.
2015-02-22 19:58:37.609425 [DEBUG] sofia_reg.c:3092 event_add_header -> 'record_stereo' = 'true'
2015-02-22 19:58:37.609425 [DEBUG] sofia_reg.c:3092 event_add_header -> 'default_gateway' = 'example.com'
2015-02-22 19:58:37.609425 [DEBUG] sofia_reg.c:3092 event_add_header -> 'default_areacode' = '918'
2015-02-22 19:58:37.609425 [DEBUG] sofia_reg.c:3092 event_add_header -> 'transfer_fallback_extension' = 'operator'
2015-02-22 19:58:37.609425 [DEBUG] sofia_reg.c:3092 event_add_header -> 'accountcode' = '3000'
2015-02-22 19:58:37.609425 [DEBUG] sofia_reg.c:3092 event_add_header -> 'user_context' = 'testing'
2015-02-22 19:58:37.609425 [DEBUG] sofia_reg.c:3092 event_add_header -> 'effective_caller_id_name' = 'Ido's machine'
2015-02-22 19:58:37.609425 [DEBUG] sofia_reg.c:3092 event_add_header -> 'effective_caller_id_number' = '3000'
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] sofia.c:6623 Channel sofia/internal/3000@10.8.0.2 entering state [received][100]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] sofia.c:6633 Remote SDP:
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 v=0
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 o=yate 1424635117 1424635117 IN IP4 10.8.0.5
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 s=SIP Call
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 c=IN IP4 10.8.0.5
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 t=0 0
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 m=audio 18898 RTP/AVP 0 8 3 11 98 97 102 103 104 105 106 101
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:0 PCMU/8000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:8 PCMA/8000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:3 GSM/8000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:11 L16/8000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:98 iLBC/8000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=fmtp:98 mode=20
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:97 iLBC/8000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=fmtp:97 mode=30
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:102 SPEEX/8000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:103 SPEEX/16000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:104 SPEEX/32000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:105 iSAC/16000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:106 iSAC/32000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:101 telephone-event/8000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=ptime:30
30a3ec3a-bacd-11e4-af07-27e56b8f8f11
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] sofia.c:6899 (sofia/internal/3000@10.8.0.2) State Change CS_NEW -> CS_INIT
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/3000@10.8.0.2) Running State Change CS_INIT
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/3000@10.8.0.2) State INIT
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] mod_sofia.c:87 sofia/internal/3000@10.8.0.2 SOFIA INIT
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_state_machine.c:40 sofia/internal/3000@10.8.0.2 Standard INIT
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/3000@10.8.0.2) State Change CS_INIT -> CS_ROUTING
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/3000@10.8.0.2) State INIT going to sleep
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/3000@10.8.0.2) Running State Change CS_ROUTING
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_channel.c:2184 (sofia/internal/3000@10.8.0.2) Callstate Change DOWN -> RINGING
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/3000@10.8.0.2) State ROUTING
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] mod_sofia.c:123 sofia/internal/3000@10.8.0.2 SOFIA ROUTING
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_state_machine.c:166 sofia/internal/3000@10.8.0.2 Standard ROUTING
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [INFO] mod_dialplan_xml.c:635 Processing 3000 <3000>->3001 in context testing
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 Dialplan: sofia/internal/3000@10.8.0.2 parsing [testing->forward] continue=false
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 Dialplan: sofia/internal/3000@10.8.0.2 Regex (PASS) [forward] destination_number(3001) =~ /^(300\d)$/ break=on-false
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 Dialplan: sofia/internal/3000@10.8.0.2 Action rayo()
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_state_machine.c:216 (sofia/internal/3000@10.8.0.2) State Change CS_ROUTING -> CS_EXECUTE
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/3000@10.8.0.2) State ROUTING going to sleep
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/3000@10.8.0.2) Running State Change CS_EXECUTE
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/3000@10.8.0.2) State EXECUTE
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] mod_sofia.c:178 sofia/internal/3000@10.8.0.2 SOFIA EXECUTE
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] switch_core_state_machine.c:258 sofia/internal/3000@10.8.0.2 Standard EXECUTE
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 EXECUTE sofia/internal/3000@10.8.0.2 rayo()
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] mod_rayo.c:3670 got event CHANNEL_EXECUTE
2015-02-22 19:58:37.609425 [DEBUG] mod_rayo.c:3881 Init 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] mod_rayo.c:3892 Offering call for Rayo 3PCC
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] mod_rayo.c:3670 got event CHANNEL_PARK
2015-02-22 19:58:37.609425 [DEBUG] mod_rayo.c:828 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:37.609425 [DEBUG] mod_rayo.c:3922 Deliver 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 => usera@10.8.0.2/localhost.localdomain-15574 <presence from='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2' to='usera@10.8.0.2/localhost.localdomain-15574'><c xmlns='http://jabber.org/protocol/caps' hash='sha-1' node='urn:xmpp:rayo:call:1' ver='L9rOKMEJl9rssEggArljiapRd9k='/><offer xmlns='urn:xmpp:rayo:1' from='sip:3000@10.8.0.2' to='sip:3001@10.8.0.2'><header name='from' value='&lt;sip:3000@10.8.0.2&gt;;tag=122714607'/><header name='to' value='&lt;sip:3001@10.8.0.2&gt;'/><header name='via' value='SIP/2.0/UDP 10.8.0.5:5060;rport=5060;branch=z9hG4bK1040058760'/></offer><delay xmlns='urn:xmpp:delay' stamp='2015-02-22T19:58:37Z'/></presence>
2015-02-22 19:58:37.609425 [DEBUG] mod_rayo.c:835 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.609425 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <presence from=30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 to=usera@10.8.0.2/localhost.localdomain-15574><c xmlns=http://jabber.org/protocol/caps hash=sha-1 node=urn:xmpp:rayo:call:1 ver=L9rOKMEJl9rssEggArljiapRd9k=/><offer xmlns=urn:xmpp:rayo:1 from=sip:3000@10.8.0.2 to=sip:3001@10.8.0.2><header name=from value=&lt;sip:3000@10.8.0.2&gt;;tag=122714607/><header name=to value=&lt;sip:3001@10.8.0.2&gt;/><header name=via value=SIP/2.0/UDP 10.8.0.5:5060;rport=5060;branch=z9hG4bK1040058760/></offer><delay xmlns=urn:xmpp:delay stamp=2015-02-22T19:58:37Z/></presence>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.709342 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in RECV <iq type="set" to="30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2" id="c397da6e-bbfb-4b91-ae54-5ce4a5c04ab5"><accept xmlns="urn:xmpp:rayo:1"/></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.709342 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, state = READY, node type = NODE_NORMAL
2015-02-22 19:58:37.709342 [DEBUG] mod_rayo.c:3995 Lock usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:37.709342 [DEBUG] mod_rayo.c:3119 usera@10.8.0.2/localhost.localdomain-15574, recv iq, availability = ONLINE
2015-02-22 19:58:37.709342 [DEBUG] mod_rayo.c:4066 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
2015-02-22 19:58:37.709342 [DEBUG] mod_rayo.c:828 Locate (jid) 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 2
2015-02-22 19:58:37.709342 [DEBUG] mod_rayo.c:3122 Deliver usera@10.8.0.2/localhost.localdomain-15574 => 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 <iq type='set' to='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2' id='c397da6e-bbfb-4b91-ae54-5ce4a5c04ab5' from='usera@10.8.0.2/localhost.localdomain-15574'><accept xmlns='urn:xmpp:rayo:1'/></iq>
2015-02-22 19:58:37.709342 [DEBUG] mod_rayo.c:709 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, looking for CALL::set:urn:xmpp:rayo:1:accept command
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.709342 [INFO] mod_rayo.c:1689 usera@10.8.0.2/localhost.localdomain-15574 has control of call
2015-02-22 19:58:37.709342 [DEBUG] mod_rayo.c:1869 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, executing command
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.709342 [INFO] mod_rayo.c:2006 Sending early media
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[SILK:117:8000:20:20000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[G722:9:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3668 Audio Codec Compare [PCMU:0:8000:20:64000:1] is saved as a near-match
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[GSM:3:8000:20:13200:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMU:0:8000:30:64000:1]/[opus:116:48000:20:0:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[SILK:117:8000:20:20000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[G722:9:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMU:0:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[PCMA:8:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3668 Audio Codec Compare [PCMA:8:8000:20:64000:1] is saved as a near-match
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[GSM:3:8000:20:13200:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:30:64000:1]/[opus:116:48000:20:0:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [GSM:3:8000:30:13200:1]/[SILK:117:8000:20:20000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [GSM:3:8000:30:13200:1]/[G722:9:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [GSM:3:8000:30:13200:1]/[PCMU:0:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [GSM:3:8000:30:13200:1]/[PCMA:8:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [GSM:3:8000:30:13200:1]/[GSM:3:8000:20:13200:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3668 Audio Codec Compare [GSM:3:8000:20:13200:1] is saved as a near-match
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [GSM:3:8000:30:13200:1]/[opus:116:48000:20:0:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [L16:11:8000:30:0:1]/[SILK:117:8000:20:20000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [L16:11:8000:30:0:1]/[G722:9:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [L16:11:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [L16:11:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [L16:11:8000:30:0:1]/[GSM:3:8000:20:13200:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [L16:11:8000:30:0:1]/[opus:116:48000:20:0:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iLBC:98:8000:30:0:1]/[SILK:117:8000:20:20000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iLBC:98:8000:30:0:1]/[G722:9:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iLBC:98:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iLBC:98:8000:30:0:1]/[GSM:3:8000:20:13200:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iLBC:98:8000:30:0:1]/[opus:116:48000:20:0:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iLBC:97:8000:30:0:1]/[SILK:117:8000:20:20000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iLBC:97:8000:30:0:1]/[G722:9:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iLBC:97:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iLBC:97:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iLBC:97:8000:30:0:1]/[GSM:3:8000:20:13200:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iLBC:97:8000:30:0:1]/[opus:116:48000:20:0:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:102:8000:30:0:1]/[SILK:117:8000:20:20000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:102:8000:30:0:1]/[G722:9:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:102:8000:30:0:1]/[PCMU:0:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:102:8000:30:0:1]/[PCMA:8:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:102:8000:30:0:1]/[GSM:3:8000:20:13200:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:102:8000:30:0:1]/[opus:116:48000:20:0:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:103:16000:30:0:1]/[SILK:117:8000:20:20000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:103:16000:30:0:1]/[G722:9:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:103:16000:30:0:1]/[PCMU:0:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:103:16000:30:0:1]/[PCMA:8:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:103:16000:30:0:1]/[GSM:3:8000:20:13200:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:103:16000:30:0:1]/[opus:116:48000:20:0:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:104:32000:30:0:1]/[SILK:117:8000:20:20000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:104:32000:30:0:1]/[G722:9:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:104:32000:30:0:1]/[PCMU:0:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:104:32000:30:0:1]/[PCMA:8:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:104:32000:30:0:1]/[GSM:3:8000:20:13200:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [SPEEX:104:32000:30:0:1]/[opus:116:48000:20:0:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iSAC:105:16000:30:32000:1]/[SILK:117:8000:20:20000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iSAC:105:16000:30:32000:1]/[G722:9:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iSAC:105:16000:30:32000:1]/[PCMU:0:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iSAC:105:16000:30:32000:1]/[PCMA:8:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iSAC:105:16000:30:32000:1]/[GSM:3:8000:20:13200:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iSAC:105:16000:30:32000:1]/[opus:116:48000:20:0:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iSAC:106:32000:30:32000:1]/[SILK:117:8000:20:20000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iSAC:106:32000:30:32000:1]/[G722:9:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iSAC:106:32000:30:32000:1]/[PCMU:0:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iSAC:106:32000:30:32000:1]/[PCMA:8:8000:20:64000:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iSAC:106:32000:30:32000:1]/[GSM:3:8000:20:13200:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [iSAC:106:32000:30:32000:1]/[opus:116:48000:20:0:1]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3548 Set telephone-event payload to 101
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3738 Substituting codec PCMU@30i@8000h@1c
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:2473 Set Codec sofia/internal/3000@10.8.0.2 PCMU/8000 30 ms 240 samples 64000 bits 1 channels
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_codec.c:111 sofia/internal/3000@10.8.0.2 Original read codec set to PCMU:0
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:3895 Set 2833 dtmf send/recv payload to 101
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:5147 AUDIO RTP [sofia/internal/3000@10.8.0.2] 10.8.0.2 port 26548 -> 10.8.0.5 port 18898 codec: 0 ms: 30
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_rtp.c:3562 Starting timer [soft] 240 bytes per 30ms
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:5445 Set 2833 dtmf send payload to 101
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_media.c:5451 Set 2833 dtmf receive payload to 101
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/3000@10.8.0.2!
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] mod_rayo.c:3670 got event CHANNEL_PROGRESS_MEDIA
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] mod_rayo.c:3675 usera@10.8.0.2/localhost.localdomain-15574 rayo event CHANNEL_PROGRESS_MEDIA
2015-02-22 19:58:37.729351 [DEBUG] mod_rayo.c:3677 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:37.729351 [DEBUG] mod_rayo.c:3685 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_channel.c:3399 (sofia/internal/3000@10.8.0.2) Callstate Change RINGING -> EARLY
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] mod_sofia.c:2268 Ring SDP:
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 v=0
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 o=FreeSWITCH 1424608569 1424608570 IN IP4 10.8.0.2
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 s=FreeSWITCH
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 c=IN IP4 10.8.0.2
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 t=0 0
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 m=audio 26548 RTP/AVP 0 101
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:0 PCMU/8000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:101 telephone-event/8000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=fmtp:101 0-16
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=ptime:30
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=sendrecv
30a3ec3a-bacd-11e4-af07-27e56b8f8f11
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_core_session.c:912 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
2015-02-22 19:58:37.729351 [DEBUG] mod_rayo.c:1871 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, done executing command
2015-02-22 19:58:37.729351 [DEBUG] mod_rayo.c:835 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 1
2015-02-22 19:58:37.729351 [DEBUG] mod_rayo.c:828 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:37.729351 [DEBUG] mod_rayo.c:1877 Deliver 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 => usera@10.8.0.2/localhost.localdomain-15574 <iq from='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2' to='usera@10.8.0.2/localhost.localdomain-15574' type='result' id='c397da6e-bbfb-4b91-ae54-5ce4a5c04ab5'/>
2015-02-22 19:58:37.729351 [DEBUG] mod_rayo.c:835 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] sofia.c:6623 Channel sofia/internal/3000@10.8.0.2 entering state [early][183]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.729351 [DEBUG] switch_ivr.c:961 Codec Activated L16@8000hz 1 channels 30ms
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.749405 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <iq from=30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 to=usera@10.8.0.2/localhost.localdomain-15574 type=result id=c397da6e-bbfb-4b91-ae54-5ce4a5c04ab5/>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.749405 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in RECV <iq type="set" to="30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2" id="61932aec-7d4e-484c-be27-06ab2de2e3a6"><answer xmlns="urn:xmpp:rayo:1"/></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.749405 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, state = READY, node type = NODE_NORMAL
2015-02-22 19:58:37.749405 [DEBUG] mod_rayo.c:3995 Lock usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:37.749405 [DEBUG] mod_rayo.c:3119 usera@10.8.0.2/localhost.localdomain-15574, recv iq, availability = ONLINE
2015-02-22 19:58:37.749405 [DEBUG] mod_rayo.c:4066 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
2015-02-22 19:58:37.749405 [DEBUG] mod_rayo.c:828 Locate (jid) 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 2
2015-02-22 19:58:37.749405 [DEBUG] mod_rayo.c:3122 Deliver usera@10.8.0.2/localhost.localdomain-15574 => 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 <iq type='set' to='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2' id='61932aec-7d4e-484c-be27-06ab2de2e3a6' from='usera@10.8.0.2/localhost.localdomain-15574'><answer xmlns='urn:xmpp:rayo:1'/></iq>
2015-02-22 19:58:37.749405 [DEBUG] mod_rayo.c:709 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, looking for CALL::set:urn:xmpp:rayo:1:answer command
2015-02-22 19:58:37.749405 [DEBUG] mod_rayo.c:1869 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, executing command
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.769373 [DEBUG] mod_sofia.c:780 Local SDP sofia/internal/3000@10.8.0.2:
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 v=0
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 o=FreeSWITCH 1424608569 1424608571 IN IP4 10.8.0.2
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 s=FreeSWITCH
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 c=IN IP4 10.8.0.2
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 t=0 0
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 m=audio 26548 RTP/AVP 0 101
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:0 PCMU/8000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=rtpmap:101 telephone-event/8000
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=fmtp:101 0-16
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=ptime:30
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 a=sendrecv
30a3ec3a-bacd-11e4-af07-27e56b8f8f11
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.769373 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.769373 [DEBUG] switch_core_session.c:912 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:3670 got event CHANNEL_ANSWER
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:3675 usera@10.8.0.2/localhost.localdomain-15574 rayo event CHANNEL_ANSWER
2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:3677 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:3443 Locate (id) 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 3
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.769373 [NOTICE] mod_rayo.c:2025 Channel [sofia/internal/3000@10.8.0.2] has been answered
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.769373 [DEBUG] switch_channel.c:3689 (sofia/internal/3000@10.8.0.2) Callstate Change EARLY -> ACTIVE
2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:1871 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, done executing command
2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:3457 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 2
2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:3685 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:835 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 1
2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:828 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:1877 Deliver 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 => usera@10.8.0.2/localhost.localdomain-15574 <iq from='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2' to='usera@10.8.0.2/localhost.localdomain-15574' type='result' id='61932aec-7d4e-484c-be27-06ab2de2e3a6'/>
2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:835 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:828 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:3451 Deliver 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 => usera@10.8.0.2/localhost.localdomain-15574 <presence from='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2' to='usera@10.8.0.2/localhost.localdomain-15574'><answered xmlns='urn:xmpp:rayo:1'/><delay xmlns='urn:xmpp:delay' stamp='2015-02-22T19:58:37Z'/></presence>
2015-02-22 19:58:37.769373 [DEBUG] mod_rayo.c:835 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.769373 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <iq from=30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 to=usera@10.8.0.2/localhost.localdomain-15574 type=result id=61932aec-7d4e-484c-be27-06ab2de2e3a6/>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.769373 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <presence from=30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 to=usera@10.8.0.2/localhost.localdomain-15574><answered xmlns=urn:xmpp:rayo:1/><delay xmlns=urn:xmpp:delay stamp=2015-02-22T19:58:37Z/></presence>
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.769373 [DEBUG] sofia.c:6623 Channel sofia/internal/3000@10.8.0.2 entering state [completed][200]
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.829359 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in RECV <iq type="set" to="30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2" id="5aebbd63-4669-4551-8ef4-2dc6492ffc6e"><input xmlns="urn:xmpp:rayo:input:1" mode="dtmf"><grammar content-type="application/srgs+xml"><![CDATA[<grammar xmlns="http://www.w3.org/2001/06/grammar" version="1.0" xml:lang="en-US" mode="dtmf" root="inputdigits">
21ab53da-bacd-11e4-af06-27e56b8f8f11 <rule id="inputdigits" scope="public">
21ab53da-bacd-11e4-af06-27e56b8f8f11 <one-of>
21ab53da-bacd-11e4-af06-27e56b8f8f11 <item>#</item>
21ab53da-bacd-11e4-af06-27e56b8f8f11 </one-of>
21ab53da-bacd-11e4-af06-27e56b8f8f11 </rule>
21ab53da-bacd-11e4-af06-27e56b8f8f11 </grammar>]]></grammar></input></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.829359 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, state = READY, node type = NODE_NORMAL
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:3995 Lock usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:3119 usera@10.8.0.2/localhost.localdomain-15574, recv iq, availability = ONLINE
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:4066 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:828 Locate (jid) 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 2
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:3122 Deliver usera@10.8.0.2/localhost.localdomain-15574 => 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 <iq type='set' to='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2' id='5aebbd63-4669-4551-8ef4-2dc6492ffc6e' from='usera@10.8.0.2/localhost.localdomain-15574'><input xmlns='urn:xmpp:rayo:input:1' mode='dtmf'><grammar content-type='application/srgs+xml'>&lt;grammar xmlns=&quot;http://www.w3.org/2001/06/grammar&quot; version=&quot;1.0&quot; xml:lang=&quot;en-US&quot; mode=&quot;dtmf&quot; root=&quot;inputdigits&quot;&gt;
&lt;rule id=&quot;inputdigits&quot; scope=&quot;public&quot;&gt;
&lt;one-of&gt;
&lt;item&gt;#&lt;/item&gt;
&lt;/one-of&gt;
&lt;/rule&gt;
&lt;/grammar&gt;</grammar></input></iq>
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:709 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, looking for CALL::set:urn:xmpp:rayo:input:1:input command
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:1869 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, executing command
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:1345 Lock 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 3
2015-02-22 19:58:37.829359 [DEBUG] rayo_input_component.c:802 Init 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/input-1
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.829359 [DEBUG] rayo_input_component.c:324 Adding DTMF callback
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.829359 [DEBUG] switch_core_media_bug.c:519 Attaching BUG to sofia/internal/3000@10.8.0.2
2015-02-22 19:58:37.829359 [DEBUG] srgs.c:1219 Using cached grammar
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:1871 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, done executing command
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:835 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 2
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:828 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:37.829359 [DEBUG] rayo_components.c:62 Deliver 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/input-1 => usera@10.8.0.2/localhost.localdomain-15574 <iq from='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2' to='usera@10.8.0.2/localhost.localdomain-15574' type='result' id='5aebbd63-4669-4551-8ef4-2dc6492ffc6e'><ref xmlns='urn:xmpp:rayo:1' uri='xmpp:30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/input-1'/></iq>
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:835 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.829359 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <iq from=30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 to=usera@10.8.0.2/localhost.localdomain-15574 type=result id=5aebbd63-4669-4551-8ef4-2dc6492ffc6e><ref xmlns=urn:xmpp:rayo:1 uri=xmpp:30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/input-1/></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.829359 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in RECV <iq type="set" to="30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2" id="b8f587d1-0153-4fc1-94d7-d4659979cdf2"><record xmlns="urn:xmpp:rayo:record:1" max-duration="60000" start-beep="true"/></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.829359 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, state = READY, node type = NODE_NORMAL
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:3995 Lock usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:3119 usera@10.8.0.2/localhost.localdomain-15574, recv iq, availability = ONLINE
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:4066 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:828 Locate (jid) 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 3
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:3122 Deliver usera@10.8.0.2/localhost.localdomain-15574 => 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 <iq type='set' to='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2' id='b8f587d1-0153-4fc1-94d7-d4659979cdf2' from='usera@10.8.0.2/localhost.localdomain-15574'><record xmlns='urn:xmpp:rayo:record:1' max-duration='60000' start-beep='true'/></iq>
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:709 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, looking for CALL::set:urn:xmpp:rayo:record:1:record command
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:1869 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, executing command
2015-02-22 19:58:37.829359 [DEBUG] mod_rayo.c:1345 Lock 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 4
2015-02-22 19:58:37.829359 [DEBUG] rayo_record_component.c:179 Init 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.849376 [DEBUG] switch_core_media_bug.c:519 Attaching BUG to sofia/internal/3000@10.8.0.2
2015-02-22 19:58:37.849376 [DEBUG] switch_event.c:1688 Parsing variable [pause]=[false]
2015-02-22 19:58:37.849376 [DEBUG] rayo_output_component.c:729 Got path /usr/local/freeswitch/recordings/30a3ec3a-bacd-11e4-af07-27e56b8f8f11-2.wav
2015-02-22 19:58:37.849376 [DEBUG] rayo_output_component.c:753 Create audio buffer
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.849376 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.849376 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.849376 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.849376 [DEBUG] switch_core_media_bug.c:519 Attaching BUG to sofia/internal/3000@10.8.0.2
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.849376 [DEBUG] rayo_record_component.c:261 Recording started: file = {pause=false}fileman:///usr/local/freeswitch/recordings/30a3ec3a-bacd-11e4-af07-27e56b8f8f11-2.wav
2015-02-22 19:58:37.849376 [DEBUG] mod_rayo.c:1871 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, done executing command
2015-02-22 19:58:37.849376 [DEBUG] mod_rayo.c:835 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 3
2015-02-22 19:58:37.849376 [DEBUG] mod_rayo.c:828 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:37.849376 [DEBUG] rayo_components.c:62 Deliver 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3 => usera@10.8.0.2/localhost.localdomain-15574 <iq from='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2' to='usera@10.8.0.2/localhost.localdomain-15574' type='result' id='b8f587d1-0153-4fc1-94d7-d4659979cdf2'><ref xmlns='urn:xmpp:rayo:1' uri='xmpp:30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3'/></iq>
2015-02-22 19:58:37.849376 [DEBUG] mod_rayo.c:835 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.849376 [DEBUG] sofia.c:6623 Channel sofia/internal/3000@10.8.0.2 entering state [ready][200]
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:37.849376 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <iq from=30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 to=usera@10.8.0.2/localhost.localdomain-15574 type=result id=b8f587d1-0153-4fc1-94d7-d4659979cdf2><ref xmlns=urn:xmpp:rayo:1 uri=xmpp:30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3/></iq>
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.909373 [DEBUG] switch_rtp.c:5870 Correct ip/port confirmed.
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.909373 [DEBUG] switch_core_io.c:528 Setting BUG Codec PCMU:0
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.909373 [DEBUG] switch_core_io.c:839 Engaging Read Buffer at 480 bytes vs 160
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:37.989398 [DEBUG] switch_core_media.c:1977 Correcting calculated ptime value from 60 to 20 to compensate for 2 lost packet(s)
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:38.169335 [WARNING] switch_core_media.c:2009 Asynchronous PTIME not supported, changing our end from 30 to 20
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:38.209348 [DEBUG] switch_core_media.c:2381 Changing Codec from PCMU@30ms@8000hz to PCMU@20ms@8000hz
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:38.269363 [DEBUG] switch_rtp.c:3443 RE-Starting timer [soft] 160 bytes per 20ms
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:38.269363 [DEBUG] switch_core_media.c:2473 Set Codec sofia/internal/3000@10.8.0.2 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:38.269363 [DEBUG] switch_core_codec.c:123 sofia/internal/3000@10.8.0.2 Original read codec replaced with PCMU:0
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:38.269363 [DEBUG] switch_core_codec.c:151 Destroying BUG Codec PCMU:0
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:38.269363 [DEBUG] switch_core_io.c:1496 Engaging Write Buffer at 320 bytes to accommodate 480->320
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:38.289331 [DEBUG] switch_core_media_bug.c:801 Removing BUG from sofia/internal/3000@10.8.0.2
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:38.309330 [DEBUG] switch_core_io.c:528 Setting BUG Codec PCMU:0
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:38.809327 [DEBUG] switch_ivr_async.c:1462 Start of speech detected
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:38.809327 [DEBUG] switch_ivr_async.c:1442 Start of silence detected
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:38.809327 [DEBUG] switch_ivr_async.c:1462 Start of speech detected
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:38.809327 [DEBUG] switch_ivr_async.c:1442 Start of silence detected
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:40.729363 [DEBUG] switch_ivr_async.c:1462 Start of speech detected
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:40.749343 [DEBUG] switch_ivr_async.c:1442 Start of silence detected
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.029354 [DEBUG] switch_rtp.c:6092 RTP RECV DTMF 8:1600
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.029354 [DEBUG] rayo_input_component.c:216 Collected digits = "8"
2015-02-22 19:58:41.029354 [DEBUG] srgs.c:1303 match = -1
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.029354 [DEBUG] rayo_input_component.c:248 NO MATCH = 8
2015-02-22 19:58:41.029354 [DEBUG] rayo_components.c:117 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/input-1: ref count = 0
2015-02-22 19:58:41.029354 [DEBUG] rayo_components.c:118 Destroy 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/input-1 requested: ref_count = 0
2015-02-22 19:58:41.029354 [DEBUG] rayo_components.c:118 Destroying 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/input-1
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:1014 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 2
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.029354 [DEBUG] switch_channel.c:488 RECV DTMF 8:1600
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.029354 [DEBUG] rayo_cpa_detector.c:175 Got Rayo CPA event dtmf
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.029354 [DEBUG] rayo_cpa_component.c:130 Subscriber execute urn:xmpp:rayo:cpa:dtmf:1
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.029354 [DEBUG] rayo_cpa_component.c:143 No subscribers for urn:xmpp:rayo:cpa:dtmf:1
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:828 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:41.029354 [DEBUG] rayo_components.c:116 Deliver 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/input-1 => usera@10.8.0.2/localhost.localdomain-15574 <presence from='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/input-1' to='usera@10.8.0.2/localhost.localdomain-15574' type='unavailable'><complete xmlns='urn:xmpp:rayo:ext:1'><nomatch xmlns='urn:xmpp:rayo:input:complete:1'/></complete><delay xmlns='urn:xmpp:delay' stamp='2015-02-22T19:58:41Z'/></presence>
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:835 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:41.029354 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <presence from=30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/input-1 to=usera@10.8.0.2/localhost.localdomain-15574 type=unavailable><complete xmlns=urn:xmpp:rayo:ext:1><nomatch xmlns=urn:xmpp:rayo:input:complete:1/></complete><delay xmlns=urn:xmpp:delay stamp=2015-02-22T19:58:41Z/></presence>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:41.029354 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in RECV <iq type="set" to="30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3" id="513b2dae-ed5c-4ff2-87b0-8cada5f39f44"><stop xmlns="urn:xmpp:rayo:ext:1"/></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:41.029354 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, state = READY, node type = NODE_NORMAL
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:3995 Lock usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:3119 usera@10.8.0.2/localhost.localdomain-15574, recv iq, availability = ONLINE
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:4066 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:828 Locate (jid) 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3: ref count = 2
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:3122 Deliver usera@10.8.0.2/localhost.localdomain-15574 => 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3 <iq type='set' to='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3' id='513b2dae-ed5c-4ff2-87b0-8cada5f39f44' from='usera@10.8.0.2/localhost.localdomain-15574'><stop xmlns='urn:xmpp:rayo:ext:1'/></iq>
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:709 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3, looking for COMPONENT_CALL:record:set:urn:xmpp:rayo:ext:1:stop command
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:1936 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3, executing command
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.029354 [DEBUG] switch_ivr_async.c:1303 Stop recording file {pause=false}fileman:///usr/local/freeswitch/recordings/30a3ec3a-bacd-11e4-af07-27e56b8f8f11-2.wav
2015-02-22 19:58:41.029354 [DEBUG] rayo_record_component.c:134 Locate (id) 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3: ref count = 3
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.029354 [DEBUG] rayo_record_component.c:104 Recording /usr/local/freeswitch/recordings/30a3ec3a-bacd-11e4-af07-27e56b8f8f11-2.wav done.
2015-02-22 19:58:41.029354 [DEBUG] rayo_components.c:117 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3: ref count = 2
2015-02-22 19:58:41.029354 [DEBUG] rayo_components.c:118 Destroy 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3 requested: ref_count = 2
2015-02-22 19:58:41.029354 [DEBUG] rayo_record_component.c:150 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3: ref count = 1
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.029354 [DEBUG] switch_core_media_bug.c:801 Removing BUG from sofia/internal/3000@10.8.0.2
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:1938 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3, done executing command
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:835 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3: ref count = 0
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:835 Destroying 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:1014 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 1
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:828 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:41.029354 [DEBUG] rayo_components.c:116 Deliver 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3 => usera@10.8.0.2/localhost.localdomain-15574 <presence from='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3' to='usera@10.8.0.2/localhost.localdomain-15574' type='unavailable'><complete xmlns='urn:xmpp:rayo:ext:1'><stop xmlns='urn:xmpp:rayo:ext:complete:1'/><recording xmlns='urn:xmpp:rayo:record:complete:1' uri='file:///usr/local/freeswitch/recordings/30a3ec3a-bacd-11e4-af07-27e56b8f8f11-2.wav' duration='3179' size='0'/></complete><delay xmlns='urn:xmpp:delay' stamp='2015-02-22T19:58:41Z'/></presence>
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:835 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:828 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:1943 Deliver 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3 => usera@10.8.0.2/localhost.localdomain-15574 <iq from='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3' to='usera@10.8.0.2/localhost.localdomain-15574' type='result' id='513b2dae-ed5c-4ff2-87b0-8cada5f39f44'/>
2015-02-22 19:58:41.029354 [DEBUG] mod_rayo.c:835 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:41.049342 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <presence from=30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3 to=usera@10.8.0.2/localhost.localdomain-15574 type=unavailable><complete xmlns=urn:xmpp:rayo:ext:1><stop xmlns=urn:xmpp:rayo:ext:complete:1/><recording xmlns=urn:xmpp:rayo:record:complete:1 uri=file:///usr/local/freeswitch/recordings/30a3ec3a-bacd-11e4-af07-27e56b8f8f11-2.wav duration=3179 size=0/></complete><delay xmlns=urn:xmpp:delay stamp=2015-02-22T19:58:41Z/></presence>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:41.049342 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <iq from=30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2/record-3 to=usera@10.8.0.2/localhost.localdomain-15574 type=result id=513b2dae-ed5c-4ff2-87b0-8cada5f39f44/>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in RECV <iq type="set" to="30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2" id="8775176c-9752-4133-8508-3e3e7f6887b3"><hangup xmlns="urn:xmpp:rayo:1"/></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, state = READY, node type = NODE_NORMAL
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3995 Lock usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3119 usera@10.8.0.2/localhost.localdomain-15574, recv iq, availability = ONLINE
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:4066 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:828 Locate (jid) 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 2
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3122 Deliver usera@10.8.0.2/localhost.localdomain-15574 => 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 <iq type='set' to='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2' id='8775176c-9752-4133-8508-3e3e7f6887b3' from='usera@10.8.0.2/localhost.localdomain-15574'><hangup xmlns='urn:xmpp:rayo:1'/></iq>
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:709 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, looking for CALL::set:urn:xmpp:rayo:1:hangup command
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:1869 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, executing command
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [NOTICE] switch_ivr.c:3723 Hangup sofia/internal/3000@10.8.0.2 [CS_EXECUTE] [NORMAL_CLEARING]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_channel.c:3222 Send signal sofia/internal/3000@10.8.0.2 [KILL]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:1871 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2, done executing command
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:835 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 1
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:828 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:1877 Deliver 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 => usera@10.8.0.2/localhost.localdomain-15574 <iq from='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2' to='usera@10.8.0.2/localhost.localdomain-15574' type='result' id='8775176c-9752-4133-8508-3e3e7f6887b3'/>
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:835 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <iq from=30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 to=usera@10.8.0.2/localhost.localdomain-15574 type=result id=8775176c-9752-4133-8508-3e3e7f6887b3/>
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3670 got event CHANNEL_EXECUTE_COMPLETE
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3675 usera@10.8.0.2/localhost.localdomain-15574 rayo event CHANNEL_EXECUTE_COMPLETE
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3677 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3612 Locate (id) 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 2
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3615 Application rayo execute complete: _none_
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3618 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 1
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3685 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_session.c:2901 sofia/internal/3000@10.8.0.2 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/3000@10.8.0.2) State EXECUTE going to sleep
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/3000@10.8.0.2) Running State Change CS_HANGUP
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] rayo_input_component.c:365 Removing DTMF callback
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_media_bug.c:773 Removing BUG from sofia/internal/3000@10.8.0.2
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/3000@10.8.0.2) Callstate Change ACTIVE -> HANGUP
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/3000@10.8.0.2) State HANGUP
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] mod_sofia.c:413 Channel sofia/internal/3000@10.8.0.2 hanging up, cause: NORMAL_CLEARING
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/internal/3000@10.8.0.2
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:60 sofia/internal/3000@10.8.0.2 Standard HANGUP, cause: NORMAL_CLEARING
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/3000@10.8.0.2) State HANGUP going to sleep
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/3000@10.8.0.2) State Change CS_HANGUP -> CS_REPORTING
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/3000@10.8.0.2) Running State Change CS_REPORTING
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/3000@10.8.0.2) State REPORTING
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:104 sofia/internal/3000@10.8.0.2 Standard REPORTING, cause: NORMAL_CLEARING
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/3000@10.8.0.2) State REPORTING going to sleep
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] rayo_cpa_component.c:130 Subscriber execute hangup
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] rayo_cpa_component.c:143 No subscribers for hangup
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/3000@10.8.0.2) State Change CS_REPORTING -> CS_DESTROY
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/3000@10.8.0.2 [BREAK]
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_session.c:1623 Session 10 (sofia/internal/3000@10.8.0.2) Locked, Waiting on external entities
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [NOTICE] switch_core_session.c:1641 Session 10 (sofia/internal/3000@10.8.0.2) Ended
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [NOTICE] switch_core_session.c:1645 Close Channel sofia/internal/3000@10.8.0.2 [CS_DESTROY]
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3413 Locate (id) 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 2
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3423 Got channel destroy event
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3428 Destroy 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 requested: ref_count = 2
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3429 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 1
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3432 Release 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2: ref count = 0
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:3432 Destroying 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:1158 Sending <end> to offered client usera@10.8.0.2/localhost.localdomain-15574
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:626 (sofia/internal/3000@10.8.0.2) Running State Change CS_DESTROY
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/3000@10.8.0.2) State DESTROY
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] mod_sofia.c:323 sofia/internal/3000@10.8.0.2 SOFIA DESTROY
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:111 sofia/internal/3000@10.8.0.2 Standard DESTROY
30a3ec3a-bacd-11e4-af07-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/3000@10.8.0.2) State DESTROY going to sleep
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:828 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:1159 Deliver 30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 => usera@10.8.0.2/localhost.localdomain-15574 <presence from='30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2' to='usera@10.8.0.2/localhost.localdomain-15574' type='unavailable'><end xmlns='urn:xmpp:rayo:1'><hangup-command/></end><delay xmlns='urn:xmpp:delay' stamp='2015-02-22T19:58:41Z'/></presence>
2015-02-22 19:58:41.069402 [DEBUG] mod_rayo.c:835 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:58:41.069402 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <presence from=30a3ec3a-bacd-11e4-af07-27e56b8f8f11@10.8.0.2 to=usera@10.8.0.2/localhost.localdomain-15574 type=unavailable><end xmlns=urn:xmpp:rayo:1><hangup-command/></end><delay xmlns=urn:xmpp:delay stamp=2015-02-22T19:58:41Z/></presence>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:59:12.409328 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in RECV <iq type="get" to="10.8.0.2" id="blather000e"><ping xmlns="urn:xmpp:ping"/></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:59:12.409328 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, state = READY, node type = NODE_NORMAL
2015-02-22 19:59:12.409328 [DEBUG] mod_rayo.c:3995 Lock usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:59:12.409328 [DEBUG] mod_rayo.c:3119 usera@10.8.0.2/localhost.localdomain-15574, recv iq, availability = ONLINE
2015-02-22 19:59:12.409328 [DEBUG] mod_rayo.c:4066 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
2015-02-22 19:59:12.409328 [DEBUG] mod_rayo.c:828 Locate (jid) 10.8.0.2: ref count = 2
2015-02-22 19:59:12.409328 [DEBUG] mod_rayo.c:3122 Deliver usera@10.8.0.2/localhost.localdomain-15574 => 10.8.0.2 <iq type='get' to='10.8.0.2' id='blather000e' from='usera@10.8.0.2/localhost.localdomain-15574'><ping xmlns='urn:xmpp:ping'/></iq>
2015-02-22 19:59:12.409328 [DEBUG] mod_rayo.c:709 10.8.0.2, looking for SERVER::get:urn:xmpp:ping:ping command
2015-02-22 19:59:12.409328 [DEBUG] mod_rayo.c:835 Release 10.8.0.2: ref count = 1
2015-02-22 19:59:12.409328 [DEBUG] mod_rayo.c:828 Locate (jid) usera@10.8.0.2/localhost.localdomain-15574: ref count = 2
2015-02-22 19:59:12.409328 [DEBUG] mod_rayo.c:1807 Deliver 10.8.0.2 => usera@10.8.0.2/localhost.localdomain-15574 <iq type='result' from='10.8.0.2' to='usera@10.8.0.2/localhost.localdomain-15574' id='blather000e'/>
2015-02-22 19:59:12.409328 [DEBUG] mod_rayo.c:835 Release usera@10.8.0.2/localhost.localdomain-15574: ref count = 1
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 19:59:12.409328 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in SEND <iq type=result from=10.8.0.2 to=usera@10.8.0.2/localhost.localdomain-15574 id=blather000e/>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 20:00:12.469339 [DEBUG] xmpp_streams.c:190 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, c2s_in RECV <iq type="get" to="10.8.0.2" id="blather0010"><ping xmlns="urn:xmpp:ping"/></iq>
21ab53da-bacd-11e4-af06-27e56b8f8f11 2015-02-22 20:00:12.469339 [DEBUG] xmpp_streams.c:1058 usera@10.8.0.2/localhost.localdomain-15574, 10.8.0.2:51392, state = READY, node type = NODE_NORMAL
# encoding: utf-8
class Test < Adhearsion::CallController
require 'active_support/time'
def run
answer
rec = record start_beep: true, interruptible: '#'
logger.debug "rec: #{rec.inspect}"
hangup
end
end
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment