Skip to content

Instantly share code, notes, and snippets.

@pungoyal
Created January 7, 2014 14:25
Show Gist options
  • Save pungoyal/8300050 to your computer and use it in GitHub Desktop.
Save pungoyal/8300050 to your computer and use it in GitHub Desktop.
freeswitch log
[2014-01-07 19:51:37] DEBUG Adhearsion::OutboundCall: 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: Receiving message: #<Punchblock::Event::Answered target_call_id="015cb21e-77a7-11e3-9592-33f9d38e2b57", target_mixer_name=nil, component_id=nil, source_uri="xmpp:015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3", domain="172.17.0.3", transport="xmpp", headers={}>
[2014-01-07 19:51:37] INFO Adhearsion::OutboundCall: 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: Executing controller #<ConferenceController call=015cb21e-77a7-11e3-9592-33f9d38e2b57, metadata={:mixer_name=>"user/userb-1389104491", :organizer=>"user/userb", :participants=>["user/userc"]}>
[2014-01-07 19:51:37] INFO Adhearsion::OutboundCall: 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: Joining to {:mixer_name=>"user/userb-1389104491"}
[2014-01-07 19:51:37] DEBUG Adhearsion::OutboundCall: 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: Executing command #<Punchblock::Command::Join target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, call_uri=nil, mixer_name="user/userb-1389104491", direction=nil, media=nil>
[2014-01-07 19:51:38] DEBUG Adhearsion::OutboundCall: 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: Receiving message: #<Punchblock::Event::Joined target_call_id="015cb21e-77a7-11e3-9592-33f9d38e2b57", target_mixer_name=nil, component_id=nil, source_uri="xmpp:015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3", domain="172.17.0.3", transport="xmpp", call_uri=nil, mixer_name="user/userb-1389104491">
[2014-01-07 19:51:38] INFO Adhearsion::OutboundCall: 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: Joined to mixer user/userb-1389104491
[2014-01-07 19:51:38] INFO EventLogger: Starting a conference with user/userb and ["user/userc"]
[2014-01-07 19:51:38] DEBUG Adhearsion::OutboundCall: 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: Finished executing controller #<ConferenceController call=015cb21e-77a7-11e3-9592-33f9d38e2b57, metadata={:mixer_name=>"user/userb-1389104491", :organizer=>"user/userb", :participants=>["user/userc"]}>
[2014-01-07 19:51:38] INFO Adhearsion::Router::Route: Call routing completed, keeping the call alive at controller/router request.
[2014-01-07 19:51:38] DEBUG Adhearsion::OutboundCall: @: Executing command #<Punchblock::Command::Dial target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, headers={}, to="user/userc", from="user/userb", timeout=10000, join=nil>
[2014-01-07 19:51:38] DEBUG Adhearsion::OutboundCall: 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: Receiving message: #<Punchblock::Event::Ringing target_call_id="053d1e6e-77a7-11e3-959b-33f9d38e2b57", target_mixer_name=nil, component_id=nil, source_uri="xmpp:053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3", domain="172.17.0.3", transport="xmpp", headers={}>
[2014-01-07 19:51:39] DEBUG Adhearsion::OutboundCall: 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: Receiving message: #<Punchblock::Event::Answered target_call_id="053d1e6e-77a7-11e3-959b-33f9d38e2b57", target_mixer_name=nil, component_id=nil, source_uri="xmpp:053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3", domain="172.17.0.3", transport="xmpp", headers={}>
[2014-01-07 19:51:39] INFO Adhearsion::OutboundCall: 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: Joining to {:mixer_name=>"user/userb-1389104491"}
[2014-01-07 19:51:39] DEBUG Adhearsion::OutboundCall: 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: Executing command #<Punchblock::Command::Join target_call_id=nil, target_mixer_name=nil, component_id=nil, source_uri=nil, domain=nil, transport=nil, call_uri=nil, mixer_name="user/userb-1389104491", direction=nil, media=nil>
[2014-01-07 19:51:40] DEBUG Adhearsion::OutboundCall: 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: Receiving message: #<Punchblock::Event::Joined target_call_id="053d1e6e-77a7-11e3-959b-33f9d38e2b57", target_mixer_name=nil, component_id=nil, source_uri="xmpp:053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3", domain="172.17.0.3", transport="xmpp", call_uri=nil, mixer_name="user/userb-1389104491">
[2014-01-07 19:51:40] INFO Adhearsion::OutboundCall: 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: Joined to mixer user/userb-1389104491
[2014-01-07 19:51:40] DEBUG Adhearsion::OutboundCall: 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: Receiving message: #<Punchblock::Event::Unjoined target_call_id="053d1e6e-77a7-11e3-959b-33f9d38e2b57", target_mixer_name=nil, component_id=nil, source_uri="xmpp:053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3", domain="172.17.0.3", transport="xmpp", call_uri=nil, mixer_name="user/userb-1389104491">
[2014-01-07 19:51:40] INFO Adhearsion::OutboundCall: 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: Unjoined from mixer user/userb-1389104491
[2014-01-07 19:51:46] DEBUG Adhearsion::OutboundCall: 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: Receiving message: #<Punchblock::Event::Unjoined target_call_id="015cb21e-77a7-11e3-9592-33f9d38e2b57", target_mixer_name=nil, component_id=nil, source_uri="xmpp:015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3", domain="172.17.0.3", transport="xmpp", call_uri=nil, mixer_name="user/userb-1389104491">
[2014-01-07 19:51:46] INFO Adhearsion::OutboundCall: 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: Unjoined from mixer user/userb-1389104491
[2014-01-07 19:51:46] DEBUG Adhearsion::OutboundCall: 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: Receiving message: #<Punchblock::Event::End target_call_id="015cb21e-77a7-11e3-9592-33f9d38e2b57", target_mixer_name=nil, component_id=nil, source_uri="xmpp:015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3", domain="172.17.0.3", transport="xmpp", headers={}, reason=:hungup, platform_code=nil>
[2014-01-07 19:51:46] INFO Adhearsion::OutboundCall: 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: Call ended due to hungup
[2014-01-07 19:51:50] DEBUG Adhearsion::OutboundCall: 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: Receiving message: #<Punchblock::Event::End target_call_id="053d1e6e-77a7-11e3-959b-33f9d38e2b57", target_mixer_name=nil, component_id=nil, source_uri="xmpp:053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3", domain="172.17.0.3", transport="xmpp", headers={}, reason=:hungup, platform_code=nil>
[2014-01-07 19:51:50] INFO Adhearsion::OutboundCall: 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: Call ended due to hungup
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 RECV <iq type="set" to="172.17.0.3" id="blather000c"><dial xmlns="urn:xmpp:rayo:1" to="user/userb" from="VoCall"/></iq>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] xmpp_streams.c:1058 usera@172.17.0.3/firefly-4178, state = READY, node type = NODE_NORMAL
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:3338 Lock usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:2579 usera@172.17.0.3/firefly-4178, recv iq, availability = ONLINE
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:3397 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:630 Locate (jid) 172.17.0.3: ref count = 2
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:2582 Deliver usera@172.17.0.3/firefly-4178 => 172.17.0.3 <iq type='set' to='172.17.0.3' id='blather000c' from='usera@172.17.0.3/firefly-4178'><dial xmlns='urn:xmpp:rayo:1' to='user/userb' from='VoCall'/></iq>
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:511 172.17.0.3, looking for SERVER::set:urn:xmpp:rayo:1:dial command
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:637 Unlock 172.17.0.3: ref count = 1
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:2172 Init 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [INFO] mod_rayo.c:2175 usera@172.17.0.3/firefly-4178 has control of call
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:2272 Using dialstring: {origination_uuid=015cb21e-77a7-11e3-9592-33f9d38e2b57,rayo_dcp_jid=usera@172.17.0.3/firefly-4178,rayo_call_jid=015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3,origination_caller_id_number=VoCall,origination_caller_id_name=VoCall}user/userb &rayo
2014-01-07 09:21:31.726438 [DEBUG] switch_ivr_originate.c:2061 Parsing global variables
2014-01-07 09:21:31.726438 [DEBUG] switch_event.c:1661 Parsing variable [origination_uuid]=[015cb21e-77a7-11e3-9592-33f9d38e2b57]
2014-01-07 09:21:31.726438 [DEBUG] switch_event.c:1661 Parsing variable [rayo_dcp_jid]=[usera@172.17.0.3/firefly-4178]
2014-01-07 09:21:31.726438 [DEBUG] switch_event.c:1661 Parsing variable [rayo_call_jid]=[015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3]
2014-01-07 09:21:31.726438 [DEBUG] switch_event.c:1661 Parsing variable [origination_caller_id_number]=[VoCall]
2014-01-07 09:21:31.726438 [DEBUG] switch_event.c:1661 Parsing variable [origination_caller_id_name]=[VoCall]
2014-01-07 09:21:31.726438 [DEBUG] switch_ivr_originate.c:2061 Parsing global variables
2014-01-07 09:21:31.726438 [DEBUG] switch_event.c:1661 Parsing variable [sip_invite_domain]=[172.17.0.3]
2014-01-07 09:21:31.726438 [DEBUG] switch_event.c:1661 Parsing variable [presence_id]=[userb@172.17.0.3]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [NOTICE] switch_channel.c:1052 New Channel sofia/external/sip:userb@172.17.42.1 [015cb21e-77a7-11e3-9592-33f9d38e2b57]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] mod_sofia.c:5231 (sofia/external/sip:userb@172.17.42.1) State Change CS_NEW -> CS_INIT
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_session.c:586 sofia/external/sip:userb@172.17.42.1 set UUID=015cb21e-77a7-11e3-9592-33f9d38e2b57
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sip:userb@172.17.42.1) Running State Change CS_INIT
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_state_machine.c:455 (sofia/external/sip:userb@172.17.42.1) State INIT
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] mod_sofia.c:87 sofia/external/sip:userb@172.17.42.1 SOFIA INIT
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] sofia_glue.c:2739 Local SDP:
015cb21e-77a7-11e3-9592-33f9d38e2b57 v=0
015cb21e-77a7-11e3-9592-33f9d38e2b57 o=FreeSWITCH 1389074953 1389074954 IN IP4 172.17.0.3
015cb21e-77a7-11e3-9592-33f9d38e2b57 s=FreeSWITCH
015cb21e-77a7-11e3-9592-33f9d38e2b57 c=IN IP4 172.17.0.3
015cb21e-77a7-11e3-9592-33f9d38e2b57 t=0 0
015cb21e-77a7-11e3-9592-33f9d38e2b57 m=audio 29538 RTP/AVP 0 8 101 13
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=rtpmap:101 telephone-event/8000
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=fmtp:101 0-16
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=ptime:20
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=sendrecv
015cb21e-77a7-11e3-9592-33f9d38e2b57
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] mod_sofia.c:127 (sofia/external/sip:userb@172.17.42.1) State Change CS_INIT -> CS_ROUTING
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_state_machine.c:455 (sofia/external/sip:userb@172.17.42.1) State INIT going to sleep
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sip:userb@172.17.42.1) Running State Change CS_ROUTING
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:3091 got event CHANNEL_ORIGINATE
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_ORIGINATE
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:2785 Locate (id) 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 2
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:2790 Got originate event
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_state_machine.c:471 (sofia/external/sip:userb@172.17.42.1) State ROUTING
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] mod_sofia.c:150 sofia/external/sip:userb@172.17.42.1 SOFIA ROUTING
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_ivr_originate.c:67 (sofia/external/sip:userb@172.17.42.1) State Change CS_ROUTING -> CS_CONSUME_MEDIA
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_state_machine.c:471 (sofia/external/sip:userb@172.17.42.1) State ROUTING going to sleep
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:2812 Unlock 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:2806 Deliver 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 => usera@172.17.0.3/firefly-4178 <iq from='172.17.0.3' to='usera@172.17.0.3/firefly-4178' id='blather000c' type='result'><ref xmlns='urn:xmpp:rayo:1' uri='xmpp:015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3'/></iq>
2014-01-07 09:21:31.726438 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sip:userb@172.17.42.1) Running State Change CS_CONSUME_MEDIA
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_state_machine.c:490 (sofia/external/sip:userb@172.17.42.1) State CONSUME_MEDIA
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_state_machine.c:490 (sofia/external/sip:userb@172.17.42.1) State CONSUME_MEDIA going to sleep
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userb@172.17.42.1 entering state [calling][0]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.726438 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userb@172.17.42.1 entering state [proceeding][101]
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:31.746415 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <iq from=172.17.0.3 to=usera@172.17.0.3/firefly-4178 id=blather000c type=result><ref xmlns=urn:xmpp:rayo:1 uri=xmpp:015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3/></iq>
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.906467 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.906467 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.906467 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userb@172.17.42.1 entering state [proceeding][180]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.906467 [NOTICE] sofia.c:5874 Ring-Ready sofia/external/sip:userb@172.17.42.1!
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.906467 [DEBUG] switch_channel.c:3238 (sofia/external/sip:userb@172.17.42.1) Callstate Change DOWN -> RINGING
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.906467 [DEBUG] mod_rayo.c:3091 got event CHANNEL_PROGRESS
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:31.906467 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_PROGRESS
2014-01-07 09:21:31.906467 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:31.906467 [DEBUG] mod_rayo.c:2870 Locate (id) 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 2
2014-01-07 09:21:31.906467 [DEBUG] mod_rayo.c:2881 Unlock 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:31.906467 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:31.906467 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:31.906467 [DEBUG] mod_rayo.c:2878 Deliver 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3' to='usera@172.17.0.3/firefly-4178'><ringing xmlns='urn:xmpp:rayo:1'/></presence>
2014-01-07 09:21:31.906467 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:31.926396 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 to=usera@172.17.0.3/firefly-4178><ringing xmlns=urn:xmpp:rayo:1/></presence>
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.906411 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.906411 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.906411 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userb@172.17.42.1 entering state [completing][200]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.906411 [DEBUG] sofia.c:5792 Remote SDP:
015cb21e-77a7-11e3-9592-33f9d38e2b57 v=0
015cb21e-77a7-11e3-9592-33f9d38e2b57 o=userc 3333 1996 IN IP4 192.168.1.3
015cb21e-77a7-11e3-9592-33f9d38e2b57 s=Talk
015cb21e-77a7-11e3-9592-33f9d38e2b57 c=IN IP4 192.168.1.3
015cb21e-77a7-11e3-9592-33f9d38e2b57 t=0 0
015cb21e-77a7-11e3-9592-33f9d38e2b57 m=audio 7078 RTP/AVP 0 8 101
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=rtpmap:0 PCMU/8000
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=rtpmap:8 PCMA/8000
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=rtpmap:101 telephone-event/8000
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=fmtp:101 0-11
015cb21e-77a7-11e3-9592-33f9d38e2b57
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.906411 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.906411 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.906411 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userb@172.17.42.1 entering state [ready][200]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.906411 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.906411 [DEBUG] sofia_glue.c:3186 Set Codec sofia/external/sip:userb@172.17.42.1 PCMU/8000 20 ms 160 samples 64000 bits
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.906411 [DEBUG] switch_core_codec.c:111 sofia/external/sip:userb@172.17.42.1 Original read codec set to PCMU:0
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.906411 [DEBUG] sofia_glue.c:5437 Set 2833 dtmf send payload to 101
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.906411 [DEBUG] sofia_glue.c:3445 AUDIO RTP [sofia/external/sip:userb@172.17.42.1] 172.17.0.3 port 29538 -> 192.168.1.3 port 7078 codec: 0 ms: 20
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.906411 [DEBUG] switch_rtp.c:2033 Starting timer [soft] 160 bytes per 20ms
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] sofia_glue.c:3712 Set 2833 dtmf send payload to 101
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] sofia_glue.c:3718 Set 2833 dtmf receive payload to 101
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] sofia_glue.c:3745 sofia/external/sip:userb@172.17.42.1 Set rtp dtmf delay to 40
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [NOTICE] sofia.c:6568 Channel [sofia/external/sip:userb@172.17.42.1] has been answered
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:3091 got event CHANNEL_ANSWER
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_ANSWER
2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:2851 Locate (id) 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 2
2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:2857 Unlock 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] switch_channel.c:3643 (sofia/external/sip:userb@172.17.42.1) Callstate Change RINGING -> ACTIVE
2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:2856 Deliver 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3' to='usera@172.17.0.3/firefly-4178'><answered xmlns='urn:xmpp:rayo:1'/></presence>
2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:37.926401 [DEBUG] switch_ivr_originate.c:3495 Originate Resulted in Success: [sofia/external/sip:userb@172.17.42.1]
2014-01-07 09:21:37.926401 [DEBUG] switch_ivr_originate.c:3495 Originate Resulted in Success: [sofia/external/sip:userb@172.17.42.1]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [INFO] switch_channel.c:3028 sofia/external/sip:userb@172.17.42.1 Flipping CID from "VoCall" <VoCall> to "Outbound Call" <userb>
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] mod_commands.c:4182 (sofia/external/sip:userb@172.17.42.1) State Change CS_CONSUME_MEDIA -> CS_EXECUTE
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:2276 Got originate result: +OK 015cb21e-77a7-11e3-9592-33f9d38e2b57
015cb21e-77a7-11e3-9592-33f9d38e2b57
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sip:userb@172.17.42.1) Running State Change CS_EXECUTE
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] switch_core_state_machine.c:478 (sofia/external/sip:userb@172.17.42.1) State EXECUTE
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] mod_sofia.c:243 sofia/external/sip:userb@172.17.42.1 SOFIA EXECUTE
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] switch_core_state_machine.c:209 sofia/external/sip:userb@172.17.42.1 Standard EXECUTE
015cb21e-77a7-11e3-9592-33f9d38e2b57 EXECUTE sofia/external/sip:userb@172.17.42.1 rayo()
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:3091 got event CHANNEL_EXECUTE
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_EXECUTE
2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:3019 Locate (id) 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 2
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:3021 Application rayo execute
2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:3022 Unlock 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:37.926401 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] switch_ivr.c:959 Codec Activated L16@8000hz 1 channels 20ms
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:37.926401 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 to=usera@172.17.0.3/firefly-4178><answered xmlns=urn:xmpp:rayo:1/></presence>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:37.986394 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 RECV <iq type="set" to="015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3" id="blather000e"><join xmlns="urn:xmpp:rayo:1" mixer-name="user/userb-1389104491"/></iq>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:37.986394 [DEBUG] xmpp_streams.c:1058 usera@172.17.0.3/firefly-4178, state = READY, node type = NODE_NORMAL
2014-01-07 09:21:37.986394 [DEBUG] mod_rayo.c:3338 Lock usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:37.986394 [DEBUG] mod_rayo.c:2579 usera@172.17.0.3/firefly-4178, recv iq, availability = ONLINE
2014-01-07 09:21:37.986394 [DEBUG] mod_rayo.c:3397 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:37.986394 [DEBUG] mod_rayo.c:630 Locate (jid) 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 2
2014-01-07 09:21:37.986394 [DEBUG] mod_rayo.c:2582 Deliver usera@172.17.0.3/firefly-4178 => 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 <iq type='set' to='015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3' id='blather000e' from='usera@172.17.0.3/firefly-4178'><join xmlns='urn:xmpp:rayo:1' mixer-name='user/userb-1389104491'/></iq>
2014-01-07 09:21:37.986394 [DEBUG] mod_rayo.c:511 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3, looking for CALL::set:urn:xmpp:rayo:1:join command
2014-01-07 09:21:37.986394 [DEBUG] mod_rayo.c:1557 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3, executing command
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:37.986394 [DEBUG] switch_core_session.c:1151 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
2014-01-07 09:21:37.986394 [DEBUG] mod_rayo.c:1559 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3, done executing command
2014-01-07 09:21:37.986394 [DEBUG] mod_rayo.c:637 Unlock 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 1
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:38.006392 [DEBUG] switch_ivr.c:615 sofia/external/sip:userb@172.17.42.1 Command Execute conference(user/userb-1389104491@sla)
015cb21e-77a7-11e3-9592-33f9d38e2b57 EXECUTE sofia/external/sip:userb@172.17.42.1 conference(user/userb-1389104491@sla)
2014-01-07 09:21:38.006392 [INFO] mod_conference.c:8614 using channel sound prefix: /usr/share/freeswitch/sounds/en/us/callie
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:38.006392 [DEBUG] mod_conference.c:7333 Raw Codec Activation Success L16@8000hz 1 channel 20ms
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:38.006392 [DEBUG] mod_rayo.c:3091 got event CHANNEL_EXECUTE
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:38.006392 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_EXECUTE
2014-01-07 09:21:38.006392 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:38.006392 [DEBUG] mod_rayo.c:3019 Locate (id) 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 2
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:38.006392 [DEBUG] mod_rayo.c:3021 Application conference execute
2014-01-07 09:21:38.006392 [DEBUG] mod_rayo.c:3022 Unlock 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:38.006392 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:38.006392 [DEBUG] mod_conference.c:1979 Setup timer success interval: 20 samples: 320
2014-01-07 09:21:38.006392 [DEBUG] mod_rayo.c:2760 looking for mixer: user/userb-1389104491
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:38.026391 [DEBUG] mod_conference.c:7378 Raw Codec Activation Success L16@16000hz 1 channel 20ms
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:38.026391 [DEBUG] switch_core_codec.c:219 sofia/external/sip:userb@172.17.42.1 Push codec L16:70
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:2760 looking for mixer: user/userb-1389104491
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:2688 Locate (id) 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 2
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:2693 creating mixer: user/userb-1389104491
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:38.026391 [DEBUG] switch_core_session.c:871 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:2694 Init user/userb-1389104491@172.17.0.3
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:38.026391 [DEBUG] mod_conference.c:3594 Setup timer soft success interval: 20 samples: 160
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:2723 Deliver 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 => usera@172.17.0.3/firefly-4178 <iq from='015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3' to='usera@172.17.0.3/firefly-4178' type='result' id='blather000e'/>
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:2733 Unlock 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:38.026391 [DEBUG] mod_conference.c:3730 Outbound conference channel answered, setting CFLAG_ANSWERED
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:2731 Deliver 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3' to='usera@172.17.0.3/firefly-4178'><joined xmlns='urn:xmpp:rayo:1' mixer-name='user/userb-1389104491'/></presence>
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:2607 Deliver user/userb-1389104491@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='user/userb-1389104491@172.17.0.3' to='usera@172.17.0.3/firefly-4178'><joined xmlns='urn:xmpp:rayo:1' call-uri='xmpp:015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3'/></presence>
2014-01-07 09:21:38.026391 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:38.046389 [DEBUG] mod_rayo.c:2760 looking for mixer: user/userb-1389104491
2014-01-07 09:21:38.046389 [DEBUG] mod_rayo.c:2761 Locate (id) user/userb-1389104491@172.17.0.3: ref count = 2
2014-01-07 09:21:38.046389 [DEBUG] mod_rayo.c:2773 Unlock user/userb-1389104491@172.17.0.3: ref count = 1
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:38.046389 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <iq from=015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 to=usera@172.17.0.3/firefly-4178 type=result id=blather000e/>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:38.046389 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 to=usera@172.17.0.3/firefly-4178><joined xmlns=urn:xmpp:rayo:1 mixer-name=user/userb-1389104491/></presence>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:38.046389 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=user/userb-1389104491@172.17.0.3 to=usera@172.17.0.3/firefly-4178><joined xmlns=urn:xmpp:rayo:1 call-uri=xmpp:015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3/></presence>
2014-01-07 09:21:38.086390 [DEBUG] mod_rayo.c:2760 looking for mixer: user/userb-1389104491
2014-01-07 09:21:38.086390 [DEBUG] mod_rayo.c:2761 Locate (id) user/userb-1389104491@172.17.0.3: ref count = 2
2014-01-07 09:21:38.086390 [DEBUG] mod_rayo.c:2773 Unlock user/userb-1389104491@172.17.0.3: ref count = 1
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:38.186396 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 RECV <iq type="set" to="user/userb-1389104491@172.17.0.3" id="blather0010"><record xmlns="urn:xmpp:rayo:record:1" format="wav" start-beep="false" stop-beep="false"/></iq>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:38.186396 [DEBUG] xmpp_streams.c:1058 usera@172.17.0.3/firefly-4178, state = READY, node type = NODE_NORMAL
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:3338 Lock usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:2579 usera@172.17.0.3/firefly-4178, recv iq, availability = ONLINE
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:3397 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:630 Locate (jid) user/userb-1389104491@172.17.0.3: ref count = 2
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:2582 Deliver usera@172.17.0.3/firefly-4178 => user/userb-1389104491@172.17.0.3 <iq type='set' to='user/userb-1389104491@172.17.0.3' id='blather0010' from='usera@172.17.0.3/firefly-4178'><record xmlns='urn:xmpp:rayo:record:1' format='wav' start-beep='false' stop-beep='false'/></iq>
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:511 user/userb-1389104491@172.17.0.3, looking for MIXER::set:urn:xmpp:rayo:record:1:record command
2014-01-07 09:21:38.186396 [DEBUG] rayo_record_component.c:179 Init user/userb-1389104491@172.17.0.3/record-2
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:1224 Lock user/userb-1389104491@172.17.0.3: ref count = 3
2014-01-07 09:21:38.186396 [DEBUG] rayo_record_component.c:386 Recording started: file = {pause=false}fileman:///var/lib/freeswitch/recordings/user/userb-1389104491-1.wav
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:637 Unlock user/userb-1389104491@172.17.0.3: ref count = 2
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:38.186396 [DEBUG] rayo_components.c:62 Deliver user/userb-1389104491@172.17.0.3/record-2 => usera@172.17.0.3/firefly-4178 <iq from='user/userb-1389104491@172.17.0.3' to='usera@172.17.0.3/firefly-4178' type='result' id='blather0010'><ref xmlns='urn:xmpp:rayo:1' uri='xmpp:user/userb-1389104491@172.17.0.3/record-2'/></iq>
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:38.186396 [DEBUG] switch_event.c:1661 Parsing variable [pause]=[false]
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:38.186396 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <iq from=user/userb-1389104491@172.17.0.3 to=usera@172.17.0.3/firefly-4178 type=result id=blather0010><ref xmlns=urn:xmpp:rayo:1 uri=xmpp:user/userb-1389104491@172.17.0.3/record-2/></iq>
2014-01-07 09:21:38.186396 [DEBUG] rayo_output_component.c:624 Got path /var/lib/freeswitch/recordings/user/userb-1389104491-1.wav
2014-01-07 09:21:38.186396 [ERR] mod_sndfile.c:202 Error Opening File [/var/lib/freeswitch/recordings/user/userb-1389104491-1.wav] [System error : No such file or directory.]
2014-01-07 09:21:38.186396 [ERR] mod_conference.c:3985 Error Opening File [{pause=false}fileman:///var/lib/freeswitch/recordings/user/userb-1389104491-1.wav]
2014-01-07 09:21:38.186396 [ERR] switch_core_timer.c:117 Timer is not properly configured.
2014-01-07 09:21:38.186396 [DEBUG] mod_conference.c:4102 Recording of {pause=false}fileman:///var/lib/freeswitch/recordings/user/userb-1389104491-1.wav Stopped
2014-01-07 09:21:38.186396 [DEBUG] rayo_record_component.c:356 Locate (id) user/userb-1389104491@172.17.0.3/record-2: ref count = 2
user/userb-1389104491 2014-01-07 09:21:38.186396 [DEBUG] rayo_record_component.c:104 Recording /var/lib/freeswitch/recordings/user/userb-1389104491-1.wav done.
2014-01-07 09:21:38.186396 [DEBUG] rayo_components.c:116 Unlock user/userb-1389104491@172.17.0.3/record-2: ref count = 1
2014-01-07 09:21:38.186396 [DEBUG] rayo_components.c:117 Destroy user/userb-1389104491@172.17.0.3/record-2 requested: ref_count = 1
2014-01-07 09:21:38.186396 [DEBUG] rayo_record_component.c:126 Unlock user/userb-1389104491@172.17.0.3/record-2: ref count = 0
2014-01-07 09:21:38.186396 [DEBUG] rayo_record_component.c:126 Destroying user/userb-1389104491@172.17.0.3/record-2
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:1199 Unlock user/userb-1389104491@172.17.0.3: ref count = 1
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:2760 looking for mixer: user/userb-1389104491
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:2761 Locate (id) user/userb-1389104491@172.17.0.3: ref count = 2
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:2773 Unlock user/userb-1389104491@172.17.0.3: ref count = 1
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:38.186396 [DEBUG] rayo_components.c:115 Deliver user/userb-1389104491@172.17.0.3/record-2 => usera@172.17.0.3/firefly-4178 <presence from='user/userb-1389104491@172.17.0.3/record-2' to='usera@172.17.0.3/firefly-4178' type='unavailable'><complete xmlns='urn:xmpp:rayo:ext:1'><final-timeout xmlns='urn:xmpp:rayo:record:complete:1'/><recording xmlns='urn:xmpp:rayo:record:complete:1' uri='file:///var/lib/freeswitch/recordings/user/userb-1389104491-1.wav' duration='0' size='0'/></complete></presence>
2014-01-07 09:21:38.186396 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:38.186396 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=user/userb-1389104491@172.17.0.3/record-2 to=usera@172.17.0.3/firefly-4178 type=unavailable><complete xmlns=urn:xmpp:rayo:ext:1><final-timeout xmlns=urn:xmpp:rayo:record:complete:1/><recording xmlns=urn:xmpp:rayo:record:complete:1 uri=file:///var/lib/freeswitch/recordings/user/userb-1389104491-1.wav duration=0 size=0/></complete></presence>
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:38.206390 [INFO] switch_rtp.c:3730 Auto Changing port from 192.168.1.3:7078 to 172.17.42.1:7078
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 RECV <iq type="set" to="172.17.0.3" id="blather0012"><dial xmlns="urn:xmpp:rayo:1" to="user/userc" from="user/userb" timeout="10000"/></iq>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] xmpp_streams.c:1058 usera@172.17.0.3/firefly-4178, state = READY, node type = NODE_NORMAL
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:3338 Lock usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:2579 usera@172.17.0.3/firefly-4178, recv iq, availability = ONLINE
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:3397 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:630 Locate (jid) 172.17.0.3: ref count = 2
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:2582 Deliver usera@172.17.0.3/firefly-4178 => 172.17.0.3 <iq type='set' to='172.17.0.3' id='blather0012' from='usera@172.17.0.3/firefly-4178'><dial xmlns='urn:xmpp:rayo:1' to='user/userc' from='user/userb' timeout='10000'/></iq>
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:511 172.17.0.3, looking for SERVER::set:urn:xmpp:rayo:1:dial command
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:637 Unlock 172.17.0.3: ref count = 1
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:2172 Init 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [INFO] mod_rayo.c:2175 usera@172.17.0.3/firefly-4178 has control of call
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:2272 Using dialstring: {origination_uuid=053d1e6e-77a7-11e3-959b-33f9d38e2b57,rayo_dcp_jid=usera@172.17.0.3/firefly-4178,rayo_call_jid=053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3,origination_caller_id_number=user/userb,origination_caller_id_name=user/userb,originate_timeout=10}user/userc &rayo
2014-01-07 09:21:38.226398 [DEBUG] switch_ivr_originate.c:2061 Parsing global variables
2014-01-07 09:21:38.226398 [DEBUG] switch_event.c:1661 Parsing variable [origination_uuid]=[053d1e6e-77a7-11e3-959b-33f9d38e2b57]
2014-01-07 09:21:38.226398 [DEBUG] switch_event.c:1661 Parsing variable [rayo_dcp_jid]=[usera@172.17.0.3/firefly-4178]
2014-01-07 09:21:38.226398 [DEBUG] switch_event.c:1661 Parsing variable [rayo_call_jid]=[053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3]
2014-01-07 09:21:38.226398 [DEBUG] switch_event.c:1661 Parsing variable [origination_caller_id_number]=[user/userb]
2014-01-07 09:21:38.226398 [DEBUG] switch_event.c:1661 Parsing variable [origination_caller_id_name]=[user/userb]
2014-01-07 09:21:38.226398 [DEBUG] switch_event.c:1661 Parsing variable [originate_timeout]=[10]
2014-01-07 09:21:38.226398 [DEBUG] switch_ivr_originate.c:2061 Parsing global variables
2014-01-07 09:21:38.226398 [DEBUG] switch_event.c:1661 Parsing variable [sip_invite_domain]=[172.17.0.3]
2014-01-07 09:21:38.226398 [DEBUG] switch_event.c:1661 Parsing variable [presence_id]=[userc@172.17.0.3]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [NOTICE] switch_channel.c:1052 New Channel sofia/external/sip:userc@172.17.42.1 [053d1e6e-77a7-11e3-959b-33f9d38e2b57]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] mod_sofia.c:5231 (sofia/external/sip:userc@172.17.42.1) State Change CS_NEW -> CS_INIT
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_session.c:586 sofia/external/sip:userc@172.17.42.1 set UUID=053d1e6e-77a7-11e3-959b-33f9d38e2b57
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sip:userc@172.17.42.1) Running State Change CS_INIT
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_state_machine.c:455 (sofia/external/sip:userc@172.17.42.1) State INIT
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] mod_sofia.c:87 sofia/external/sip:userc@172.17.42.1 SOFIA INIT
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] sofia_glue.c:2739 Local SDP:
053d1e6e-77a7-11e3-959b-33f9d38e2b57 v=0
053d1e6e-77a7-11e3-959b-33f9d38e2b57 o=FreeSWITCH 1389076200 1389076201 IN IP4 172.17.0.3
053d1e6e-77a7-11e3-959b-33f9d38e2b57 s=FreeSWITCH
053d1e6e-77a7-11e3-959b-33f9d38e2b57 c=IN IP4 172.17.0.3
053d1e6e-77a7-11e3-959b-33f9d38e2b57 t=0 0
053d1e6e-77a7-11e3-959b-33f9d38e2b57 m=audio 28298 RTP/AVP 0 8 101 13
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=rtpmap:101 telephone-event/8000
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=fmtp:101 0-16
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=ptime:20
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=sendrecv
053d1e6e-77a7-11e3-959b-33f9d38e2b57
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] mod_sofia.c:127 (sofia/external/sip:userc@172.17.42.1) State Change CS_INIT -> CS_ROUTING
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_state_machine.c:455 (sofia/external/sip:userc@172.17.42.1) State INIT going to sleep
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sip:userc@172.17.42.1) Running State Change CS_ROUTING
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_state_machine.c:471 (sofia/external/sip:userc@172.17.42.1) State ROUTING
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] mod_sofia.c:150 sofia/external/sip:userc@172.17.42.1 SOFIA ROUTING
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_ivr_originate.c:67 (sofia/external/sip:userc@172.17.42.1) State Change CS_ROUTING -> CS_CONSUME_MEDIA
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_state_machine.c:471 (sofia/external/sip:userc@172.17.42.1) State ROUTING going to sleep
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sip:userc@172.17.42.1) Running State Change CS_CONSUME_MEDIA
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_state_machine.c:490 (sofia/external/sip:userc@172.17.42.1) State CONSUME_MEDIA
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_state_machine.c:490 (sofia/external/sip:userc@172.17.42.1) State CONSUME_MEDIA going to sleep
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userc@172.17.42.1 entering state [calling][0]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userc@172.17.42.1 entering state [proceeding][101]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:3091 got event CHANNEL_ORIGINATE
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_ORIGINATE
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:2785 Locate (id) 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 2
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:2790 Got originate event
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:2812 Unlock 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:2806 Deliver 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 => usera@172.17.0.3/firefly-4178 <iq from='172.17.0.3' to='usera@172.17.0.3/firefly-4178' id='blather0012' type='result'><ref xmlns='urn:xmpp:rayo:1' uri='xmpp:053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3'/></iq>
2014-01-07 09:21:38.226398 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:38.246395 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <iq from=172.17.0.3 to=usera@172.17.0.3/firefly-4178 id=blather0012 type=result><ref xmlns=urn:xmpp:rayo:1 uri=xmpp:053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3/></iq>
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.246395 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.246395 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.246395 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userc@172.17.42.1 entering state [proceeding][180]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.246395 [NOTICE] sofia.c:5874 Ring-Ready sofia/external/sip:userc@172.17.42.1!
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.246395 [DEBUG] mod_rayo.c:3091 got event CHANNEL_PROGRESS
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.246395 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_PROGRESS
2014-01-07 09:21:38.246395 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:38.246395 [DEBUG] mod_rayo.c:2870 Locate (id) 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 2
2014-01-07 09:21:38.246395 [DEBUG] mod_rayo.c:2881 Unlock 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:38.246395 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:38.246395 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:38.246395 [DEBUG] mod_rayo.c:2878 Deliver 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3' to='usera@172.17.0.3/firefly-4178'><ringing xmlns='urn:xmpp:rayo:1'/></presence>
2014-01-07 09:21:38.246395 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:38.246395 [DEBUG] switch_channel.c:3238 (sofia/external/sip:userc@172.17.42.1) Callstate Change DOWN -> RINGING
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:38.266397 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 to=usera@172.17.0.3/firefly-4178><ringing xmlns=urn:xmpp:rayo:1/></presence>
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:39.926416 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:39.926416 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:39.946394 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userb@172.17.42.1 entering state [received][100]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:39.946394 [DEBUG] sofia.c:5792 Remote SDP:
015cb21e-77a7-11e3-9592-33f9d38e2b57 v=0
015cb21e-77a7-11e3-9592-33f9d38e2b57 o=userc 3333 1997 IN IP4 192.168.1.3
015cb21e-77a7-11e3-9592-33f9d38e2b57 s=Talk
015cb21e-77a7-11e3-9592-33f9d38e2b57 c=IN IP4 0.0.0.0
015cb21e-77a7-11e3-9592-33f9d38e2b57 t=0 0
015cb21e-77a7-11e3-9592-33f9d38e2b57 m=audio 7078 RTP/AVP 125 111 110 0 8 101
015cb21e-77a7-11e3-9592-33f9d38e2b57 c=IN IP4 192.168.1.3
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=rtpmap:125 opus/48000
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=fmtp:125 useinbandfec=1; usedtx=1
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=rtpmap:111 speex/16000
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=fmtp:111 vbr=on
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=rtpmap:110 speex/8000
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=fmtp:110 vbr=on
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=rtpmap:101 telephone-event/8000
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=fmtp:101 0-11
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=sendonly
015cb21e-77a7-11e3-9592-33f9d38e2b57
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:39.946394 [DEBUG] switch_channel.c:1786 (sofia/external/sip:userb@172.17.42.1) Callstate Change ACTIVE -> HELD
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.946394 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.946394 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.946394 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userc@172.17.42.1 entering state [completing][200]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.946394 [DEBUG] sofia.c:5792 Remote SDP:
053d1e6e-77a7-11e3-959b-33f9d38e2b57 v=0
053d1e6e-77a7-11e3-959b-33f9d38e2b57 o=userc 2501 1235 IN IP4 192.168.1.3
053d1e6e-77a7-11e3-959b-33f9d38e2b57 s=Talk
053d1e6e-77a7-11e3-959b-33f9d38e2b57 c=IN IP4 192.168.1.3
053d1e6e-77a7-11e3-959b-33f9d38e2b57 t=0 0
053d1e6e-77a7-11e3-959b-33f9d38e2b57 m=audio 7080 RTP/AVP 0 8 101
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=rtpmap:0 PCMU/8000
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=rtpmap:8 PCMA/8000
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=rtpmap:101 telephone-event/8000
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=fmtp:101 0-11
053d1e6e-77a7-11e3-959b-33f9d38e2b57
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userc@172.17.42.1 entering state [ready][200]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] sofia_glue.c:3186 Set Codec sofia/external/sip:userc@172.17.42.1 PCMU/8000 20 ms 160 samples 64000 bits
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] switch_core_codec.c:111 sofia/external/sip:userc@172.17.42.1 Original read codec set to PCMU:0
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] sofia_glue.c:5437 Set 2833 dtmf send payload to 101
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] sofia_glue.c:3445 AUDIO RTP [sofia/external/sip:userc@172.17.42.1] 172.17.0.3 port 28298 -> 192.168.1.3 port 7080 codec: 0 ms: 20
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] switch_rtp.c:2033 Starting timer [soft] 160 bytes per 20ms
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] sofia_glue.c:3712 Set 2833 dtmf send payload to 101
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] sofia_glue.c:3718 Set 2833 dtmf receive payload to 101
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] sofia_glue.c:3745 sofia/external/sip:userc@172.17.42.1 Set rtp dtmf delay to 40
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [NOTICE] sofia.c:6568 Channel [sofia/external/sip:userc@172.17.42.1] has been answered
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:3091 got event CHANNEL_ANSWER
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_ANSWER
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:2851 Locate (id) 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 2
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:2857 Unlock 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:2856 Deliver 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3' to='usera@172.17.0.3/firefly-4178'><answered xmlns='urn:xmpp:rayo:1'/></presence>
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] switch_channel.c:3643 (sofia/external/sip:userc@172.17.42.1) Callstate Change RINGING -> ACTIVE
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 to=usera@172.17.0.3/firefly-4178><answered xmlns=urn:xmpp:rayo:1/></presence>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 RECV <iq type="set" to="053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3" id="blather0014"><join xmlns="urn:xmpp:rayo:1" mixer-name="user/userb-1389104491"/></iq>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] xmpp_streams.c:1058 usera@172.17.0.3/firefly-4178, state = READY, node type = NODE_NORMAL
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:3338 Lock usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:2579 usera@172.17.0.3/firefly-4178, recv iq, availability = ONLINE
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:3397 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:630 Locate (jid) 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 2
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:2582 Deliver usera@172.17.0.3/firefly-4178 => 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 <iq type='set' to='053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3' id='blather0014' from='usera@172.17.0.3/firefly-4178'><join xmlns='urn:xmpp:rayo:1' mixer-name='user/userb-1389104491'/></iq>
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:511 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3, looking for CALL::set:urn:xmpp:rayo:1:join command
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:1557 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3, executing command
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.966399 [DEBUG] switch_core_session.c:1151 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:1559 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3, done executing command
2014-01-07 09:21:39.966399 [DEBUG] mod_rayo.c:637 Unlock 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:39.986392 [DEBUG] switch_ivr_originate.c:3495 Originate Resulted in Success: [sofia/external/sip:userc@172.17.42.1]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] switch_ivr.c:615 sofia/external/sip:userc@172.17.42.1 Command Execute conference(user/userb-1389104491@sla)
053d1e6e-77a7-11e3-959b-33f9d38e2b57 EXECUTE sofia/external/sip:userc@172.17.42.1 conference(user/userb-1389104491@sla)
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] mod_conference.c:7333 Raw Codec Activation Success L16@8000hz 1 channel 20ms
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] mod_conference.c:7378 Raw Codec Activation Success L16@16000hz 1 channel 20ms
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] switch_core_codec.c:219 sofia/external/sip:userc@172.17.42.1 Push codec L16:70
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] switch_core_session.c:871 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] mod_conference.c:3594 Setup timer soft success interval: 20 samples: 160
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:3091 got event CHANNEL_EXECUTE
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_EXECUTE
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:3019 Locate (id) 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 2
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:3021 Application conference execute
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:3022 Unlock 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:39.986392 [DEBUG] switch_ivr_originate.c:3495 Originate Resulted in Success: [sofia/external/sip:userc@172.17.42.1]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.986392 [INFO] switch_channel.c:3028 sofia/external/sip:userc@172.17.42.1 Flipping CID from "userb" <userb> to "Outbound Call" <userc>
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] mod_commands.c:4182 (sofia/external/sip:userc@172.17.42.1) State Change CS_CONSUME_MEDIA -> CS_EXECUTE
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:2276 Got originate result: +OK 053d1e6e-77a7-11e3-959b-33f9d38e2b57
053d1e6e-77a7-11e3-959b-33f9d38e2b57
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:2760 looking for mixer: user/userb-1389104491
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:2761 Locate (id) user/userb-1389104491@172.17.0.3: ref count = 2
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:2688 Locate (id) 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 2
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:2733 Unlock 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:2723 Deliver 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 => usera@172.17.0.3/firefly-4178 <iq from='053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3' to='usera@172.17.0.3/firefly-4178' type='result' id='blather0014'/>
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:2731 Deliver 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3' to='usera@172.17.0.3/firefly-4178'><joined xmlns='urn:xmpp:rayo:1' mixer-name='user/userb-1389104491'/></presence>
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:2607 Deliver user/userb-1389104491@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='user/userb-1389104491@172.17.0.3' to='usera@172.17.0.3/firefly-4178'><joined xmlns='urn:xmpp:rayo:1' call-uri='xmpp:053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3'/></presence>
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:39.986392 [DEBUG] mod_rayo.c:2773 Unlock user/userb-1389104491@172.17.0.3: ref count = 1
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <iq from=053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 to=usera@172.17.0.3/firefly-4178 type=result id=blather0014/>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 to=usera@172.17.0.3/firefly-4178><joined xmlns=urn:xmpp:rayo:1 mixer-name=user/userb-1389104491/></presence>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:39.986392 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=user/userb-1389104491@172.17.0.3 to=usera@172.17.0.3/firefly-4178><joined xmlns=urn:xmpp:rayo:1 call-uri=xmpp:053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3/></presence>
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] mod_conference.c:3896 Channel leaving conference, cause: NONE
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] switch_core_session.c:871 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] switch_core_codec.c:244 sofia/external/sip:userc@172.17.42.1 Restore previous codec PCMU:0.
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:2760 looking for mixer: user/userb-1389104491
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:2761 Locate (id) user/userb-1389104491@172.17.0.3: ref count = 2
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:2636 Locate (id) 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 2
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:2640 Unlock 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:2773 Unlock user/userb-1389104491@172.17.0.3: ref count = 1
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:2647 Deliver user/userb-1389104491@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3' to='usera@172.17.0.3/firefly-4178'><unjoined xmlns='urn:xmpp:rayo:1' mixer-name='user/userb-1389104491'/></presence>
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:2607 Deliver user/userb-1389104491@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='user/userb-1389104491@172.17.0.3' to='usera@172.17.0.3/firefly-4178'><unjoined xmlns='urn:xmpp:rayo:1' call-uri='xmpp:053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3'/></presence>
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sip:userc@172.17.42.1) Running State Change CS_EXECUTE
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] switch_core_state_machine.c:478 (sofia/external/sip:userc@172.17.42.1) State EXECUTE
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] mod_sofia.c:243 sofia/external/sip:userc@172.17.42.1 SOFIA EXECUTE
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] switch_core_state_machine.c:209 sofia/external/sip:userc@172.17.42.1 Standard EXECUTE
053d1e6e-77a7-11e3-959b-33f9d38e2b57 EXECUTE sofia/external/sip:userc@172.17.42.1 rayo()
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] switch_ivr.c:959 Codec Activated L16@8000hz 1 channels 20ms
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3091 got event CHANNEL_EXECUTE_COMPLETE
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_EXECUTE_COMPLETE
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3033 Locate (id) 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 2
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3036 Application conference execute complete: _none_
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3039 Unlock 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3091 got event CHANNEL_EXECUTE
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_EXECUTE
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3019 Locate (id) 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 2
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3021 Application rayo execute
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3022 Unlock 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:40.026397 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 to=usera@172.17.0.3/firefly-4178><unjoined xmlns=urn:xmpp:rayo:1 mixer-name=user/userb-1389104491/></presence>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:40.026397 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=user/userb-1389104491@172.17.0.3 to=usera@172.17.0.3/firefly-4178><unjoined xmlns=urn:xmpp:rayo:1 call-uri=xmpp:053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3/></presence>
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.186405 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [opus:125:48000:20:0]/[PCMU:0:8000:20:64000]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.186405 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [speex:111:16000:20:0]/[PCMU:0:8000:20:64000]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.186405 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [speex:110:8000:20:0]/[PCMU:0:8000:20:64000]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.186405 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.186405 [DEBUG] sofia_glue.c:3115 Already using PCMU
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.186405 [DEBUG] sofia_glue.c:5437 Set 2833 dtmf send payload to 101
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.186405 [DEBUG] sofia_glue.c:3415 Audio params are unchanged for sofia/external/sip:userb@172.17.42.1.
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.186405 [DEBUG] sofia_glue.c:3425 sofia/external/sip:userb@172.17.42.1 Setting audio receive payload in Re-INVITE to 0
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.186405 [DEBUG] sofia.c:6358 Processing updated SDP
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.186405 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.186405 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userb@172.17.42.1 entering state [completed][200]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.206409 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.206409 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.206409 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:40.226407 [INFO] switch_rtp.c:3730 Auto Changing port from 192.168.1.3:7080 to 172.17.42.1:7080
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:40.226407 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userb@172.17.42.1 entering state [ready][200]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.046405 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.046405 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.046405 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.046405 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.066392 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userb@172.17.42.1 entering state [received][100]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.066392 [DEBUG] sofia.c:5792 Remote SDP:
015cb21e-77a7-11e3-9592-33f9d38e2b57 v=0
015cb21e-77a7-11e3-9592-33f9d38e2b57 o=userc 3333 1998 IN IP4 192.168.1.3
015cb21e-77a7-11e3-9592-33f9d38e2b57 s=Talk
015cb21e-77a7-11e3-9592-33f9d38e2b57 c=IN IP4 192.168.1.3
015cb21e-77a7-11e3-9592-33f9d38e2b57 t=0 0
015cb21e-77a7-11e3-9592-33f9d38e2b57 m=audio 7078 RTP/AVP 125 111 110 0 8 101
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=rtpmap:125 opus/48000
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=fmtp:125 useinbandfec=1; usedtx=1
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=rtpmap:111 speex/16000
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=fmtp:111 vbr=on
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=rtpmap:110 speex/8000
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=fmtp:110 vbr=on
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=rtpmap:101 telephone-event/8000
015cb21e-77a7-11e3-9592-33f9d38e2b57 a=fmtp:101 0-11
015cb21e-77a7-11e3-9592-33f9d38e2b57
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.066392 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userc@172.17.42.1 entering state [received][100]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.066392 [DEBUG] sofia.c:5792 Remote SDP:
053d1e6e-77a7-11e3-959b-33f9d38e2b57 v=0
053d1e6e-77a7-11e3-959b-33f9d38e2b57 o=userc 2501 1236 IN IP4 192.168.1.3
053d1e6e-77a7-11e3-959b-33f9d38e2b57 s=Talk
053d1e6e-77a7-11e3-959b-33f9d38e2b57 c=IN IP4 0.0.0.0
053d1e6e-77a7-11e3-959b-33f9d38e2b57 t=0 0
053d1e6e-77a7-11e3-959b-33f9d38e2b57 m=audio 7080 RTP/AVP 125 111 110 0 8 101
053d1e6e-77a7-11e3-959b-33f9d38e2b57 c=IN IP4 192.168.1.3
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=rtpmap:125 opus/48000
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=fmtp:125 useinbandfec=1; usedtx=1
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=rtpmap:111 speex/16000
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=fmtp:111 vbr=on
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=rtpmap:110 speex/8000
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=fmtp:110 vbr=on
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=rtpmap:101 telephone-event/8000
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=fmtp:101 0-11
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=sendonly
053d1e6e-77a7-11e3-959b-33f9d38e2b57
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.066392 [DEBUG] switch_channel.c:1786 (sofia/external/sip:userc@172.17.42.1) Callstate Change ACTIVE -> HELD
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] switch_channel.c:1954 (sofia/external/sip:userb@172.17.42.1) Callstate Change HELD -> UNHOLD
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [opus:125:48000:20:0]/[PCMU:0:8000:20:64000]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [speex:111:16000:20:0]/[PCMU:0:8000:20:64000]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [speex:110:8000:20:0]/[PCMU:0:8000:20:64000]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:3115 Already using PCMU
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:5437 Set 2833 dtmf send payload to 101
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:3415 Audio params are unchanged for sofia/external/sip:userc@172.17.42.1.
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:3425 sofia/external/sip:userc@172.17.42.1 Setting audio receive payload in Re-INVITE to 0
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia.c:6358 Processing updated SDP
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [opus:125:48000:20:0]/[PCMU:0:8000:20:64000]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [speex:111:16000:20:0]/[PCMU:0:8000:20:64000]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [speex:110:8000:20:0]/[PCMU:0:8000:20:64000]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:3115 Already using PCMU
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:5437 Set 2833 dtmf send payload to 101
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:3415 Audio params are unchanged for sofia/external/sip:userb@172.17.42.1.
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia_glue.c:3425 sofia/external/sip:userb@172.17.42.1 Setting audio receive payload in Re-INVITE to 0
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia.c:6358 Processing updated SDP
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.306399 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userc@172.17.42.1 entering state [completed][200]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.326435 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userb@172.17.42.1 entering state [completed][200]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.326435 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.326435 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.326435 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.326435 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.326435 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.326435 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.346397 [DEBUG] switch_rtp.c:3749 Correct ip/port confirmed.
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:44.346397 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userc@172.17.42.1 entering state [ready][200]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:44.346397 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userb@172.17.42.1 entering state [ready][200]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.386474 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [NOTICE] sofia.c:737 Hangup sofia/external/sip:userb@172.17.42.1 [CS_EXECUTE] [NORMAL_CLEARING]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_channel.c:3183 Send signal sofia/external/sip:userb@172.17.42.1 [KILL]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] mod_conference.c:3896 Channel leaving conference, cause: NORMAL_CLEARING
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] mod_conference.c:7922 sofia/external/sip:userb@172.17.42.1 skip receive message [UNBRIDGE] (channel is hungup already)
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_codec.c:244 sofia/external/sip:userb@172.17.42.1 Restore previous codec PCMU:0.
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_session.c:2810 sofia/external/sip:userb@172.17.42.1 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_ivr.c:658 sofia/external/sip:userb@172.17.42.1 skip receive message [AUDIO_SYNC] (channel is hungup already)
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_session.c:2810 sofia/external/sip:userb@172.17.42.1 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:478 (sofia/external/sip:userb@172.17.42.1) State EXECUTE going to sleep
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sip:userb@172.17.42.1) Running State Change CS_HANGUP
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:679 (sofia/external/sip:userb@172.17.42.1) State HANGUP
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] mod_sofia.c:506 Channel sofia/external/sip:userb@172.17.42.1 hanging up, cause: NORMAL_CLEARING
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:48 sofia/external/sip:userb@172.17.42.1 Standard HANGUP, cause: NORMAL_CLEARING
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:679 (sofia/external/sip:userb@172.17.42.1) State HANGUP going to sleep
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:690 (sofia/external/sip:userb@172.17.42.1) Callstate Change UNHOLD -> HANGUP
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:447 (sofia/external/sip:userb@172.17.42.1) State Change CS_HANGUP -> CS_REPORTING
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sip:userb@172.17.42.1) Running State Change CS_REPORTING
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:762 (sofia/external/sip:userb@172.17.42.1) State REPORTING
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:92 sofia/external/sip:userb@172.17.42.1 Standard REPORTING, cause: NORMAL_CLEARING
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:762 (sofia/external/sip:userb@172.17.42.1) State REPORTING going to sleep
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:441 (sofia/external/sip:userb@172.17.42.1) State Change CS_REPORTING -> CS_DESTROY
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userb@172.17.42.1 [BREAK]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_session.c:1559 Session 1 (sofia/external/sip:userb@172.17.42.1) Locked, Waiting on external entities
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [NOTICE] switch_core_session.c:1577 Session 1 (sofia/external/sip:userb@172.17.42.1) Ended
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [NOTICE] switch_core_session.c:1581 Close Channel sofia/external/sip:userb@172.17.42.1 [CS_DESTROY]
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:566 (sofia/external/sip:userb@172.17.42.1) Callstate Change HANGUP -> DOWN
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:569 (sofia/external/sip:userb@172.17.42.1) Running State Change CS_DESTROY
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:579 (sofia/external/sip:userb@172.17.42.1) State DESTROY
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] mod_sofia.c:399 sofia/external/sip:userb@172.17.42.1 SOFIA DESTROY
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:99 sofia/external/sip:userb@172.17.42.1 Standard DESTROY
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] switch_core_state_machine.c:579 (sofia/external/sip:userb@172.17.42.1) State DESTROY going to sleep
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2760 looking for mixer: user/userb-1389104491
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2761 Locate (id) user/userb-1389104491@172.17.0.3: ref count = 2
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2773 Unlock user/userb-1389104491@172.17.0.3: ref count = 1
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2760 looking for mixer: user/userb-1389104491
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2761 Locate (id) user/userb-1389104491@172.17.0.3: ref count = 2
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2636 Locate (id) 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 2
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2640 Unlock 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2773 Unlock user/userb-1389104491@172.17.0.3: ref count = 1
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2647 Deliver user/userb-1389104491@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3' to='usera@172.17.0.3/firefly-4178'><unjoined xmlns='urn:xmpp:rayo:1' mixer-name='user/userb-1389104491'/></presence>
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2607 Deliver user/userb-1389104491@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='user/userb-1389104491@172.17.0.3' to='usera@172.17.0.3/firefly-4178'><unjoined xmlns='urn:xmpp:rayo:1' call-uri='xmpp:015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3'/></presence>
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3091 got event CHANNEL_EXECUTE_COMPLETE
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_EXECUTE_COMPLETE
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3033 Locate (id) 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 2
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3036 Application conference execute complete: _none_
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3039 Unlock 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3091 got event CHANNEL_EXECUTE_COMPLETE
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_EXECUTE_COMPLETE
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3033 Locate (id) 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 2
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3036 Application rayo execute complete: _none_
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3039 Unlock 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] rayo_cpa_component.c:130 Subscriber execute hangup
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] rayo_cpa_component.c:143 No subscribers for hangup
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2821 Locate (id) 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 2
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2831 Got channel destroy event
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2836 Destroy 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 requested: ref_count = 2
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2837 Unlock 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2840 Unlock 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3: ref count = 0
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:2840 Destroying 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3
015cb21e-77a7-11e3-9592-33f9d38e2b57 2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:954 Sending <end> to DCP usera@172.17.0.3/firefly-4178
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:955 Deliver 015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3' to='usera@172.17.0.3/firefly-4178' type='unavailable'><end xmlns='urn:xmpp:rayo:1'><hungup/></end></presence>
2014-01-07 09:21:46.406397 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:21:46.426403 [DEBUG] mod_conference.c:2530 Write Lock ON
2014-01-07 09:21:46.426403 [DEBUG] mod_conference.c:2533 Write Lock OFF
2014-01-07 09:21:46.426403 [DEBUG] mod_rayo.c:2760 looking for mixer: user/userb-1389104491
2014-01-07 09:21:46.426403 [DEBUG] mod_rayo.c:2761 Locate (id) user/userb-1389104491@172.17.0.3: ref count = 2
2014-01-07 09:21:46.426403 [DEBUG] mod_rayo.c:2673 user/userb-1389104491@172.17.0.3, destroying mixer: user/userb-1389104491
2014-01-07 09:21:46.426403 [DEBUG] mod_rayo.c:2674 Unlock user/userb-1389104491@172.17.0.3: ref count = 1
2014-01-07 09:21:46.426403 [DEBUG] mod_rayo.c:2675 Destroy user/userb-1389104491@172.17.0.3 requested: ref_count = 1
2014-01-07 09:21:46.426403 [DEBUG] mod_rayo.c:2773 Unlock user/userb-1389104491@172.17.0.3: ref count = 0
2014-01-07 09:21:46.426403 [DEBUG] mod_rayo.c:2773 Destroying user/userb-1389104491@172.17.0.3
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:46.426403 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 to=usera@172.17.0.3/firefly-4178><unjoined xmlns=urn:xmpp:rayo:1 mixer-name=user/userb-1389104491/></presence>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:46.426403 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=user/userb-1389104491@172.17.0.3 to=usera@172.17.0.3/firefly-4178><unjoined xmlns=urn:xmpp:rayo:1 call-uri=xmpp:015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3/></presence>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:46.426403 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=015cb21e-77a7-11e3-9592-33f9d38e2b57@172.17.0.3 to=usera@172.17.0.3/firefly-4178 type=unavailable><end xmlns=urn:xmpp:rayo:1><hungup/></end></presence>
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.566391 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.566391 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.586391 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userc@172.17.42.1 entering state [received][100]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.586391 [DEBUG] sofia.c:5792 Remote SDP:
053d1e6e-77a7-11e3-959b-33f9d38e2b57 v=0
053d1e6e-77a7-11e3-959b-33f9d38e2b57 o=userc 2501 1237 IN IP4 192.168.1.3
053d1e6e-77a7-11e3-959b-33f9d38e2b57 s=Talk
053d1e6e-77a7-11e3-959b-33f9d38e2b57 c=IN IP4 192.168.1.3
053d1e6e-77a7-11e3-959b-33f9d38e2b57 t=0 0
053d1e6e-77a7-11e3-959b-33f9d38e2b57 m=audio 7080 RTP/AVP 125 111 110 0 8 101
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=rtpmap:125 opus/48000
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=fmtp:125 useinbandfec=1; usedtx=1
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=rtpmap:111 speex/16000
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=fmtp:111 vbr=on
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=rtpmap:110 speex/8000
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=fmtp:110 vbr=on
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=rtpmap:101 telephone-event/8000
053d1e6e-77a7-11e3-959b-33f9d38e2b57 a=fmtp:101 0-11
053d1e6e-77a7-11e3-959b-33f9d38e2b57
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.826387 [DEBUG] switch_channel.c:1954 (sofia/external/sip:userc@172.17.42.1) Callstate Change HELD -> UNHOLD
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.826387 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [opus:125:48000:20:0]/[PCMU:0:8000:20:64000]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.826387 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [speex:111:16000:20:0]/[PCMU:0:8000:20:64000]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.826387 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [speex:110:8000:20:0]/[PCMU:0:8000:20:64000]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.826387 [DEBUG] sofia_glue.c:5278 Audio Codec Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.826387 [DEBUG] sofia_glue.c:3115 Already using PCMU
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.826387 [DEBUG] sofia_glue.c:5437 Set 2833 dtmf send payload to 101
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.826387 [DEBUG] sofia_glue.c:3415 Audio params are unchanged for sofia/external/sip:userc@172.17.42.1.
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.826387 [DEBUG] sofia_glue.c:3425 sofia/external/sip:userc@172.17.42.1 Setting audio receive payload in Re-INVITE to 0
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.826387 [DEBUG] sofia.c:6358 Processing updated SDP
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.826387 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.826387 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userc@172.17.42.1 entering state [completed][200]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.846386 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.846386 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.846386 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.866433 [DEBUG] sofia.c:5779 Channel sofia/external/sip:userc@172.17.42.1 entering state [ready][200]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:48.886394 [DEBUG] switch_rtp.c:3749 Correct ip/port confirmed.
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.106391 [DEBUG] switch_core_session.c:1016 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [NOTICE] sofia.c:737 Hangup sofia/external/sip:userc@172.17.42.1 [CS_EXECUTE] [NORMAL_CLEARING]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_channel.c:3183 Send signal sofia/external/sip:userc@172.17.42.1 [KILL]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_session.c:2810 sofia/external/sip:userc@172.17.42.1 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:478 (sofia/external/sip:userc@172.17.42.1) State EXECUTE going to sleep
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sip:userc@172.17.42.1) Running State Change CS_HANGUP
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:3091 got event CHANNEL_EXECUTE_COMPLETE
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:3096 usera@172.17.0.3/firefly-4178 rayo event CHANNEL_EXECUTE_COMPLETE
2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:3098 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:3033 Locate (id) 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 2
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:679 (sofia/external/sip:userc@172.17.42.1) State HANGUP
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:3036 Application rayo execute complete: _none_
2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:3039 Unlock 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:3106 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] mod_sofia.c:506 Channel sofia/external/sip:userc@172.17.42.1 hanging up, cause: NORMAL_CLEARING
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:48 sofia/external/sip:userc@172.17.42.1 Standard HANGUP, cause: NORMAL_CLEARING
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:679 (sofia/external/sip:userc@172.17.42.1) State HANGUP going to sleep
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:690 (sofia/external/sip:userc@172.17.42.1) Callstate Change UNHOLD -> HANGUP
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:447 (sofia/external/sip:userc@172.17.42.1) State Change CS_HANGUP -> CS_REPORTING
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:415 (sofia/external/sip:userc@172.17.42.1) Running State Change CS_REPORTING
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:762 (sofia/external/sip:userc@172.17.42.1) State REPORTING
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:92 sofia/external/sip:userc@172.17.42.1 Standard REPORTING, cause: NORMAL_CLEARING
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:762 (sofia/external/sip:userc@172.17.42.1) State REPORTING going to sleep
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:441 (sofia/external/sip:userc@172.17.42.1) State Change CS_REPORTING -> CS_DESTROY
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_session.c:1351 Send signal sofia/external/sip:userc@172.17.42.1 [BREAK]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] rayo_cpa_component.c:130 Subscriber execute hangup
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_session.c:1559 Session 2 (sofia/external/sip:userc@172.17.42.1) Locked, Waiting on external entities
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] rayo_cpa_component.c:143 No subscribers for hangup
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [NOTICE] switch_core_session.c:1577 Session 2 (sofia/external/sip:userc@172.17.42.1) Ended
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [NOTICE] switch_core_session.c:1581 Close Channel sofia/external/sip:userc@172.17.42.1 [CS_DESTROY]
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:566 (sofia/external/sip:userc@172.17.42.1) Callstate Change HANGUP -> DOWN
2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:2821 Locate (id) 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 2
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:2831 Got channel destroy event
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:569 (sofia/external/sip:userc@172.17.42.1) Running State Change CS_DESTROY
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:579 (sofia/external/sip:userc@172.17.42.1) State DESTROY
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] mod_sofia.c:399 sofia/external/sip:userc@172.17.42.1 SOFIA DESTROY
2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:2836 Destroy 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 requested: ref_count = 2
2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:2837 Unlock 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 1
2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:2840 Unlock 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3: ref count = 0
2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:2840 Destroying 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:99 sofia/external/sip:userc@172.17.42.1 Standard DESTROY
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] switch_core_state_machine.c:579 (sofia/external/sip:userc@172.17.42.1) State DESTROY going to sleep
053d1e6e-77a7-11e3-959b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:954 Sending <end> to DCP usera@172.17.0.3/firefly-4178
2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:955 Deliver 053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 => usera@172.17.0.3/firefly-4178 <presence from='053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3' to='usera@172.17.0.3/firefly-4178' type='unavailable'><end xmlns='urn:xmpp:rayo:1'><hungup/></end></presence>
2014-01-07 09:21:50.126416 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:21:50.126416 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <presence from=053d1e6e-77a7-11e3-959b-33f9d38e2b57@172.17.0.3 to=usera@172.17.0.3/firefly-4178 type=unavailable><end xmlns=urn:xmpp:rayo:1><hungup/></end></presence>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:22:18.206401 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 RECV <iq type="get" to="172.17.0.3" id="blather0016"><ping xmlns="urn:xmpp:ping"/></iq>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:22:18.206401 [DEBUG] xmpp_streams.c:1058 usera@172.17.0.3/firefly-4178, state = READY, node type = NODE_NORMAL
2014-01-07 09:22:18.206401 [DEBUG] mod_rayo.c:3338 Lock usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:22:18.206401 [DEBUG] mod_rayo.c:2579 usera@172.17.0.3/firefly-4178, recv iq, availability = ONLINE
2014-01-07 09:22:18.206401 [DEBUG] mod_rayo.c:3397 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:22:18.206401 [DEBUG] mod_rayo.c:630 Locate (jid) 172.17.0.3: ref count = 2
2014-01-07 09:22:18.206401 [DEBUG] mod_rayo.c:2582 Deliver usera@172.17.0.3/firefly-4178 => 172.17.0.3 <iq type='get' to='172.17.0.3' id='blather0016' from='usera@172.17.0.3/firefly-4178'><ping xmlns='urn:xmpp:ping'/></iq>
2014-01-07 09:22:18.206401 [DEBUG] mod_rayo.c:511 172.17.0.3, looking for SERVER::get:urn:xmpp:ping:ping command
2014-01-07 09:22:18.206401 [DEBUG] mod_rayo.c:637 Unlock 172.17.0.3: ref count = 1
2014-01-07 09:22:18.206401 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:22:18.206401 [DEBUG] mod_rayo.c:1518 Deliver 172.17.0.3 => usera@172.17.0.3/firefly-4178 <iq type='result' from='172.17.0.3' to='usera@172.17.0.3/firefly-4178' id='blather0016'/>
2014-01-07 09:22:18.206401 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:22:18.206401 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <iq type=result from=172.17.0.3 to=usera@172.17.0.3/firefly-4178 id=blather0016/>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:23:18.266428 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 RECV <iq type="get" to="172.17.0.3" id="blather0018"><ping xmlns="urn:xmpp:ping"/></iq>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:23:18.266428 [DEBUG] xmpp_streams.c:1058 usera@172.17.0.3/firefly-4178, state = READY, node type = NODE_NORMAL
2014-01-07 09:23:18.266428 [DEBUG] mod_rayo.c:3338 Lock usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:23:18.266428 [DEBUG] mod_rayo.c:2579 usera@172.17.0.3/firefly-4178, recv iq, availability = ONLINE
2014-01-07 09:23:18.266428 [DEBUG] mod_rayo.c:3397 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:23:18.266428 [DEBUG] mod_rayo.c:630 Locate (jid) 172.17.0.3: ref count = 2
2014-01-07 09:23:18.266428 [DEBUG] mod_rayo.c:2582 Deliver usera@172.17.0.3/firefly-4178 => 172.17.0.3 <iq type='get' to='172.17.0.3' id='blather0018' from='usera@172.17.0.3/firefly-4178'><ping xmlns='urn:xmpp:ping'/></iq>
2014-01-07 09:23:18.266428 [DEBUG] mod_rayo.c:511 172.17.0.3, looking for SERVER::get:urn:xmpp:ping:ping command
2014-01-07 09:23:18.266428 [DEBUG] mod_rayo.c:637 Unlock 172.17.0.3: ref count = 1
2014-01-07 09:23:18.266428 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:23:18.266428 [DEBUG] mod_rayo.c:1518 Deliver 172.17.0.3 => usera@172.17.0.3/firefly-4178 <iq type='result' from='172.17.0.3' to='usera@172.17.0.3/firefly-4178' id='blather0018'/>
2014-01-07 09:23:18.266428 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:23:18.286454 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <iq type=result from=172.17.0.3 to=usera@172.17.0.3/firefly-4178 id=blather0018/>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:24:18.326466 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 RECV <iq type="get" to="172.17.0.3" id="blather001a"><ping xmlns="urn:xmpp:ping"/></iq>
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:24:18.326466 [DEBUG] xmpp_streams.c:1058 usera@172.17.0.3/firefly-4178, state = READY, node type = NODE_NORMAL
2014-01-07 09:24:18.326466 [DEBUG] mod_rayo.c:3338 Lock usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:24:18.326466 [DEBUG] mod_rayo.c:2579 usera@172.17.0.3/firefly-4178, recv iq, availability = ONLINE
2014-01-07 09:24:18.326466 [DEBUG] mod_rayo.c:3397 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
2014-01-07 09:24:18.326466 [DEBUG] mod_rayo.c:630 Locate (jid) 172.17.0.3: ref count = 2
2014-01-07 09:24:18.326466 [DEBUG] mod_rayo.c:2582 Deliver usera@172.17.0.3/firefly-4178 => 172.17.0.3 <iq type='get' to='172.17.0.3' id='blather001a' from='usera@172.17.0.3/firefly-4178'><ping xmlns='urn:xmpp:ping'/></iq>
2014-01-07 09:24:18.326466 [DEBUG] mod_rayo.c:511 172.17.0.3, looking for SERVER::get:urn:xmpp:ping:ping command
2014-01-07 09:24:18.326466 [DEBUG] mod_rayo.c:637 Unlock 172.17.0.3: ref count = 1
2014-01-07 09:24:18.326466 [DEBUG] mod_rayo.c:630 Locate (jid) usera@172.17.0.3/firefly-4178: ref count = 2
2014-01-07 09:24:18.326466 [DEBUG] mod_rayo.c:1518 Deliver 172.17.0.3 => usera@172.17.0.3/firefly-4178 <iq type='result' from='172.17.0.3' to='usera@172.17.0.3/firefly-4178' id='blather001a'/>
2014-01-07 09:24:18.326466 [DEBUG] mod_rayo.c:637 Unlock usera@172.17.0.3/firefly-4178: ref count = 1
d57c61a8-77a6-11e3-958b-33f9d38e2b57 2014-01-07 09:24:18.346440 [DEBUG] xmpp_streams.c:190 c2s_in usera@172.17.0.3/firefly-4178 SEND <iq type=result from=172.17.0.3 to=usera@172.17.0.3/firefly-4178 id=blather001a/>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment