gistfile1.txt

Dec 13 16:07:01 general info    Shutting down...
Dec 13 16:07:01 general info    Shutdown status: Cleaning up
Dec 13 16:07:01 general info    Shutdown complete
Dec 13 16:07:01 general info    Hello and welcome to Prosody version 0.9.1
Dec 13 16:07:01 general info    Prosody is using the select backend for connection handling
Dec 13 16:07:01 hostmanager     debug   Activated host: directory.buddycloud.org
Dec 13 16:07:01 portmanager     debug   No active service for component, activating...
Dec 13 16:07:01 socket  debug   server.lua: new server listener on '[127.0.0.1]:5347'
Dec 13 16:07:01 portmanager     debug   Added listening service component to [127.0.0.1]:5347
Dec 13 16:07:01 portmanager     info    Activated service 'component' on [127.0.0.1]:5347
Dec 13 16:07:02 portmanager     debug   No active service for s2s, activating...
Dec 13 16:07:02 socket  debug   server.lua: new server listener on '[*]:5269'
Dec 13 16:07:02 portmanager     debug   Added listening service s2s to [*]:5269
Dec 13 16:07:02 portmanager     info    Activated service 's2s' on [*]:5269
Dec 13 16:07:02 hostmanager     debug   Activated host: topics.buddycloud.org
Dec 13 16:07:02 hostmanager     debug   Activated host: buddycloud.org
Dec 13 16:07:02 buddycloud.org:storage_sql      debug   Successfully connected to database
Dec 13 16:07:02 auth_internal_hashed    debug   initializing internal_hashed authentication provider for host 'buddycloud.org'
Dec 13 16:07:02 usermanager     debug   host 'buddycloud.org' now set to use user provider 'internal_hashed'
Dec 13 16:07:02 portmanager     debug   No active service for console, activating...
Dec 13 16:07:02 socket  debug   server.lua: new server listener on '[127.0.0.1]:5582'
Dec 13 16:07:02 portmanager     debug   Added listening service console to [127.0.0.1]:5582
Dec 13 16:07:02 portmanager     info    Activated service 'console' on [127.0.0.1]:5582
Dec 13 16:07:02 portmanager     debug   No active service for http, activating...
Dec 13 16:07:02 socket  debug   server.lua: new server listener on '[*]:5280'
Dec 13 16:07:02 portmanager     debug   Added listening service http to [*]:5280
Dec 13 16:07:02 portmanager     info    Activated service 'http' on [*]:5280
Dec 13 16:07:02 portmanager     debug   No active service for https, activating...
Dec 13 16:07:02 socket  debug   server.lua: new ssl server listener on '[*]:5281'
Dec 13 16:07:02 portmanager     debug   Added listening service https to [*]:5281
Dec 13 16:07:02 portmanager     info    Activated service 'https' on [*]:5281
Dec 13 16:07:02 portmanager     debug   No active service for c2s, activating...
Dec 13 16:07:02 socket  debug   server.lua: new server listener on '[*]:5222'
Dec 13 16:07:02 portmanager     debug   Added listening service c2s to [*]:5222
Dec 13 16:07:02 portmanager     info    Activated service 'c2s' on [*]:5222
Dec 13 16:07:02 portmanager     debug   No active service for legacy_ssl, activating...
Dec 13 16:07:02 portmanager     info    Activated service 'legacy_ssl' on no ports
Dec 13 16:07:02 mod_posix       info    Prosody is about to detach from the console, disabling further console output
Dec 13 16:07:02 mod_posix       info    Successfully daemonized to PID 7226
Dec 13 16:07:02 hostmanager     debug   Activated host: mediaserver.buddycloud.org
Dec 13 16:07:02 hostmanager     debug   Activated host: pusher.buddycloud.com
Dec 13 16:07:02 hostmanager     debug   Activated host: channels.buddycloud.org
Dec 13 16:07:02 hostmanager     debug   Activated host: search.buddycloud.org
Dec 13 16:07:02 hostmanager     debug   Activated host: anon.buddycloud.org
Dec 13 16:07:02 usermanager     error   Deprecated config option 'anonymous_login'. Use authentication = 'anonymous' instead.
Dec 13 16:07:02 usermanager     debug   host 'anon.buddycloud.org' now set to use user provider 'anonymous'
Dec 13 16:07:02 anon.buddycloud.org:s2s warn    The 'disallow_s2s' config option is deprecated, please see http://prosody.im/doc/s2s#disabling
Dec 13 16:07:03 socket  debug   server.lua: accepted new client connection from 5.9.67.253:44384 to 5222
Dec 13 16:07:03 c2sa50140       info    Client connected
Dec 13 16:07:03 c2sa50140       debug   Client sent opening <stream:stream> to anon.buddycloud.org
Dec 13 16:07:03 c2sa50140       debug   Sent reply <stream:stream> to client
Dec 13 16:07:03 c2sa50140       debug   Received[c2s_unauthed]: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
Dec 13 16:07:03 socket  debug   server.lua: we need to do tls, but delaying until send buffer empty
Dec 13 16:07:03 c2sa50140       debug   TLS negotiation started for c2s_unauthed...
Dec 13 16:07:03 socket  debug   server.lua: attempting to start tls on tcp{client}: 0x9e76e8
Dec 13 16:07:03 socket  debug   server.lua: ssl handshake done
Dec 13 16:07:03 c2sa50140       debug   Client sent opening <stream:stream> to anon.buddycloud.org
Dec 13 16:07:03 c2sa50140       debug   Sent reply <stream:stream> to client
Dec 13 16:07:03 c2sa50140       debug   Received[c2s_unauthed]: <auth mechanism='ANONYMOUS' xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
Dec 13 16:07:03 c2sa50140       info    Authenticated as [email protected]
Dec 13 16:07:03 anon.buddycloud.org:saslauth    debug   sasl reply: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'></success>
Dec 13 16:07:03 c2sa50140       debug   Client sent opening <stream:stream> to anon.buddycloud.org
Dec 13 16:07:03 c2sa50140       debug   Sent reply <stream:stream> to client
Dec 13 16:07:03 c2sa50140       debug   Received[c2s]: <iq id='bind' type='set'>
Dec 13 16:07:03 rostermanager   debug   load_roster: asked for: [email protected]
Dec 13 16:07:03 rostermanager   debug   load_roster: loading for new user: [email protected]
Dec 13 16:07:03 c2sa50140       debug   Resource bound: [email protected]/6707a40c-c023-4609-9fa8-749de96ba387
Dec 13 16:07:03 c2sa50140       debug   Received[c2s]: <iq id='sess' type='set' to='anon.buddycloud.org'>
Dec 13 16:07:03 c2sa50140       debug   Received[c2s]: <presence>
Dec 13 16:07:03 datamanager     debug   Assuming empty offline storage ('cannot open /var/lib/prosody/anon%2ebuddycloud%2eorg/offline/ea53f7db%2dcb70%2d4669%2da15a%2d6b1c677728ce.list: No such file or directory') for user: [email protected]
Dec 13 16:07:03 c2sa50140       debug   Received[c2s]: <presence to='channels.buddycloud.org' from='[email protected]'>
Dec 13 16:07:03 channels.buddycloud.org:component       warn    Component not connected, bouncing error for: <presence to='channels.buddycloud.org' from='[email protected]/6707a40c-c023-4609-9fa8-749de96ba387'>
Dec 13 16:07:03 socket  debug   server.lua: accepted new client connection from 5.9.67.253:44388 to 5222
Dec 13 16:07:03 c2s77afa0       info    Client connected
Dec 13 16:07:03 c2s77afa0       debug   Client sent opening <stream:stream> to buddycloud.org
Dec 13 16:07:03 c2s77afa0       debug   Sent reply <stream:stream> to client
Dec 13 16:07:03 c2s77afa0       debug   Received[c2s_unauthed]: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
Dec 13 16:07:03 socket  debug   server.lua: we need to do tls, but delaying until send buffer empty
Dec 13 16:07:03 c2s77afa0       debug   TLS negotiation started for c2s_unauthed...
Dec 13 16:07:03 socket  debug   server.lua: attempting to start tls on tcp{client}: 0x8ff8c8
Dec 13 16:07:03 socket  debug   server.lua: ssl handshake done
Dec 13 16:07:03 c2s77afa0       debug   Client sent opening <stream:stream> to buddycloud.org
Dec 13 16:07:03 c2s77afa0       debug   Sent reply <stream:stream> to client
Dec 13 16:07:03 c2s77afa0       debug   Received[c2s_unauthed]: <auth mechanism='PLAIN' xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>
Dec 13 16:07:03 c2s77afa0       info    Authenticated as [email protected]
Dec 13 16:07:03 buddycloud.org:saslauth debug   sasl reply: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'></success>
Dec 13 16:07:03 c2s77afa0       debug   Client sent opening <stream:stream> to buddycloud.org
Dec 13 16:07:03 c2s77afa0       debug   Sent reply <stream:stream> to client
Dec 13 16:07:03 c2s77afa0       debug   Received[c2s]: <iq id='bind' type='set'>
Dec 13 16:07:03 rostermanager   debug   load_roster: asked for: [email protected]
Dec 13 16:07:03 rostermanager   debug   load_roster: loading for new user: [email protected]
Dec 13 16:07:03 c2s77afa0       debug   Resource bound: [email protected]/53d23e79-832b-4800-9360-8fc033fe1be3
Dec 13 16:07:03 c2s77afa0       debug   Received[c2s]: <iq id='sess' type='set' to='buddycloud.org'>
Dec 13 16:07:03 c2s77afa0       debug   Received[c2s]: <presence>
Dec 13 16:07:03 stanzarouter    debug   Routing to remote...
Dec 13 16:07:03 mod_s2s debug   opening a new outgoing connection for this stanza
Dec 13 16:07:03 mod_s2s debug   stanza [presence] queued until connection complete
Dec 13 16:07:03 mod_s2s debug   First attempt to connect to surevine.com, starting with SRV lookup...
Dec 13 16:07:03 adns    debug   Records for _xmpp-server._tcp.surevine.com. not in cache, sending query (thread: 0x9a1d50)...
Dec 13 16:07:03 adns    debug   Sending DNS query to 213.133.99.99
Dec 13 16:07:03 stanzarouter    debug   Routing to remote...
Dec 13 16:07:03 mod_s2s debug   opening a new outgoing connection for this stanza
Dec 13 16:07:03 mod_s2s debug   stanza [presence] queued until connection complete
Dec 13 16:07:03 mod_s2s debug   First attempt to connect to evilprofessor.co.uk, starting with SRV lookup...
Dec 13 16:07:03 adns    debug   Records for _xmpp-server._tcp.evilprofessor.co.uk. not in cache, sending query (thread: 0x9273a0)...

