Created
August 30, 2013 00:13
-
-
Save neerajnagi/6384920 to your computer and use it in GitHub Desktop.
fs + ahn
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
est-2.compute.internal-2670: ref count = 2 | |
2013-08-29 20:00:46.991334 [DEBUG] mod_rayo.c:930 Deliver d752bc87-7cbb-c2d5-df6d-b364079b95f7@54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 <presence from='d752bc87-7cbb-c2d5-df6d-b364079b95f7@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670' type='unavailable'><end xmlns='urn:xmpp:rayo:1'><hangup-command/></end></presence> | |
2013-08-29 20:00:46.991334 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 1 | |
2013-08-29 20:00:46.991334 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 SEND <presence from='d752bc87-7cbb-c2d5-df6d-b364079b95f7@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670' type='unavailable'><end xmlns='urn:xmpp:rayo:1'><hangup-command/></end></presence> | |
2013-08-29 20:01:22.369197 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 RECV <iq type="get" to="54.213.58.94" id="blather0060"><ping xmlns="urn:xmpp:ping"/></iq> | |
2013-08-29 20:01:22.369197 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:01:22.369197 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 2 | |
2013-08-29 20:01:22.369197 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670, recv iq, availability = ONLINE | |
2013-08-29 20:01:22.369197 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 1 | |
2013-08-29 20:01:22.369197 [DEBUG] mod_rayo.c:624 Locate 54.213.58.94: ref count = 2 | |
2013-08-29 20:01:22.369197 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 => 54.213.58.94 <iq type='get' to='54.213.58.94' id='blather0060' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670'><ping xmlns='urn:xmpp:ping'/></iq> | |
2013-08-29 20:01:22.369197 [DEBUG] mod_rayo.c:505 54.213.58.94, looking for SERVER::get:urn:xmpp:ping:ping command | |
2013-08-29 20:01:22.369197 [DEBUG] mod_rayo.c:631 Unlock 54.213.58.94: ref count = 1 | |
2013-08-29 20:01:22.369197 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 2 | |
2013-08-29 20:01:22.369197 [DEBUG] mod_rayo.c:1432 Deliver 54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670' id='blather0060'/> | |
2013-08-29 20:01:22.369197 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 1 | |
2013-08-29 20:01:22.369197 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 SEND <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670' id='blather0060'/> | |
2013-08-29 20:02:22.372958 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 RECV <iq type="get" to="54.213.58.94" id="blather0062"><ping xmlns="urn:xmpp:ping"/></iq> | |
2013-08-29 20:02:22.372958 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:02:22.372958 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 2 | |
2013-08-29 20:02:22.372958 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670, recv iq, availability = ONLINE | |
2013-08-29 20:02:22.372958 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 1 | |
2013-08-29 20:02:22.372958 [DEBUG] mod_rayo.c:624 Locate 54.213.58.94: ref count = 2 | |
2013-08-29 20:02:22.372958 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 => 54.213.58.94 <iq type='get' to='54.213.58.94' id='blather0062' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670'><ping xmlns='urn:xmpp:ping'/></iq> | |
2013-08-29 20:02:22.372958 [DEBUG] mod_rayo.c:505 54.213.58.94, looking for SERVER::get:urn:xmpp:ping:ping command | |
2013-08-29 20:02:22.372958 [DEBUG] mod_rayo.c:631 Unlock 54.213.58.94: ref count = 1 | |
2013-08-29 20:02:22.372958 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 2 | |
2013-08-29 20:02:22.372958 [DEBUG] mod_rayo.c:1432 Deliver 54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670' id='blather0062'/> | |
2013-08-29 20:02:22.372958 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 1 | |
2013-08-29 20:02:22.372958 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 SEND <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670' id='blather0062'/> | |
2013-08-29 20:03:22.372717 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 RECV <iq type="get" to="54.213.58.94" id="blather0064"><ping xmlns="urn:xmpp:ping"/></iq> | |
2013-08-29 20:03:22.372717 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:03:22.372717 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 2 | |
2013-08-29 20:03:22.372717 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670, recv iq, availability = ONLINE | |
2013-08-29 20:03:22.372717 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 1 | |
2013-08-29 20:03:22.372717 [DEBUG] mod_rayo.c:624 Locate 54.213.58.94: ref count = 2 | |
2013-08-29 20:03:22.372717 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 => 54.213.58.94 <iq type='get' to='54.213.58.94' id='blather0064' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670'><ping xmlns='urn:xmpp:ping'/></iq> | |
2013-08-29 20:03:22.372717 [DEBUG] mod_rayo.c:505 54.213.58.94, looking for SERVER::get:urn:xmpp:ping:ping command | |
2013-08-29 20:03:22.372717 [DEBUG] mod_rayo.c:631 Unlock 54.213.58.94: ref count = 1 | |
2013-08-29 20:03:22.372717 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 2 | |
2013-08-29 20:03:22.372717 [DEBUG] mod_rayo.c:1432 Deliver 54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670' id='blather0064'/> | |
2013-08-29 20:03:22.372717 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 1 | |
2013-08-29 20:03:22.372717 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 SEND <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670' id='blather0064'/> | |
2013-08-29 20:04:22.372475 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 RECV <iq type="get" to="54.213.58.94" id="blather0066"><ping xmlns="urn:xmpp:ping"/></iq> | |
2013-08-29 20:04:22.372475 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:04:22.372475 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 2 | |
2013-08-29 20:04:22.372475 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670, recv iq, availability = ONLINE | |
2013-08-29 20:04:22.372475 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 1 | |
2013-08-29 20:04:22.372475 [DEBUG] mod_rayo.c:624 Locate 54.213.58.94: ref count = 2 | |
2013-08-29 20:04:22.372475 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 => 54.213.58.94 <iq type='get' to='54.213.58.94' id='blather0066' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670'><ping xmlns='urn:xmpp:ping'/></iq> | |
2013-08-29 20:04:22.372475 [DEBUG] mod_rayo.c:505 54.213.58.94, looking for SERVER::get:urn:xmpp:ping:ping command | |
2013-08-29 20:04:22.372475 [DEBUG] mod_rayo.c:631 Unlock 54.213.58.94: ref count = 1 | |
2013-08-29 20:04:22.372475 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 2 | |
2013-08-29 20:04:22.372475 [DEBUG] mod_rayo.c:1432 Deliver 54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670' id='blather0066'/> | |
2013-08-29 20:04:22.372475 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 1 | |
2013-08-29 20:04:22.372475 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 SEND <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670' id='blather0066'/> | |
2013-08-29 20:04:42.437015 [INFO] xmpp_streams.c:1211 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670, iks_recv() error = NET_RWERR, ending session | |
2013-08-29 20:04:42.437015 [DEBUG] mod_rayo.c:3097 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670: ref count = 0 | |
2013-08-29 20:04:42.437015 [DEBUG] mod_rayo.c:3098 Destroy 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 requested: ref_count = 0 | |
2013-08-29 20:04:42.437015 [DEBUG] mod_rayo.c:3098 Destroying 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-2670 | |
2013-08-29 20:04:51.180878 [DEBUG] xmpp_streams.c:1189 New c2s_in stream | |
2013-08-29 20:04:51.180878 [DEBUG] xmpp_streams.c:190 c2s_in (null) RECV <stream:stream to='54.213.58.94' xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en'> | |
2013-08-29 20:04:51.180878 [DEBUG] xmpp_streams.c:1058 (null), state = CONNECT, node type = NODE_START | |
2013-08-29 20:04:51.180878 [DEBUG] xmpp_streams.c:190 c2s_in (null) SEND <stream:stream xmlns='jabber:client' xmlns:db='jabber:server:dialback' from='54.213.58.94' id='c9ff1858-1107-11e3-9950-5d997994877d' xml:lang='en' version='1.0' xmlns:stream='http://etherx.jabber.org/streams'><stream:features><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism></mechanisms></stream:features> | |
2013-08-29 20:04:51.279561 [DEBUG] xmpp_streams.c:190 c2s_in (null) RECV <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="PLAIN">MUA1NC4yMTMuNTguOTQAMQAx</auth> | |
2013-08-29 20:04:51.279561 [DEBUG] xmpp_streams.c:1058 (null), state = SECURE, node type = NODE_NORMAL | |
2013-08-29 20:04:51.279561 [DEBUG] xmpp_streams.c:471 (null), auth, state = SECURE | |
2013-08-29 20:04:51.279561 [DEBUG] xmpp_streams.c:505 (null), auth, state = SECURE, SASL/PLAIN decoded authzid = "1@54.213.58.94" authcid = "1" | |
2013-08-29 20:04:51.304935 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94 SEND <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/> | |
2013-08-29 20:04:51.304935 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94 RECV <stream:stream to='54.213.58.94' xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xml:lang='en'> | |
2013-08-29 20:04:51.304935 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94, state = AUTHENTICATED, node type = NODE_START | |
2013-08-29 20:04:51.304935 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94 SEND <stream:stream xmlns='jabber:client' xmlns:db='jabber:server:dialback' from='54.213.58.94' id='ca1afe10-1107-11e3-9951-5d997994877d' xml:lang='en' version='1.0' xmlns:stream='http://etherx.jabber.org/streams'><stream:features><bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'/><session xmlns='urn:ietf:params:xml:ns:xmpp-session'/></stream:features> | |
2013-08-29 20:04:51.304935 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94 RECV <iq type="set" id="blather0002"><bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"><resource>ip-172-31-41-127.us-west-2.compute.internal-4766</resource></bind></iq> | |
2013-08-29 20:04:51.304935 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94, state = AUTHENTICATED, node type = NODE_NORMAL | |
2013-08-29 20:04:51.304935 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <iq type='result' id='blather0002'><bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'><jid>1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766</jid></bind></iq> | |
2013-08-29 20:04:51.304935 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 RECV <iq type="set" id="blather0004" to="54.213.58.94"><session xmlns="urn:ietf:params:xml:ns:xmpp-session"/></iq> | |
2013-08-29 20:04:51.304935 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, state = RESOURCE_BOUND, node type = NODE_NORMAL | |
2013-08-29 20:04:51.304935 [DEBUG] mod_rayo.c:1198 Init 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 | |
2013-08-29 20:04:51.304935 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <iq from='54.213.58.94' type='result' id='blather0004'/> | |
2013-08-29 20:04:51.304935 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 RECV <iq type="get" id="blather0006"><query xmlns="jabber:iq:roster"/></iq> | |
2013-08-29 20:04:51.304935 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:04:51.304935 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:04:51.304935 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, recv iq, availability = OFFLINE | |
2013-08-29 20:04:51.304935 [DEBUG] mod_rayo.c:624 Locate 54.213.58.94: ref count = 2 | |
2013-08-29 20:04:51.304935 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 => 54.213.58.94 <iq type='get' id='blather0006' to='54.213.58.94' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><query xmlns='jabber:iq:roster'/></iq> | |
2013-08-29 20:04:51.304935 [DEBUG] mod_rayo.c:505 54.213.58.94, looking for SERVER::get:jabber:iq:roster:query command | |
2013-08-29 20:04:51.304935 [DEBUG] mod_rayo.c:1418 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, no handler function for command to 54.213.58.94 | |
2013-08-29 20:04:51.304935 [DEBUG] mod_rayo.c:631 Unlock 54.213.58.94: ref count = 1 | |
2013-08-29 20:04:51.304935 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 3 | |
2013-08-29 20:04:51.304935 [DEBUG] mod_rayo.c:1420 Deliver 54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <iq type='error' id='blather0006' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' from='54.213.58.94'><query xmlns='jabber:iq:roster'/><error type='modify'><feature-not-implemented xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/></error></iq> | |
2013-08-29 20:04:51.304935 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:04:51.304935 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:04:51.304935 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <iq type='error' id='blather0006' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' from='54.213.58.94'><query xmlns='jabber:iq:roster'/><error type='modify'><feature-not-implemented xmlns='urn:ietf:params:xml:ns:xmpp-stanzas'/></error></iq> | |
2013-08-29 20:04:51.315806 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 RECV <presence/> | |
2013-08-29 20:04:51.315806 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:04:51.315806 [DEBUG] xmpp_streams.c:287 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, presence, state = READY | |
2013-08-29 20:04:51.315806 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:04:51.315806 [DEBUG] mod_rayo.c:2310 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 got empty presence | |
2013-08-29 20:04:51.315806 [DEBUG] mod_rayo.c:2331 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 is ONLINE | |
2013-08-29 20:04:51.315806 [DEBUG] mod_rayo.c:3076 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:05:51.310014 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 RECV <iq type="get" to="54.213.58.94" id="blather0008"><ping xmlns="urn:xmpp:ping"/></iq> | |
2013-08-29 20:05:51.310014 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:05:51.310014 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:05:51.310014 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, recv iq, availability = ONLINE | |
2013-08-29 20:05:51.310014 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:05:51.310014 [DEBUG] mod_rayo.c:624 Locate 54.213.58.94: ref count = 2 | |
2013-08-29 20:05:51.310014 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 => 54.213.58.94 <iq type='get' to='54.213.58.94' id='blather0008' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><ping xmlns='urn:xmpp:ping'/></iq> | |
2013-08-29 20:05:51.310014 [DEBUG] mod_rayo.c:505 54.213.58.94, looking for SERVER::get:urn:xmpp:ping:ping command | |
2013-08-29 20:05:51.310014 [DEBUG] mod_rayo.c:631 Unlock 54.213.58.94: ref count = 1 | |
2013-08-29 20:05:51.310014 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:05:51.310014 [DEBUG] mod_rayo.c:1432 Deliver 54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather0008'/> | |
2013-08-29 20:05:51.310014 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:05:51.310014 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather0008'/> | |
2013-08-29 20:06:51.309747 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 RECV <iq type="get" to="54.213.58.94" id="blather000a"><ping xmlns="urn:xmpp:ping"/></iq> | |
2013-08-29 20:06:51.309747 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:06:51.309747 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:06:51.309747 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, recv iq, availability = ONLINE | |
2013-08-29 20:06:51.309747 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:06:51.309747 [DEBUG] mod_rayo.c:624 Locate 54.213.58.94: ref count = 2 | |
2013-08-29 20:06:51.309747 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 => 54.213.58.94 <iq type='get' to='54.213.58.94' id='blather000a' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><ping xmlns='urn:xmpp:ping'/></iq> | |
2013-08-29 20:06:51.309747 [DEBUG] mod_rayo.c:505 54.213.58.94, looking for SERVER::get:urn:xmpp:ping:ping command | |
2013-08-29 20:06:51.309747 [DEBUG] mod_rayo.c:631 Unlock 54.213.58.94: ref count = 1 | |
2013-08-29 20:06:51.309747 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:06:51.309747 [DEBUG] mod_rayo.c:1432 Deliver 54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather000a'/> | |
2013-08-29 20:06:51.309747 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:06:51.309747 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather000a'/> | |
2013-08-29 20:07:27.412024 [NOTICE] switch_channel.c:1030 New Channel sofia/internal/1001@54.213.58.94 [424928b4-bc76-505f-febd-a5febae13aa3] | |
2013-08-29 20:07:27.412024 [DEBUG] switch_core_session.c:1006 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:27.412024 [DEBUG] switch_core_session.c:1006 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:27.412024 [DEBUG] switch_core_state_machine.c:416 (sofia/internal/1001@54.213.58.94) Running State Change CS_NEW | |
2013-08-29 20:07:27.412024 [DEBUG] switch_core_state_machine.c:434 (sofia/internal/1001@54.213.58.94) State NEW | |
2013-08-29 20:07:27.432045 [DEBUG] sofia.c:7906 IP 202.157.93.2 Approved by acl "domains[]". Access Granted. | |
2013-08-29 20:07:27.432045 [DEBUG] sofia.c:8925 Setting NAT mode based on via received | |
2013-08-29 20:07:27.432045 [DEBUG] sofia.c:5793 Channel sofia/internal/1001@54.213.58.94 entering state [received][100] | |
2013-08-29 20:07:27.432045 [DEBUG] sofia.c:5802 Remote SDP: | |
v=0 | |
o=- 417531139091299800 2 IN IP4 127.0.0.1 | |
s=Doubango Telecom - chrome | |
t=0 0 | |
a=group:BUNDLE audio video | |
a=msid-semantic: WMS yhhZ3SJtPGPnmHpiROozjtjw4QZ8d7KftE1z | |
m=audio 62710 RTP/SAVPF 111 103 104 0 8 107 106 105 13 126 | |
c=IN IP4 202.157.93.2 | |
a=rtpmap:111 opus/48000/2 | |
a=fmtp:111 minptime=10 | |
a=rtpmap:103 ISAC/16000 | |
a=rtpmap:104 ISAC/32000 | |
a=rtpmap:0 PCMU/8000 | |
a=rtpmap:8 PCMA/8000 | |
a=rtpmap:107 CN/48000 | |
a=rtpmap:106 CN/32000 | |
a=rtpmap:105 CN/16000 | |
a=rtpmap:13 CN/8000 | |
a=rtpmap:126 telephone-event/8000 | |
a=rtcp:62710 IN IP4 202.157.93.2 | |
a=candidate:524234378 1 udp 2113937151 10.100.101.254 62710 typ host generation 0 | |
a=candidate:524234378 2 udp 2113937151 10.100.101.254 62710 typ host generation 0 | |
a=candidate:1371329146 1 tcp 1509957375 10.100.101.254 0 typ host generation 0 | |
a=candidate:1371329146 2 tcp 1509957375 10.100.101.254 0 typ host generation 0 | |
a=candidate:3551662361 1 udp 1845501695 202.157.93.2 62710 typ srflx raddr 10.100.101.254 rport 62710 generation 0 | |
a=candidate:3551662361 2 udp 1845501695 202.157.93.2 62710 typ srflx raddr 10.100.101.254 rport 62710 generation 0 | |
a=ice-ufrag:Wg2KPXu0KeJsEiW0 | |
a=ice-pwd:AEydpu9aYxE309iFeTeJEMOO | |
a=ice-options:google-ice | |
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level | |
a=mid:audio | |
a=rtcp-mux | |
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:mOzzWppgFTdvWF0fn9jx9rZ9RR21wJ9yX5weywrC | |
a=maxptime:60 | |
a=ssrc:169614681 cname:GO5nEQ90ukOmvC1y | |
a=ssrc:169614681 msid:yhhZ3SJtPGPnmHpiROozjtjw4QZ8d7KftE1z yhhZ3SJtPGPnmHpiROozjtjw4QZ8d7KftE1za0 | |
a=ssrc:169614681 mslabel:yhhZ3SJtPGPnmHpiROozjtjw4QZ8d7KftE1z | |
a=ssrc:169614681 label:yhhZ3SJtPGPnmHpiROozjtjw4QZ8d7KftE1za0 | |
m=video 62710 RTP/SAVPF 100 116 117 | |
c=IN IP4 202.157.93.2 | |
a=rtpmap:100 VP8/90000 | |
a=rtpmap:116 red/90000 | |
a=rtpmap:117 ulpfec/90000 | |
a=rtcp:62710 IN IP4 202.157.93.2 | |
a=candidate:524234378 1 udp 2113937151 10.100.101.254 62710 typ host generation 0 | |
a=candidate:524234378 2 udp 2113937151 10.100.101.254 62710 typ host generation 0 | |
a=candidate:1371329146 1 tcp 1509957375 10.100.101.254 0 typ host generation 0 | |
a=candidate:1371329146 2 tcp 1509957375 10.100.101.254 0 typ host generation 0 | |
a=candidate:3551662361 1 udp 1845501695 202.157.93.2 62710 typ srflx raddr 10.100.101.254 rport 62710 generation 0 | |
a=candidate:3551662361 2 udp 1845501695 202.157.93.2 62710 typ srflx raddr 10.100.101.254 rport 62710 generation 0 | |
a=ice-ufrag:Wg2KPXu0KeJsEiW0 | |
a=ice-pwd:AEydpu9aYxE309iFeTeJEMOO | |
a=ice-options:google-ice | |
a=extmap:2 urn:ietf:params:rtp-hdrext:toffset | |
a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time | |
a=mid:video | |
a=rtcp-mux | |
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:mOzzWppgFTdvWF0fn9jx9rZ9RR21wJ9yX5weywrC | |
a=rtcp-fb:100 ccm fir | |
a=rtcp-fb:100 nack | |
a=rtcp-fb:100 goog-remb | |
2013-08-29 20:07:27.432045 [DEBUG] sofia.c:6015 (sofia/internal/1001@54.213.58.94) State Change CS_NEW -> CS_INIT | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_session.c:1341 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_state_machine.c:416 (sofia/internal/1001@54.213.58.94) Running State Change CS_INIT | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_state_machine.c:455 (sofia/internal/1001@54.213.58.94) State INIT | |
2013-08-29 20:07:27.432045 [DEBUG] mod_sofia.c:87 sofia/internal/1001@54.213.58.94 SOFIA INIT | |
2013-08-29 20:07:27.432045 [DEBUG] mod_sofia.c:114 (sofia/internal/1001@54.213.58.94) State Change CS_INIT -> CS_ROUTING | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_session.c:1341 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_state_machine.c:455 (sofia/internal/1001@54.213.58.94) State INIT going to sleep | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_state_machine.c:416 (sofia/internal/1001@54.213.58.94) Running State Change CS_ROUTING | |
2013-08-29 20:07:27.432045 [DEBUG] switch_channel.c:2116 (sofia/internal/1001@54.213.58.94) Callstate Change DOWN -> RINGING | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/1001@54.213.58.94) State ROUTING | |
2013-08-29 20:07:27.432045 [DEBUG] mod_sofia.c:137 sofia/internal/1001@54.213.58.94 SOFIA ROUTING | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_state_machine.c:117 sofia/internal/1001@54.213.58.94 Standard ROUTING | |
2013-08-29 20:07:27.432045 [INFO] mod_dialplan_xml.c:558 Processing 1001 <1001>->1002 in context public | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->public_did] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (FAIL) [public_did] destination_number(1002) =~ /^(5551212)$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->conferences_10000] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (FAIL) [conferences_10000] destination_number(1002) =~ /^(10000)$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->conferences_123123123123] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (FAIL) [conferences_123123123123] destination_number(1002) =~ /^(123123123123)$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->conferences_2354] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (FAIL) [conferences_2354] destination_number(1002) =~ /^(2354)$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->conferences_2355] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (FAIL) [conferences_2355] destination_number(1002) =~ /^(2355)$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->conferences_2356] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (FAIL) [conferences_2356] destination_number(1002) =~ /^(2356)$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->conferences_2722249814] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (FAIL) [conferences_2722249814] destination_number(1002) =~ /^(2722249814)$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->conferences_800] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (FAIL) [conferences_800] destination_number(1002) =~ /^(800)$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->conferences_800100] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (FAIL) [conferences_800100] destination_number(1002) =~ /^(800100)$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->conferences_Raj2] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (FAIL) [conferences_Raj2] destination_number(1002) =~ /^(Raj2)$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->conferences_RajRoom] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (FAIL) [conferences_RajRoom] destination_number(1002) =~ /^(RajRoom)$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->conferences_monu_ki_conference] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (FAIL) [conferences_monu_ki_conference] destination_number(1002) =~ /^(conference_monu_ki_conference)$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->sunil_conferences] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (FAIL) [sunil_conferences] destination_number(1002) =~ /^2353$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 parsing [public->Adhearsion] continue=false | |
Dialplan: sofia/internal/1001@54.213.58.94 Regex (PASS) [Adhearsion] destination_number(1002) =~ /.*$/ break=on-false | |
Dialplan: sofia/internal/1001@54.213.58.94 Action info() | |
Dialplan: sofia/internal/1001@54.213.58.94 Action set(is_parent_leg=yes) | |
Dialplan: sofia/internal/1001@54.213.58.94 Action set(hangup_after_bridge=false) | |
Dialplan: sofia/internal/1001@54.213.58.94 Action set(park_after_bridge=false) | |
Dialplan: sofia/internal/1001@54.213.58.94 Action set(domain_name=54.213.58.94) | |
Dialplan: sofia/internal/1001@54.213.58.94 Action rayo() | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_state_machine.c:167 (sofia/internal/1001@54.213.58.94) State Change CS_ROUTING -> CS_EXECUTE | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_session.c:1341 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_state_machine.c:471 (sofia/internal/1001@54.213.58.94) State ROUTING going to sleep | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_state_machine.c:416 (sofia/internal/1001@54.213.58.94) Running State Change CS_EXECUTE | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1001@54.213.58.94) State EXECUTE | |
2013-08-29 20:07:27.432045 [DEBUG] mod_sofia.c:230 sofia/internal/1001@54.213.58.94 SOFIA EXECUTE | |
2013-08-29 20:07:27.432045 [DEBUG] switch_core_state_machine.c:209 sofia/internal/1001@54.213.58.94 Standard EXECUTE | |
EXECUTE sofia/internal/1001@54.213.58.94 info() | |
2013-08-29 20:07:27.432045 [INFO] mod_dptools.c:1586 CHANNEL_DATA: | |
Channel-State: [CS_EXECUTE] | |
Channel-Call-State: [RINGING] | |
Channel-State-Number: [4] | |
Channel-Name: [sofia/internal/1001@54.213.58.94] | |
Unique-ID: [424928b4-bc76-505f-febd-a5febae13aa3] | |
Call-Direction: [inbound] | |
Presence-Call-Direction: [inbound] | |
Channel-HIT-Dialplan: [true] | |
Channel-Presence-ID: [1001@54.213.58.94] | |
Channel-Call-UUID: [424928b4-bc76-505f-febd-a5febae13aa3] | |
Answer-State: [ringing] | |
Caller-Direction: [inbound] | |
Caller-Username: [1001] | |
Caller-Dialplan: [XML] | |
Caller-Caller-ID-Name: [1001] | |
Caller-Caller-ID-Number: [1001] | |
Caller-Orig-Caller-ID-Name: [1001] | |
Caller-Orig-Caller-ID-Number: [1001] | |
Caller-Network-Addr: [202.157.93.2] | |
Caller-ANI: [1001] | |
Caller-Destination-Number: [1002] | |
Caller-Unique-ID: [424928b4-bc76-505f-febd-a5febae13aa3] | |
Caller-Source: [mod_sofia] | |
Caller-Context: [public] | |
Caller-Channel-Name: [sofia/internal/1001@54.213.58.94] | |
Caller-Profile-Index: [1] | |
Caller-Profile-Created-Time: [1377821247432045] | |
Caller-Channel-Created-Time: [1377821247432045] | |
Caller-Channel-Answered-Time: [0] | |
Caller-Channel-Progress-Time: [0] | |
Caller-Channel-Progress-Media-Time: [0] | |
Caller-Channel-Hangup-Time: [0] | |
Caller-Channel-Transfer-Time: [0] | |
Caller-Channel-Resurrect-Time: [0] | |
Caller-Channel-Bridged-Time: [0] | |
Caller-Channel-Last-Hold: [0] | |
Caller-Channel-Hold-Accum: [0] | |
Caller-Screen-Bit: [true] | |
Caller-Privacy-Hide-Name: [false] | |
Caller-Privacy-Hide-Number: [false] | |
variable_direction: [inbound] | |
variable_uuid: [424928b4-bc76-505f-febd-a5febae13aa3] | |
variable_session_id: [25] | |
variable_sip_from_user: [1001] | |
variable_sip_from_uri: [1001@54.213.58.94] | |
variable_sip_from_host: [54.213.58.94] | |
variable_channel_name: [sofia/internal/1001@54.213.58.94] | |
variable_sip_call_id: [424928b4-bc76-505f-febd-a5febae13aa3] | |
variable_sip_local_network_addr: [54.213.58.94] | |
variable_sip_network_ip: [202.157.93.2] | |
variable_sip_network_port: [63020] | |
variable_sip_received_ip: [202.157.93.2] | |
variable_sip_received_port: [63020] | |
variable_sip_via_protocol: [ws] | |
variable_sip_authorized: [true] | |
variable_sip_acl_authed_by: [domains] | |
variable_sip_from_user_stripped: [1001] | |
variable_sip_from_tag: [rUEmLhAqn5JETUNxGUPJ] | |
variable_sofia_profile_name: [internal] | |
variable_recovery_profile_name: [internal] | |
variable_sip_full_via: [SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKFdZVBe8T02PrtL6Q3OiuqruyMMHqROwS;rport=63020;received=202.157.93.2] | |
variable_sip_full_from: [<sip:1001@54.213.58.94>;tag=rUEmLhAqn5JETUNxGUPJ] | |
variable_sip_full_to: [<sip:1002@54.213.58.94>] | |
variable_sip_req_user: [1002] | |
variable_sip_req_uri: [1002@54.213.58.94] | |
variable_sip_req_host: [54.213.58.94] | |
variable_sip_to_user: [1002] | |
variable_sip_to_uri: [1002@54.213.58.94] | |
variable_sip_to_host: [54.213.58.94] | |
variable_sip_contact_params: [rtcweb-breaker=no;click2call=no;transport=ws] | |
variable_sip_contact_user: [1001] | |
variable_sip_contact_uri: [1001@df7jal23ls0d.invalid] | |
variable_sip_contact_host: [df7jal23ls0d.invalid] | |
variable_rtp_use_codec_string: [G722,PCMU,PCMA,GSM] | |
variable_sip_user_agent: [IM-client/OMA1.0 sipML5-v1.2013.05.24] | |
variable_sip_via_host: [df7jal23ls0d.invalid] | |
variable_sip_via_rport: [63020] | |
variable_max_forwards: [70] | |
variable_presence_id: [1001@54.213.58.94] | |
variable_sip_nat_detected: [true] | |
variable_switch_r_sdp: [v=0 | |
o=- 417531139091299800 2 IN IP4 127.0.0.1 | |
s=Doubango Telecom - chrome | |
t=0 0 | |
a=group:BUNDLE audio video | |
a=msid-semantic: WMS yhhZ3SJtPGPnmHpiROozjtjw4QZ8d7KftE1z | |
m=audio 62710 RTP/SAVPF 111 103 104 0 8 107 106 105 13 126 | |
c=IN IP4 202.157.93.2 | |
a=rtpmap:111 opus/48000/2 | |
a=fmtp:111 minptime=10 | |
a=rtpmap:103 ISAC/16000 | |
a=rtpmap:104 ISAC/32000 | |
a=rtpmap:0 PCMU/8000 | |
a=rtpmap:8 PCMA/8000 | |
a=rtpmap:107 CN/48000 | |
a=rtpmap:106 CN/32000 | |
a=rtpmap:105 CN/16000 | |
a=rtpmap:13 CN/8000 | |
a=rtpmap:126 telephone-event/8000 | |
a=rtcp:62710 IN IP4 202.157.93.2 | |
a=candidate:524234378 1 udp 2113937151 10.100.101.254 62710 typ host generation 0 | |
a=candidate:524234378 2 udp 2113937151 10.100.101.254 62710 typ host generation 0 | |
a=candidate:1371329146 1 tcp 1509957375 10.100.101.254 0 typ host generation 0 | |
a=candidate:1371329146 2 tcp 1509957375 10.100.101.254 0 typ host generation 0 | |
a=candidate:3551662361 1 udp 1845501695 202.157.93.2 62710 typ srflx raddr 10.100.101.254 rport 62710 generation 0 | |
a=candidate:3551662361 2 udp 1845501695 202.157.93.2 62710 typ srflx raddr 10.100.101.254 rport 62710 generation 0 | |
a=ice-ufrag:Wg2KPXu0KeJsEiW0 | |
a=ice-pwd:AEydpu9aYxE309iFeTeJEMOO | |
a=ice-options:google-ice | |
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level | |
a=mid:audio | |
a=rtcp-mux | |
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:mOzzWppgFTdvWF0fn9jx9rZ9RR21wJ9yX5weywrC | |
a=maxptime:60 | |
a=ssrc:169614681 cname:GO5nEQ90ukOmvC1y | |
a=ssrc:169614681 msid:yhhZ3SJtPGPnmHpiROozjtjw4QZ8d7KftE1z yhhZ3SJtPGPnmHpiROozjtjw4QZ8d7KftE1za0 | |
a=ssrc:169614681 mslabel:yhhZ3SJtPGPnmHpiROozjtjw4QZ8d7KftE1z | |
a=ssrc:169614681 label:yhhZ3SJtPGPnmHpiROozjtjw4QZ8d7KftE1za0 | |
m=video 62710 RTP/SAVPF 100 116 117 | |
c=IN IP4 202.157.93.2 | |
a=rtpmap:100 VP8/90000 | |
a=rtpmap:116 red/90000 | |
a=rtpmap:117 ulpfec/90000 | |
a=rtcp:62710 IN IP4 202.157.93.2 | |
a=candidate:524234378 1 udp 2113937151 10.100.101.254 62710 typ host generation 0 | |
a=candidate:524234378 2 udp 2113937151 10.100.101.254 62710 typ host generation 0 | |
a=candidate:1371329146 1 tcp 1509957375 10.100.101.254 0 typ host generation 0 | |
a=candidate:1371329146 2 tcp 1509957375 10.100.101.254 0 typ host generation 0 | |
a=candidate:3551662361 1 udp 1845501695 202.157.93.2 62710 typ srflx raddr 10.100.101.254 rport 62710 generation 0 | |
a=candidate:3551662361 2 udp 1845501695 202.157.93.2 62710 typ srflx raddr 10.100.101.254 rport 62710 generation 0 | |
a=ice-ufrag:Wg2KPXu0KeJsEiW0 | |
a=ice-pwd:AEydpu9aYxE309iFeTeJEMOO | |
a=ice-options:google-ice | |
a=extmap:2 urn:ietf:params:rtp-hdrext:toffset | |
a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time | |
a=mid:video | |
a=rtcp-mux | |
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:mOzzWppgFTdvWF0fn9jx9rZ9RR21wJ9yX5weywrC | |
a=rtcp-fb:100 ccm fir | |
a=rtcp-fb:100 nack | |
a=rtcp-fb:100 goog-remb | |
] | |
variable_ep_codec_string: [PCMU@8000h@20i@64000b,PCMA@8000h@20i@64000b] | |
variable_endpoint_disposition: [DELAYED NEGOTIATION] | |
variable_call_uuid: [424928b4-bc76-505f-febd-a5febae13aa3] | |
variable_current_application: [info] | |
EXECUTE sofia/internal/1001@54.213.58.94 set(is_parent_leg=yes) | |
2013-08-29 20:07:27.432045 [DEBUG] mod_dptools.c:1374 sofia/internal/1001@54.213.58.94 SET [is_parent_leg]=[yes] | |
EXECUTE sofia/internal/1001@54.213.58.94 set(hangup_after_bridge=false) | |
2013-08-29 20:07:27.432045 [DEBUG] mod_dptools.c:1374 sofia/internal/1001@54.213.58.94 SET [hangup_after_bridge]=[false] | |
EXECUTE sofia/internal/1001@54.213.58.94 set(park_after_bridge=false) | |
2013-08-29 20:07:27.432045 [DEBUG] mod_dptools.c:1374 sofia/internal/1001@54.213.58.94 SET [park_after_bridge]=[false] | |
EXECUTE sofia/internal/1001@54.213.58.94 set(domain_name=54.213.58.94) | |
2013-08-29 20:07:27.432045 [DEBUG] mod_dptools.c:1374 sofia/internal/1001@54.213.58.94 SET [domain_name]=[54.213.58.94] | |
EXECUTE sofia/internal/1001@54.213.58.94 rayo() | |
2013-08-29 20:07:27.432045 [DEBUG] mod_rayo.c:2938 Init 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94 | |
2013-08-29 20:07:27.432045 [DEBUG] mod_rayo.c:2943 Offering call for Rayo 3PCC | |
2013-08-29 20:07:27.432045 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:27.432045 [DEBUG] mod_rayo.c:2961 Deliver 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <presence from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><offer xmlns='urn:xmpp:rayo:1' from='sip:1001@54.213.58.94' to='sip:1002@54.213.58.94'><header name='from' value='<sip:1001@54.213.58.94>;tag=rUEmLhAqn5JETUNxGUPJ'/><header name='to' value='<sip:1002@54.213.58.94>'/><header name='via' value='SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKFdZVBe8T02PrtL6Q3OiuqruyMMHqROwS;rport=63020;received=202.157.93.2'/></offer></presence> | |
2013-08-29 20:07:27.432045 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:27.452119 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <presence from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><offer xmlns='urn:xmpp:rayo:1' from='sip:1001@54.213.58.94' to='sip:1002@54.213.58.94'><header name='from' value='<sip:1001@54.213.58.94>;tag=rUEmLhAqn5JETUNxGUPJ'/><header name='to' value='<sip:1002@54.213.58.94>'/><header name='via' value='SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKFdZVBe8T02PrtL6Q3OiuqruyMMHqROwS;rport=63020;received=202.157.93.2'/></offer></presence> | |
2013-08-29 20:07:27.590981 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 RECV <iq type="set" to="424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94" id="blather000c"><accept xmlns="urn:xmpp:rayo:1"/></iq> | |
2013-08-29 20:07:27.590981 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, recv iq, availability = ONLINE | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:624 Locate 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: ref count = 2 | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 => 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94 <iq type='set' to='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' id='blather000c' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><accept xmlns='urn:xmpp:rayo:1'/></iq> | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:505 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94, looking for CALL::set:urn:xmpp:rayo:1:accept command | |
2013-08-29 20:07:27.590981 [INFO] mod_rayo.c:1314 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 has control of call | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:1471 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94, executing command | |
2013-08-29 20:07:27.590981 [INFO] mod_rayo.c:1609 Sending early media | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:881 Set Remote Key [1 AES_CM_128_HMAC_SHA1_80 inline:mOzzWppgFTdvWF0fn9jx9rZ9RR21wJ9yX5weywrC] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:682 Set Local Key [1 AES_CM_128_HMAC_SHA1_80 inline:o04A9WuX0qSgkP+ctMOcqfIgqMLOPQzsUnEF2nNe] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [opus:111:48000:60:0]/[G722:9:8000:20:64000] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [opus:111:48000:60:0]/[PCMU:0:8000:20:64000] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [opus:111:48000:60:0]/[PCMA:8:8000:20:64000] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [opus:111:48000:60:0]/[GSM:3:8000:20:13200] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [ISAC:103:16000:30:32000]/[G722:9:8000:20:64000] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [ISAC:103:16000:30:32000]/[PCMU:0:8000:20:64000] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [ISAC:103:16000:30:32000]/[PCMA:8:8000:20:64000] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [ISAC:103:16000:30:32000]/[GSM:3:8000:20:13200] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [ISAC:104:32000:30:32000]/[G722:9:8000:20:64000] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [ISAC:104:32000:30:32000]/[PCMU:0:8000:20:64000] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [ISAC:104:32000:30:32000]/[PCMA:8:8000:20:64000] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [ISAC:104:32000:30:32000]/[GSM:3:8000:20:13200] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [PCMU:0:8000:60:64000]/[G722:9:8000:20:64000] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2787 Audio Codec Compare [PCMU:0:8000:60:64000]/[PCMU:0:8000:20:64000] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:1823 Set Codec sofia/internal/1001@54.213.58.94 PCMU/8000 20 ms 160 samples 64000 bits | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_codec.c:111 sofia/internal/1001@54.213.58.94 Original read codec set to PCMU:0 | |
2013-08-29 20:07:27.590981 [WARNING] switch_core_media.c:2002 NO candidate ACL defined, Defaulting to wan.auto | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2026 Checking Candidate cid: 1 proto: udp type: host addr: 10.100.101.254:62710 | |
2013-08-29 20:07:27.590981 [NOTICE] switch_core_media.c:2040 Save audio Candidate cid: 1 proto: udp type: host addr: 10.100.101.254:62710 | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2026 Checking Candidate cid: 2 proto: udp type: host addr: 10.100.101.254:62710 | |
2013-08-29 20:07:27.590981 [NOTICE] switch_core_media.c:2040 Save audio Candidate cid: 2 proto: udp type: host addr: 10.100.101.254:62710 | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2026 Checking Candidate cid: 1 proto: udp type: srflx addr: 202.157.93.2:62710 | |
2013-08-29 20:07:27.590981 [NOTICE] switch_core_media.c:2035 Choose audio Candidate cid: 1 proto: udp type: srflx addr: 202.157.93.2:62710 | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2026 Checking Candidate cid: 2 proto: udp type: srflx addr: 202.157.93.2:62710 | |
2013-08-29 20:07:27.590981 [NOTICE] switch_core_media.c:2035 Choose audio Candidate cid: 2 proto: udp type: srflx addr: 202.157.93.2:62710 | |
2013-08-29 20:07:27.590981 [NOTICE] switch_core_media.c:2149 setting remote audio ice addr to 202.157.93.2:62710 based on candidate | |
2013-08-29 20:07:27.590981 [NOTICE] switch_core_media.c:2167 setting remote rtcp audio addr to 202.157.93.2:62710 based on candidate | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:2958 Set 2833 dtmf send/recv payload to 126 | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:881 Set Remote Key [1 AES_CM_128_HMAC_SHA1_80 inline:mOzzWppgFTdvWF0fn9jx9rZ9RR21wJ9yX5weywrC] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:682 Set Local Key [1 AES_CM_128_HMAC_SHA1_80 inline:8keJpJsPDno27YyBMP6Er5cQJquljOrYm2PbT4pG] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:3986 AUDIO RTP [sofia/internal/1001@54.213.58.94] 172.31.41.127 port 31924 -> 202.157.93.2 port 62710 codec: 0 ms: 20 | |
2013-08-29 20:07:27.590981 [DEBUG] switch_rtp.c:2885 Starting timer [soft] 160 bytes per 20ms | |
2013-08-29 20:07:27.590981 [INFO] switch_core_media.c:4149 Activating Audio ICE | |
2013-08-29 20:07:27.590981 [NOTICE] switch_rtp.c:3317 Activating RTP audio ICE: Wg2KPXu0KeJsEiW0:OiAKpFdDYT1WvVLA 202.157.93.2:62710 | |
2013-08-29 20:07:27.590981 [INFO] switch_core_media.c:4192 Activating RTCP PORT 62710 | |
2013-08-29 20:07:27.590981 [DEBUG] switch_rtp.c:3222 RTCP send rate is: 10000 and packet rate is: 20000 Remote Port: 62710 | |
2013-08-29 20:07:27.590981 [DEBUG] switch_rtp.c:1858 Setting RTCP remote addr to 202.157.93.2:62710 | |
2013-08-29 20:07:27.590981 [INFO] switch_core_media.c:4200 Skipping RTCP ICE (Same as RTP) | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:4320 Set 2833 dtmf send payload to 126 | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:4326 Set 2833 dtmf receive payload to 126 | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_media.c:4359 Set comfort noise payload to 107 | |
2013-08-29 20:07:27.590981 [INFO] switch_rtp.c:2705 Activating Audio Secure RTP SEND | |
2013-08-29 20:07:27.590981 [INFO] switch_rtp.c:2683 Activating Audio Secure RTP RECV | |
2013-08-29 20:07:27.590981 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1001@54.213.58.94! | |
2013-08-29 20:07:27.590981 [DEBUG] switch_channel.c:3316 (sofia/internal/1001@54.213.58.94) Callstate Change RINGING -> EARLY | |
2013-08-29 20:07:27.590981 [DEBUG] mod_sofia.c:2105 Ring SDP: | |
v=0 | |
o=FreeSWITCH 1377789323 1377789324 IN IP4 54.213.58.94 | |
s=FreeSWITCH | |
c=IN IP4 54.213.58.94 | |
t=0 0 | |
a=msid-semantic: WMS 1EIDro0V8i90FUfnMdi46heCotQx7L4Z | |
m=audio 31924 RTP/SAVPF 0 126 107 | |
a=rtpmap:0 PCMU/8000 | |
a=rtpmap:126 telephone-event/8000 | |
a=rtpmap:107 CN/8000 | |
a=ptime:20 | |
a=sendrecv | |
a=rtcp-mux | |
a=rtcp:31924 IN IP4 54.213.58.94 | |
a=ssrc:1618248726 cname:fDswRjiPriFW2LaF | |
a=ssrc:1618248726 msid:1EIDro0V8i90FUfnMdi46heCotQx7L4Z a0 | |
a=ssrc:1618248726 mslabel:1EIDro0V8i90FUfnMdi46heCotQx7L4Z | |
a=ssrc:1618248726 label:1EIDro0V8i90FUfnMdi46heCotQx7L4Za0 | |
a=ice-ufrag:OiAKpFdDYT1WvVLA | |
a=ice-pwd:o4X6d6Luehh7ShCx | |
a=candidate:9165585375 1 udp 659136 54.213.58.94 31924 typ host generation 0 | |
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:o04A9WuX0qSgkP+ctMOcqfIgqMLOPQzsUnEF2nNe | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_session.c:861 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:1473 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94, done executing command | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:631 Unlock 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: ref count = 1 | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:1480 Deliver 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <iq from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' type='result' id='blather000c'/> | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_sqldb.c:2352 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80 | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_session.c:1006 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_core_sqldb.c:2352 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80 | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:2776 got event CHANNEL_PROGRESS_MEDIA | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:2781 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 rayo event CHANNEL_PROGRESS_MEDIA | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:2783 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:27.590981 [DEBUG] mod_rayo.c:2791 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:27.590981 [DEBUG] sofia.c:5793 Channel sofia/internal/1001@54.213.58.94 entering state [early][183] | |
2013-08-29 20:07:27.590981 [DEBUG] switch_ivr.c:951 Codec Activated L16@8000hz 1 channels 20ms | |
2013-08-29 20:07:27.590981 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <iq from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' type='result' id='blather000c'/> | |
2013-08-29 20:07:28.056773 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 RECV <iq type="set" to="424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94" id="blather000e"><answer xmlns="urn:xmpp:rayo:1"/></iq> | |
2013-08-29 20:07:28.056773 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, recv iq, availability = ONLINE | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:624 Locate 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: ref count = 2 | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 => 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94 <iq type='set' to='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' id='blather000e' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><answer xmlns='urn:xmpp:rayo:1'/></iq> | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:505 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94, looking for CALL::set:urn:xmpp:rayo:1:answer command | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:1471 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94, executing command | |
2013-08-29 20:07:28.056773 [DEBUG] mod_sofia.c:822 Local SDP sofia/internal/1001@54.213.58.94: | |
v=0 | |
o=FreeSWITCH 1377789323 1377789325 IN IP4 54.213.58.94 | |
s=FreeSWITCH | |
c=IN IP4 54.213.58.94 | |
t=0 0 | |
a=msid-semantic: WMS 1EIDro0V8i90FUfnMdi46heCotQx7L4Z | |
m=audio 31924 RTP/SAVPF 0 126 107 | |
a=rtpmap:0 PCMU/8000 | |
a=rtpmap:126 telephone-event/8000 | |
a=rtpmap:107 CN/8000 | |
a=ptime:20 | |
a=sendrecv | |
a=rtcp-mux | |
a=rtcp:31924 IN IP4 54.213.58.94 | |
a=ssrc:1618248726 cname:fDswRjiPriFW2LaF | |
a=ssrc:1618248726 msid:1EIDro0V8i90FUfnMdi46heCotQx7L4Z a0 | |
a=ssrc:1618248726 mslabel:1EIDro0V8i90FUfnMdi46heCotQx7L4Z | |
a=ssrc:1618248726 label:1EIDro0V8i90FUfnMdi46heCotQx7L4Za0 | |
a=ice-ufrag:OiAKpFdDYT1WvVLA | |
a=ice-pwd:o4X6d6Luehh7ShCx | |
a=candidate:8637987208 1 udp 659136 54.213.58.94 31924 typ host generation 0 | |
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:o04A9WuX0qSgkP+ctMOcqfIgqMLOPQzsUnEF2nNe | |
2013-08-29 20:07:28.056773 [DEBUG] switch_core_session.c:861 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:28.056773 [NOTICE] mod_rayo.c:1628 Channel [sofia/internal/1001@54.213.58.94] has been answered | |
2013-08-29 20:07:28.056773 [DEBUG] switch_channel.c:3595 (sofia/internal/1001@54.213.58.94) Callstate Change EARLY -> ACTIVE | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:1473 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94, done executing command | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:631 Unlock 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: ref count = 1 | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:1480 Deliver 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <iq from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' type='result' id='blather000e'/> | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:2776 got event CHANNEL_ANSWER | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:2781 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 rayo event CHANNEL_ANSWER | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:2783 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:2616 Locate 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: ref count = 2 | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:2622 Unlock 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: ref count = 1 | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:2791 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:2621 Deliver 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <presence from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><answered xmlns='urn:xmpp:rayo:1'/></presence> | |
2013-08-29 20:07:28.056773 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:28.056773 [DEBUG] switch_core_session.c:1006 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:28.056773 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <iq from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' type='result' id='blather000e'/> | |
2013-08-29 20:07:28.056773 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <presence from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><answered xmlns='urn:xmpp:rayo:1'/></presence> | |
2013-08-29 20:07:28.191113 [DEBUG] sofia.c:5793 Channel sofia/internal/1001@54.213.58.94 entering state [completed][200] | |
2013-08-29 20:07:28.220537 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 RECV <iq type="set" to="424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94" id="blather0010"><output xmlns="urn:xmpp:rayo:output:1" start-paused="false"><document content-type="application/ssml+xml"><![CDATA[<speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"> | |
<audio src="/var/punchblock/record/welcome.mp3"/> | |
</speak>]]></document></output></iq> | |
2013-08-29 20:07:28.220537 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, recv iq, availability = ONLINE | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:624 Locate 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: ref count = 2 | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 => 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94 <iq type='set' to='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' id='blather0010' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><output xmlns='urn:xmpp:rayo:output:1' start-paused='false'><document content-type='application/ssml+xml'><speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"> | |
<audio src="/var/punchblock/record/welcome.mp3"/> | |
</speak></document></output></iq> | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:505 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94, looking for CALL::set:urn:xmpp:rayo:output:1:output command | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:1471 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94, executing command | |
2013-08-29 20:07:28.220537 [DEBUG] rayo_output_component.c:67 Init 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1 | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:1151 Lock 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: ref count = 3 | |
2013-08-29 20:07:28.220537 [DEBUG] switch_event.c:1615 Parsing variable [id]=[424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1] | |
2013-08-29 20:07:28.220537 [DEBUG] switch_event.c:1615 Parsing variable [session]=[424928b4-bc76-505f-febd-a5febae13aa3] | |
2013-08-29 20:07:28.220537 [DEBUG] switch_event.c:1615 Parsing variable [pause]=[false] | |
2013-08-29 20:07:28.220537 [DEBUG] rayo_output_component.c:624 Got path rayo://424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1 | |
2013-08-29 20:07:28.220537 [DEBUG] rayo_output_component.c:458 Got path 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1 | |
2013-08-29 20:07:28.220537 [DEBUG] rayo_output_component.c:460 Locate 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1: ref count = 2 | |
2013-08-29 20:07:28.220537 [DEBUG] mod_ssml.c:793 Open: <speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"> | |
<audio src="/var/punchblock/record/welcome.mp3"/> | |
</speak> | |
2013-08-29 20:07:28.220537 [DEBUG] mod_ssml.c:813 Parse error: <speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"> | |
<audio src="/var/punchblock/record/welcome.mp3"/> | |
</speak>, num_files = 0 | |
2013-08-29 20:07:28.220537 [INFO] rayo_output_component.c:425 Failed to open ssml://<speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"> | |
<audio src="/var/punchblock/record/welcome.mp3"/> | |
</speak> | |
2013-08-29 20:07:28.220537 [INFO] rayo_output_component.c:386 Done playing | |
2013-08-29 20:07:28.220537 [INFO] rayo_output_component.c:474 Status = 1 | |
2013-08-29 20:07:28.220537 [DEBUG] rayo_output_component.c:475 Unlock 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1: ref count = 1 | |
2013-08-29 20:07:28.220537 [DEBUG] rayo_components.c:116 Unlock 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1: ref count = 0 | |
2013-08-29 20:07:28.220537 [DEBUG] rayo_components.c:117 Destroy 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1 requested: ref_count = 0 | |
2013-08-29 20:07:28.220537 [DEBUG] rayo_components.c:117 Destroying 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1 | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:1129 Unlock 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: ref count = 2 | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:1473 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94, done executing command | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:631 Unlock 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: ref count = 1 | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:28.220537 [DEBUG] rayo_components.c:62 Deliver 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <iq from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' type='result' id='blather0010'><ref xmlns='urn:xmpp:rayo:1' uri='xmpp:424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1'/></iq> | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:28.220537 [DEBUG] rayo_components.c:115 Deliver 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <presence from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' type='unavailable'><complete xmlns='urn:xmpp:rayo:ext:1'><error xmlns='urn:xmpp:rayo:ext:complete:1'/></complete></presence> | |
2013-08-29 20:07:28.220537 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:28.220537 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <iq from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' type='result' id='blather0010'><ref xmlns='urn:xmpp:rayo:1' uri='xmpp:424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1'/></iq> | |
2013-08-29 20:07:28.220537 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <presence from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' type='unavailable'><complete xmlns='urn:xmpp:rayo:ext:1'><error xmlns='urn:xmpp:rayo:ext:complete:1'/></complete></presence> | |
2013-08-29 20:07:28.472357 [DEBUG] switch_core_session.c:1006 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:28.472357 [DEBUG] switch_core_session.c:1006 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:28.472357 [DEBUG] switch_core_session.c:1006 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:28.492199 [DEBUG] sofia.c:5793 Channel sofia/internal/1001@54.213.58.94 entering state [ready][200] | |
2013-08-29 20:07:51.330449 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 RECV <iq type="get" to="54.213.58.94" id="blather0012"><ping xmlns="urn:xmpp:ping"/></iq> | |
2013-08-29 20:07:51.330449 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:07:51.330449 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:51.330449 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, recv iq, availability = ONLINE | |
2013-08-29 20:07:51.330449 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:51.330449 [DEBUG] mod_rayo.c:624 Locate 54.213.58.94: ref count = 2 | |
2013-08-29 20:07:51.330449 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 => 54.213.58.94 <iq type='get' to='54.213.58.94' id='blather0012' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><ping xmlns='urn:xmpp:ping'/></iq> | |
2013-08-29 20:07:51.330449 [DEBUG] mod_rayo.c:505 54.213.58.94, looking for SERVER::get:urn:xmpp:ping:ping command | |
2013-08-29 20:07:51.330449 [DEBUG] mod_rayo.c:631 Unlock 54.213.58.94: ref count = 1 | |
2013-08-29 20:07:51.330449 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:51.330449 [DEBUG] mod_rayo.c:1432 Deliver 54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather0012'/> | |
2013-08-29 20:07:51.330449 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:51.330449 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather0012'/> | |
2013-08-29 20:07:58.229957 [WARNING] mod_rayo.c:2885 Ending abandoned call. idle_duration_ms = 30009 ms | |
2013-08-29 20:07:58.229957 [NOTICE] mod_rayo.c:2886 Hangup sofia/internal/1001@54.213.58.94 [CS_EXECUTE] [NORMAL_CLEARING] | |
2013-08-29 20:07:58.229957 [DEBUG] switch_channel.c:3135 Send signal sofia/internal/1001@54.213.58.94 [KILL] | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_session.c:1341 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_session.c:2743 sofia/internal/1001@54.213.58.94 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1001@54.213.58.94) State EXECUTE going to sleep | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:416 (sofia/internal/1001@54.213.58.94) Running State Change CS_HANGUP | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:679 (sofia/internal/1001@54.213.58.94) State HANGUP | |
2013-08-29 20:07:58.229957 [DEBUG] mod_sofia.c:463 Channel sofia/internal/1001@54.213.58.94 hanging up, cause: NORMAL_CLEARING | |
2013-08-29 20:07:58.229957 [DEBUG] mod_sofia.c:515 Sending BYE to sofia/internal/1001@54.213.58.94 | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1001@54.213.58.94 Standard HANGUP, cause: NORMAL_CLEARING | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:679 (sofia/internal/1001@54.213.58.94) State HANGUP going to sleep | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:692 (sofia/internal/1001@54.213.58.94) Callstate Change ACTIVE -> HANGUP | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:447 (sofia/internal/1001@54.213.58.94) State Change CS_HANGUP -> CS_REPORTING | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_session.c:1341 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:416 (sofia/internal/1001@54.213.58.94) Running State Change CS_REPORTING | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:764 (sofia/internal/1001@54.213.58.94) State REPORTING | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:92 sofia/internal/1001@54.213.58.94 Standard REPORTING, cause: NORMAL_CLEARING | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:764 (sofia/internal/1001@54.213.58.94) State REPORTING going to sleep | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:441 (sofia/internal/1001@54.213.58.94) State Change CS_REPORTING -> CS_DESTROY | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_session.c:1341 Send signal sofia/internal/1001@54.213.58.94 [BREAK] | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_session.c:1549 Session 25 (sofia/internal/1001@54.213.58.94) Locked, Waiting on external entities | |
2013-08-29 20:07:58.229957 [NOTICE] switch_core_session.c:1567 Session 25 (sofia/internal/1001@54.213.58.94) Ended | |
2013-08-29 20:07:58.229957 [NOTICE] switch_core_session.c:1571 Close Channel sofia/internal/1001@54.213.58.94 [CS_DESTROY] | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:566 (sofia/internal/1001@54.213.58.94) Callstate Change HANGUP -> DOWN | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/1001@54.213.58.94) Running State Change CS_DESTROY | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/1001@54.213.58.94) State DESTROY | |
2013-08-29 20:07:58.229957 [DEBUG] mod_sofia.c:373 sofia/internal/1001@54.213.58.94 SOFIA DESTROY | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:99 sofia/internal/1001@54.213.58.94 Standard DESTROY | |
2013-08-29 20:07:58.229957 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/1001@54.213.58.94) State DESTROY going to sleep | |
2013-08-29 20:07:58.229957 [DEBUG] mod_rayo.c:2592 Locate 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: ref count = 2 | |
2013-08-29 20:07:58.229957 [DEBUG] mod_rayo.c:2603 Unlock 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: ref count = 1 | |
2013-08-29 20:07:58.229957 [DEBUG] mod_rayo.c:2604 Destroy 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94 requested: ref_count = 1 | |
2013-08-29 20:07:58.229957 [DEBUG] mod_rayo.c:2605 Unlock 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: ref count = 0 | |
2013-08-29 20:07:58.229957 [DEBUG] mod_rayo.c:2605 Destroying 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94 | |
2013-08-29 20:07:58.229957 [DEBUG] mod_rayo.c:929 Sending <end> to offered client 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 | |
2013-08-29 20:07:58.229957 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:07:58.229957 [DEBUG] mod_rayo.c:930 Deliver 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <presence from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' type='unavailable'><end xmlns='urn:xmpp:rayo:1'><hungup/></end></presence> | |
2013-08-29 20:07:58.229957 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:07:58.229957 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <presence from='424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' type='unavailable'><end xmlns='urn:xmpp:rayo:1'><hungup/></end></presence> | |
2013-08-29 20:08:51.329255 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 RECV <iq type="get" to="54.213.58.94" id="blather0014"><ping xmlns="urn:xmpp:ping"/></iq> | |
2013-08-29 20:08:51.329255 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:08:51.329255 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:08:51.329255 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, recv iq, availability = ONLINE | |
2013-08-29 20:08:51.329255 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:08:51.329255 [DEBUG] mod_rayo.c:624 Locate 54.213.58.94: ref count = 2 | |
2013-08-29 20:08:51.329255 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 => 54.213.58.94 <iq type='get' to='54.213.58.94' id='blather0014' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><ping xmlns='urn:xmpp:ping'/></iq> | |
2013-08-29 20:08:51.329255 [DEBUG] mod_rayo.c:505 54.213.58.94, looking for SERVER::get:urn:xmpp:ping:ping command | |
2013-08-29 20:08:51.329255 [DEBUG] mod_rayo.c:631 Unlock 54.213.58.94: ref count = 1 | |
2013-08-29 20:08:51.329255 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:08:51.329255 [DEBUG] mod_rayo.c:1432 Deliver 54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather0014'/> | |
2013-08-29 20:08:51.329255 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:08:51.329255 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather0014'/> | |
2013-08-29 20:09:51.333018 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 RECV <iq type="get" to="54.213.58.94" id="blather0016"><ping xmlns="urn:xmpp:ping"/></iq> | |
2013-08-29 20:09:51.333018 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:09:51.333018 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:09:51.333018 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, recv iq, availability = ONLINE | |
2013-08-29 20:09:51.333018 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:09:51.333018 [DEBUG] mod_rayo.c:624 Locate 54.213.58.94: ref count = 2 | |
2013-08-29 20:09:51.333018 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 => 54.213.58.94 <iq type='get' to='54.213.58.94' id='blather0016' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><ping xmlns='urn:xmpp:ping'/></iq> | |
2013-08-29 20:09:51.333018 [DEBUG] mod_rayo.c:505 54.213.58.94, looking for SERVER::get:urn:xmpp:ping:ping command | |
2013-08-29 20:09:51.333018 [DEBUG] mod_rayo.c:631 Unlock 54.213.58.94: ref count = 1 | |
2013-08-29 20:09:51.333018 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:09:51.333018 [DEBUG] mod_rayo.c:1432 Deliver 54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather0016'/> | |
2013-08-29 20:09:51.333018 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:09:51.333018 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather0016'/> | |
2013-08-29 20:10:51.332757 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 RECV <iq type="get" to="54.213.58.94" id="blather0018"><ping xmlns="urn:xmpp:ping"/></iq> | |
2013-08-29 20:10:51.332757 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:10:51.332757 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:10:51.332757 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, recv iq, availability = ONLINE | |
2013-08-29 20:10:51.332757 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:10:51.332757 [DEBUG] mod_rayo.c:624 Locate 54.213.58.94: ref count = 2 | |
2013-08-29 20:10:51.332757 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 => 54.213.58.94 <iq type='get' to='54.213.58.94' id='blather0018' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><ping xmlns='urn:xmpp:ping'/></iq> | |
2013-08-29 20:10:51.332757 [DEBUG] mod_rayo.c:505 54.213.58.94, looking for SERVER::get:urn:xmpp:ping:ping command | |
2013-08-29 20:10:51.332757 [DEBUG] mod_rayo.c:631 Unlock 54.213.58.94: ref count = 1 | |
2013-08-29 20:10:51.332757 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:10:51.332757 [DEBUG] mod_rayo.c:1432 Deliver 54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather0018'/> | |
2013-08-29 20:10:51.332757 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:10:51.332757 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather0018'/> | |
2013-08-29 20:11:51.332522 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 RECV <iq type="get" to="54.213.58.94" id="blather001a"><ping xmlns="urn:xmpp:ping"/></iq> | |
2013-08-29 20:11:51.332522 [DEBUG] xmpp_streams.c:1058 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, state = READY, node type = NODE_NORMAL | |
2013-08-29 20:11:51.332522 [DEBUG] mod_rayo.c:3010 Lock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:11:51.332522 [DEBUG] mod_rayo.c:2365 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766, recv iq, availability = ONLINE | |
2013-08-29 20:11:51.332522 [DEBUG] mod_rayo.c:3069 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:11:51.332522 [DEBUG] mod_rayo.c:624 Locate 54.213.58.94: ref count = 2 | |
2013-08-29 20:11:51.332522 [DEBUG] mod_rayo.c:2368 Deliver 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 => 54.213.58.94 <iq type='get' to='54.213.58.94' id='blather001a' from='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766'><ping xmlns='urn:xmpp:ping'/></iq> | |
2013-08-29 20:11:51.332522 [DEBUG] mod_rayo.c:505 54.213.58.94, looking for SERVER::get:urn:xmpp:ping:ping command | |
2013-08-29 20:11:51.332522 [DEBUG] mod_rayo.c:631 Unlock 54.213.58.94: ref count = 1 | |
2013-08-29 20:11:51.332522 [DEBUG] mod_rayo.c:624 Locate 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 2 | |
2013-08-29 20:11:51.332522 [DEBUG] mod_rayo.c:1432 Deliver 54.213.58.94 => 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather001a'/> | |
2013-08-29 20:11:51.332522 [DEBUG] mod_rayo.c:631 Unlock 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766: ref count = 1 | |
2013-08-29 20:11:51.332522 [DEBUG] xmpp_streams.c:190 c2s_in 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 SEND <iq type='result' from='54.213.58.94' to='1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766' id='blather001a'/> | |
freeswitch@internal> | |
resource> | |
</bind> | |
</iq> | |
[2013-08-29 20:04:50] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq type="result" id="blather0002"> | |
<bind xmlns="urn:ietf:params:xml:ns:xmpp-bind"> | |
<jid>1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766</jid> | |
</bind> | |
</iq> | |
[2013-08-29 20:04:50] TRACE Punchblock::Connection::XMPP: USING JID: 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 | |
[2013-08-29 20:04:50] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/stream/features/session.rb:40:in `session') <iq type="set" id="blather0004" to="54.213.58.94"> | |
<session xmlns="urn:ietf:params:xml:ns:xmpp-session"/> | |
</iq> | |
[2013-08-29 20:04:50] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq from="54.213.58.94" type="result" id="blather0004"/> | |
[2013-08-29 20:04:50] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:149:in `write') <iq type="get" id="blather0006"> | |
<query xmlns="jabber:iq:roster"/> | |
</iq> | |
[2013-08-29 20:04:50] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq type="error" id="blather0006" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" from="54.213.58.94"> | |
<query xmlns="jabber:iq:roster"/> | |
<error type="modify"> | |
<feature-not-implemented xmlns="urn:ietf:params:xml:ns:xmpp-stanzas"/> | |
</error> | |
</iq> | |
[2013-08-29 20:04:50] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:149:in `write') <presence/> | |
[2013-08-29 20:04:50] INFO Punchblock::Connection::XMPP: Connected to XMPP as 1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766 | |
[2013-08-29 20:04:50] INFO Adhearsion::PunchblockPlugin::Initializer: Connected to Punchblock server | |
[2013-08-29 20:04:50] INFO Adhearsion::Process: Transitioning from booting to running with 0 active calls due to booted event. | |
[2013-08-29 20:05:50] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:149:in `write') <iq type="get" to="54.213.58.94" id="blather0008"> | |
<ping xmlns="urn:xmpp:ping"/> | |
</iq> | |
[2013-08-29 20:05:50] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq type="result" from="54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" id="blather0008"/> | |
[2013-08-29 20:06:50] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:149:in `write') <iq type="get" to="54.213.58.94" id="blather000a"> | |
<ping xmlns="urn:xmpp:ping"/> | |
</iq> | |
[2013-08-29 20:06:50] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq type="result" from="54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" id="blather000a"/> | |
[2013-08-29 20:07:26] TRACE Punchblock::Connection::XMPP: RECEIVING (presence) <presence from="424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766"> | |
<offer xmlns="urn:xmpp:rayo:1" from="sip:1001@54.213.58.94" to="sip:1002@54.213.58.94"> | |
<header name="from" value="<sip:1001@54.213.58.94>;tag=rUEmLhAqn5JETUNxGUPJ"/> | |
<header name="to" value="<sip:1002@54.213.58.94>"/> | |
<header name="via" value="SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKFdZVBe8T02PrtL6Q3OiuqruyMMHqROwS;rport=63020;received=202.157.93.2"/> | |
</offer> | |
</presence> | |
[2013-08-29 20:07:26] DEBUG Adhearsion::Call: @: Receiving message: #<Punchblock::Event::Offer target_call_id="424928b4-bc76-505f-febd-a5febae13aa3", target_mixer_name=nil, component_id=nil, domain="54.213.58.94", transport="xmpp", headers={"from"=>"<sip:1001@54.213.58.94>;tag=rUEmLhAqn5JETUNxGUPJ", "to"=>"<sip:1002@54.213.58.94>", "via"=>"SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKFdZVBe8T02PrtL6Q3OiuqruyMMHqROwS;rport=63020;received=202.157.93.2"}, to="sip:1002@54.213.58.94", from="sip:1001@54.213.58.94"> | |
[2013-08-29 20:07:26] INFO Adhearsion::Router: Call 424928b4-bc76-505f-febd-a5febae13aa3 selected route "default" (Incomming) | |
[2013-08-29 20:07:26] DEBUG Adhearsion::Call: 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: Executing command #<Punchblock::Command::Accept target_call_id=nil, target_mixer_name=nil, component_id=nil, domain=nil, transport=nil, headers={}> | |
[2013-08-29 20:07:26] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:149:in `write') <iq type="set" to="424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94" id="blather000c"> | |
<accept xmlns="urn:xmpp:rayo:1"/> | |
</iq> | |
[2013-08-29 20:07:26] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq from="424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" type="result" id="blather000c"/> | |
[2013-08-29 20:07:26] INFO Adhearsion::Call: 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: Executing controller #<Incomming call=424928b4-bc76-505f-febd-a5febae13aa3, metadata={}> | |
[2013-08-29 20:07:26] DEBUG Adhearsion::Call: 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: Receiving message: #<Punchblock::Event::Offer target_call_id="424928b4-bc76-505f-febd-a5febae13aa3", target_mixer_name=nil, component_id=nil, domain="54.213.58.94", transport="xmpp", headers={"from"=>"<sip:1001@54.213.58.94>;tag=rUEmLhAqn5JETUNxGUPJ", "to"=>"<sip:1002@54.213.58.94>", "via"=>"SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKFdZVBe8T02PrtL6Q3OiuqruyMMHqROwS;rport=63020;received=202.157.93.2"}, to="sip:1002@54.213.58.94", from="sip:1001@54.213.58.94"> | |
[2013-08-29 20:07:26] INFO Adhearsion::Call: 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: incoming call from 1001 --> 1002 | |
[2013-08-29 20:07:26] INFO Adhearsion::Call: 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: #<Adhearsion::Call:424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94 offer=#<Punchblock::Event::Offer target_call_id="424928b4-bc76-505f-febd-a5febae13aa3", target_mixer_name=nil, component_id=nil, domain="54.213.58.94", transport="xmpp", headers={"from"=>"<sip:1001@54.213.58.94>;tag=rUEmLhAqn5JETUNxGUPJ", "to"=>"<sip:1002@54.213.58.94>", "via"=>"SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKFdZVBe8T02PrtL6Q3OiuqruyMMHqROwS;rport=63020;received=202.157.93.2"}, to="sip:1002@54.213.58.94", from="sip:1001@54.213.58.94">, end_reason=nil, commands=[], variables={"from"=>"<sip:1001@54.213.58.94>;tag=rUEmLhAqn5JETUNxGUPJ", "to"=>"<sip:1002@54.213.58.94>", "via"=>"SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKFdZVBe8T02PrtL6Q3OiuqruyMMHqROwS;rport=63020;received=202.157.93.2"}, controllers=[#<Incomming call=424928b4-bc76-505f-febd-a5febae13aa3, metadata={}>], to="sip:1002@54.213.58.94", from="sip:1001@54.213.58.94"> | |
[2013-08-29 20:07:27] DEBUG Adhearsion::Call: 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: Executing command #<Punchblock::Command::Answer target_call_id=nil, target_mixer_name=nil, component_id=nil, domain=nil, transport=nil, headers={}> | |
[2013-08-29 20:07:27] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:149:in `write') <iq type="set" to="424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94" id="blather000e"> | |
<answer xmlns="urn:xmpp:rayo:1"/> | |
</iq> | |
[2013-08-29 20:07:27] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq from="424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" type="result" id="blather000e"/> | |
[2013-08-29 20:07:27] TRACE Punchblock::Connection::XMPP: RECEIVING (presence) <presence from="424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766"> | |
<answered xmlns="urn:xmpp:rayo:1"/> | |
</presence> | |
[2013-08-29 20:07:27] DEBUG Adhearsion::Call: 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: Executing command #<Punchblock::Component::Output target_call_id=nil, target_mixer_name=nil, component_id=nil, domain=nil, transport=nil, voice=nil, interrupt_on=nil, start_offset=nil, start_paused=false, repeat_interval=nil, repeat_times=nil, max_time=nil, renderer=nil, render_documents=[#<Punchblock::Component::Output::Document target_call_id=nil, target_mixer_name=nil, component_id=nil, domain=nil, transport=nil, url=nil, content_type="application/ssml+xml", value=<speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"> | |
<audio src="/var/punchblock/record/welcome.mp3"/> | |
</speak>>]> | |
[2013-08-29 20:07:27] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:149:in `write') <iq type="set" to="424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94" id="blather0010"> | |
<output xmlns="urn:xmpp:rayo:output:1" start-paused="false"> | |
<document content-type="application/ssml+xml"><![CDATA[<speak xmlns="http://www.w3.org/2001/10/synthesis" version="1.0" xml:lang="en-US"> | |
<audio src="/var/punchblock/record/welcome.mp3"/> | |
</speak>]]></document> | |
</output> | |
</iq> | |
[2013-08-29 20:07:27] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq from="424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" type="result" id="blather0010"> | |
<ref xmlns="urn:xmpp:rayo:1" uri="xmpp:424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1"/> | |
</iq> | |
[2013-08-29 20:07:27] TRACE Punchblock::Connection::XMPP: RECEIVING (presence) <presence from="424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94/output-1" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" type="unavailable"> | |
<complete xmlns="urn:xmpp:rayo:ext:1"> | |
<error xmlns="urn:xmpp:rayo:ext:complete:1"/> | |
</complete> | |
</presence> | |
Cannot transition state via :complete from :requested | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/state_machine-1.2.0/lib/state_machine/event.rb:252:in `block in add_actions' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/state_machine-1.2.0/lib/state_machine/machine.rb:765:in `call' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/state_machine-1.2.0/lib/state_machine/machine.rb:765:in `block (2 levels) in define_helper' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/punchblock-2.0.0/lib/punchblock/component/component_node.rb:53:in `complete_event=' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/punchblock-2.0.0/lib/punchblock/component/component_node.rb:16:in `block in register_internal_handlers' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/has-guarded-handlers-1.5.0/lib/has_guarded_handlers.rb:105:in `call' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/has-guarded-handlers-1.5.0/lib/has_guarded_handlers.rb:105:in `call_handler' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/has-guarded-handlers-1.5.0/lib/has_guarded_handlers.rb:91:in `block (3 levels) in trigger_handler' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/has-guarded-handlers-1.5.0/lib/has_guarded_handlers.rb:87:in `catch' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/has-guarded-handlers-1.5.0/lib/has_guarded_handlers.rb:87:in `block (2 levels) in trigger_handler' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/has-guarded-handlers-1.5.0/lib/has_guarded_handlers.rb:85:in `each' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/has-guarded-handlers-1.5.0/lib/has_guarded_handlers.rb:85:in `find' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/has-guarded-handlers-1.5.0/lib/has_guarded_handlers.rb:85:in `block in trigger_handler' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/has-guarded-handlers-1.5.0/lib/has_guarded_handlers.rb:84:in `catch' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/has-guarded-handlers-1.5.0/lib/has_guarded_handlers.rb:84:in `trigger_handler' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/punchblock-2.0.0/lib/punchblock/component/component_node.rb:22:in `add_event' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/punchblock-2.0.0/lib/punchblock/client.rb:27:in `handle_event' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/punchblock-2.0.0/lib/punchblock/client.rb:20:in `block in initialize' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/punchblock-2.0.0/lib/punchblock/connection/xmpp.rb:136:in `call' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/punchblock-2.0.0/lib/punchblock/connection/xmpp.rb:136:in `handle_presence' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/punchblock-2.0.0/lib/punchblock/connection/xmpp.rb:165:in `block in register_handlers' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:295:in `call' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:295:in `call_handler' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:286:in `block (2 levels) in call_handler_for' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:286:in `catch' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:286:in `block in call_handler_for' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:285:in `each' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:285:in `find' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:285:in `call_handler_for' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:278:in `block in handle_stanza' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:277:in `each' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:277:in `handle_stanza' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:194:in `block in handle_data' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:192:in `catch' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:192:in `handle_data' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:63:in `block in initialize' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/girl_friday-0.11.2/lib/girl_friday/work_queue.rb:147:in `call' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/girl_friday-0.11.2/lib/girl_friday/work_queue.rb:147:in `block (2 levels) in start' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/girl_friday-0.11.2/lib/girl_friday/actor.rb:86:in `call' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/girl_friday-0.11.2/lib/girl_friday/actor.rb:86:in `block in spawn_link' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/girl_friday-0.11.2/lib/girl_friday/actor.rb:69:in `call' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/girl_friday-0.11.2/lib/girl_friday/actor.rb:69:in `block (2 levels) in spawn' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/girl_friday-0.11.2/lib/girl_friday/actor.rb:212:in `block in initialize' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/girl_friday-0.11.2/lib/girl_friday/actor.rb:377:in `watchdog' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/girl_friday-0.11.2/lib/girl_friday/actor.rb:212:in `initialize' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/girl_friday-0.11.2/lib/girl_friday/actor.rb:66:in `new' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/girl_friday-0.11.2/lib/girl_friday/actor.rb:66:in `block in spawn' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/logging-1.8.1/lib/logging/diagnostic_context.rb:323:in `call' | |
/usr/local/rvm/gems/ruby-2.0.0-p247/gems/logging-1.8.1/lib/logging/diagnostic_context.rb:323:in `block in create_with_logging_context' | |
[2013-08-29 20:07:27] DEBUG Adhearsion::Call: 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: Receiving message: #<Punchblock::Event::Answered target_call_id="424928b4-bc76-505f-febd-a5febae13aa3", target_mixer_name=nil, component_id=nil, domain="54.213.58.94", transport="xmpp", headers={}> | |
[2013-08-29 20:07:50] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:149:in `write') <iq type="get" to="54.213.58.94" id="blather0012"> | |
<ping xmlns="urn:xmpp:ping"/> | |
</iq> | |
[2013-08-29 20:07:50] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq type="result" from="54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" id="blather0012"/> | |
[2013-08-29 20:07:57] TRACE Punchblock::Connection::XMPP: RECEIVING (presence) <presence from="424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" type="unavailable"> | |
<end xmlns="urn:xmpp:rayo:1"> | |
<hungup/> | |
</end> | |
</presence> | |
[2013-08-29 20:07:57] DEBUG Adhearsion::Call: 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: Receiving message: #<Punchblock::Event::End target_call_id="424928b4-bc76-505f-febd-a5febae13aa3", target_mixer_name=nil, component_id=nil, domain="54.213.58.94", transport="xmpp", headers={}, reason=:hungup, platform_code=nil> | |
[2013-08-29 20:07:57] INFO Adhearsion::Call: 424928b4-bc76-505f-febd-a5febae13aa3@54.213.58.94: Call ended due to hungup | |
[2013-08-29 20:08:50] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:149:in `write') <iq type="get" to="54.213.58.94" id="blather0014"> | |
<ping xmlns="urn:xmpp:ping"/> | |
</iq> | |
[2013-08-29 20:08:50] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq type="result" from="54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" id="blather0014"/> | |
[2013-08-29 20:09:50] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:149:in `write') <iq type="get" to="54.213.58.94" id="blather0016"> | |
<ping xmlns="urn:xmpp:ping"/> | |
</iq> | |
[2013-08-29 20:09:50] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq type="result" from="54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" id="blather0016"/> | |
[2013-08-29 20:10:50] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:149:in `write') <iq type="get" to="54.213.58.94" id="blather0018"> | |
<ping xmlns="urn:xmpp:ping"/> | |
</iq> | |
[2013-08-29 20:10:50] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq type="result" from="54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" id="blather0018"/> | |
[2013-08-29 20:11:50] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:149:in `write') <iq type="get" to="54.213.58.94" id="blather001a"> | |
<ping xmlns="urn:xmpp:ping"/> | |
</iq> | |
[2013-08-29 20:11:50] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq type="result" from="54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" id="blather001a"/> | |
[2013-08-29 20:12:50] TRACE Punchblock::Connection::XMPP: SENDING: (/usr/local/rvm/gems/ruby-2.0.0-p247/gems/blather-0.8.7/lib/blather/client/client.rb:149:in `write') <iq type="get" to="54.213.58.94" id="blather001c"> | |
<ping xmlns="urn:xmpp:ping"/> | |
</iq> | |
[2013-08-29 20:12:50] TRACE Punchblock::Connection::XMPP: RECEIVING (iq) <iq type="result" from="54.213.58.94" to="1@54.213.58.94/ip-172-31-41-127.us-west-2.compute.internal-4766" id="blather001c"/> |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
I don't know the original reason for this log dump but I am also seeing the "NET_RWERR" error. It seems to indicate that FreeSwitch is unable to reply to Adhearsion:
https://freeswitch.org/stash/projects/FS/repos/freeswitch/browse/src/mod/event_handlers/mod_rayo/iks_helpers.c?at=96eba0d6a8e7bbb202e8928c3b18918eeacb4f1c&raw
meduketto/iksemel@8f79792
Recommendation: check firewalls and load balancers.