and later


Dec 13 16:07:03 adns    debug   Records for buddycloud.surevine.com. not in cache, sending query (thread: 0x7cbe90)...
Dec 13 16:07:03 adns    debug   Sending DNS query to 213.133.99.99
Dec 13 16:07:03 adns    debug   Reply for xmpp.evilprofessor.co.uk. (thread: 0x8a64a0)
Dec 13 16:07:03 mod_s2s debug   DNS reply for xmpp.evilprofessor.co.uk. gives us 82.45.44.132
Dec 13 16:07:03 s2sout9151e0    info    Beginning new connection attempt to evilprofessor.co.uk ([82.45.44.132]:5269)
Dec 13 16:07:03 s2sout9151e0    debug   Connection attempt in progress...
Dec 13 16:07:03 socket  debug   server.lua: closed client handler and removed socket from list
Dec 13 16:07:03 adns    debug   Reply for buddycloud.surevine.com. (thread: 0x7cbe90)
Dec 13 16:07:03 mod_s2s debug   DNS reply for buddycloud.surevine.com. gives us 54.246.189.81
Dec 13 16:07:03 s2sout84bfb0    info    Beginning new connection attempt to surevine.com ([54.246.189.81]:5269)
Dec 13 16:07:03 s2sout84bfb0    debug   Connection attempt in progress...
Dec 13 16:07:03 s2sout9151e0    debug   sending: <?xml version='1.0'?>
Dec 13 16:07:03 s2sout9151e0    debug   sending: <stream:stream xmlns:db='jabber:server:dialback' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='buddycloud.org' to='evilprofessor.co.uk' xml:lang='en' xmlns='jabber:server'>
Dec 13 16:07:03 s2sout84bfb0    debug   sending: <?xml version='1.0'?>
Dec 13 16:07:03 s2sout84bfb0    debug   sending: <stream:stream xmlns:db='jabber:server:dialback' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='buddycloud.org' to='surevine.com' xml:lang='en' xmlns='jabber:server'>
Dec 13 16:07:03 s2sout9151e0    debug   Received[s2sout_unauthed]: <features xmlns='http://etherx.jabber.org/streams'>
Dec 13 16:07:03 buddycloud.org:tls      debug   Received features element
Dec 13 16:07:03 buddycloud.org:tls      debug   evilprofessor.co.uk is offering TLS, taking up the offer...
Dec 13 16:07:03 s2sout9151e0    debug   sending: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>
Dec 13 16:07:03 s2sout84bfb0    debug   Received[s2sout_unauthed]: <features xmlns='http://etherx.jabber.org/streams'>
Dec 13 16:07:03 buddycloud.org:tls      debug   Received features element
Dec 13 16:07:03 buddycloud.org:tls      debug   surevine.com is offering TLS, taking up the offer...
Dec 13 16:07:03 s2sout84bfb0    debug   sending: <starttls xmlns='urn:ietf:params:xml:ns:xmpp-tls'/>
Dec 13 16:07:03 s2sout84bfb0    debug   Received[s2sout_unauthed]: <proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
Dec 13 16:07:03 buddycloud.org:tls      debug   Proceeding with TLS on s2sout...
Dec 13 16:07:03 socket  debug   server.lua: attempting to start tls on tcp{client}: 0xa0e428
Dec 13 16:07:03 s2sout9151e0    debug   Received[s2sout_unauthed]: <proceed xmlns='urn:ietf:params:xml:ns:xmpp-tls'>
Dec 13 16:07:03 buddycloud.org:tls      debug   Proceeding with TLS on s2sout...
Dec 13 16:07:03 socket  debug   server.lua: attempting to start tls on tcp{client}: 0x7dbf88
Dec 13 16:07:03 c2s77afa0       debug   Received[c2s]: <iq id='f6bf6e3149f7a8be0f4d225a35d20a30' type='get' to='channels.buddycloud.org' from='[email protected]/53d23e79-832b-4800-9360-8fc033fe1be3'>
Dec 13 16:07:03 channels.buddycloud.org:component       warn    Component not connected, bouncing error for: <iq id='f6bf6e3149f7a8be0f4d225a35d20a30' type='get' to='channels.buddycloud.org' from='[email protected]/53d23e79-832b-4800-9360-8fc033fe1be3'>
Dec 13 16:07:03 socket  debug   server.lua: ssl handshake done
Dec 13 16:07:03 s2sout84bfb0    debug   Sending stream header...
Dec 13 16:07:03 s2sout84bfb0    debug   sending: <?xml version='1.0'?>
Dec 13 16:07:03 s2sout84bfb0    debug   sending: <stream:stream xmlns:db='jabber:server:dialback' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='buddycloud.org' id='0356530d-9afd-4dea-b280-3a4e981fc845' to='surevine.com' xml:lang='en' xmlns='jabber:server'>
Dec 13 16:07:03 s2sout84bfb0    debug   certificate chain validation result: valid
Dec 13 16:07:03 x509    debug   Cert dNSName surevine.com matched hostname
Dec 13 16:07:03 s2sout84bfb0    debug   certificate identity validation result: valid   
Dec 13 16:07:03 s2sout84bfb0    debug   Received[s2sout_unauthed]: <features xmlns='http://etherx.jabber.org/streams'>
Dec 13 16:07:03 buddycloud.org:tls      debug   Received features element
Dec 13 16:07:03 buddycloud.org:dialback debug   Initiating dialback...
Dec 13 16:07:03 s2sout84bfb0    debug   sending: <db:result to='surevine.com' from='buddycloud.org'>
Dec 13 16:07:03 s2sout84bfb0    info    sent dialback key on outgoing s2s stream
Dec 13 16:07:03 socket  debug   server.lua: ssl handshake done
Dec 13 16:07:03 s2sout9151e0    debug   Sending stream header...
Dec 13 16:07:03 s2sout9151e0    debug   sending: <?xml version='1.0'?>
Dec 13 16:07:03 s2sout9151e0    debug   sending: <stream:stream xmlns:db='jabber:server:dialback' xmlns:stream='http://etherx.jabber.org/streams' version='1.0' from='buddycloud.org' id='e01e067b-9fa9-420a-9998-e2ac32dfe977' to='evilprofessor.co.uk' xml:lang='en' xmlns='jabber:server'>
Dec 13 16:07:03 s2sout9151e0    debug   certificate chain validation result: invalid