Jan 28 03:03:34 general info Hello and welcome to Prosody version 0.9.1 Jan 28 03:03:34 general info Prosody is using the select backend for connection handling Jan 28 03:03:34 hostmanager debug Activated host: mp5.im Jan 28 03:03:34 mp5.im:storage_sql debug Successfully connected to database Jan 28 03:03:34 auth_internal_hashed debug initializing internal_hashed authentication provider for host 'mp5.im' Jan 28 03:03:34 usermanager debug host 'mp5.im' now set to use user provider 'internal_hashed' Jan 28 03:03:34 portmanager debug No active service for c2s, activating... Jan 28 03:03:34 socket debug server.lua: new server listener on '[192.252.217.6]:5222' Jan 28 03:03:34 portmanager debug Added listening service c2s to [192.252.217.6]:5222 Jan 28 03:03:34 portmanager info Activated service 'c2s' on [192.252.217.6]:5222 Jan 28 03:03:34 portmanager debug No active service for legacy_ssl, activating... Jan 28 03:03:34 portmanager info Activated service 'legacy_ssl' on no ports Jan 28 03:03:34 portmanager debug No active service for s2s, activating... Jan 28 03:03:34 socket debug server.lua: new server listener on '[192.252.217.6]:5269' Jan 28 03:03:34 portmanager debug Added listening service s2s to [192.252.217.6]:5269 Jan 28 03:03:34 portmanager info Activated service 's2s' on [192.252.217.6]:5269 Jan 28 03:03:34 portmanager debug No active service for http, activating... Jan 28 03:03:34 socket debug server.lua: new server listener on '[192.252.217.6]:5280' Jan 28 03:03:34 portmanager debug Added listening service http to [192.252.217.6]:5280 Jan 28 03:03:34 portmanager info Activated service 'http' on [192.252.217.6]:5280 Jan 28 03:03:34 portmanager debug No active service for https, activating... Jan 28 03:03:34 socket debug server.lua: new ssl server listener on '[192.252.217.6]:5281' Jan 28 03:03:34 portmanager debug Added listening service https to [192.252.217.6]:5281 Jan 28 03:03:34 portmanager info Activated service 'https' on [192.252.217.6]:5281 Jan 28 03:03:34 mod_posix info Prosody is about to detach from the console, disabling further console output Jan 28 03:03:34 mod_posix info Successfully daemonized to PID 7178 Jan 28 03:03:34 modulemanager warn http is already loaded for mp5.im, so not loading again Jan 28 03:03:34 hostmanager debug Activated host: conference.mp5.im Jan 28 03:03:34 hostmanager debug Activated host: proxy.mp5.im Jan 28 03:03:34 portmanager debug No active service for proxy65, activating... Jan 28 03:03:34 socket debug server.lua: new server listener on '[192.252.217.6]:5000' Jan 28 03:03:34 portmanager debug Added listening service proxy65 to [192.252.217.6]:5000 Jan 28 03:03:34 portmanager info Activated service 'proxy65' on [192.252.217.6]:5000 Jan 28 03:03:34 socket debug server.lua: accepted new client connection from 108.248.207.74:21443 to 5222 Jan 28 03:03:34 c2s8bea93e6480 info Client connected Jan 28 03:03:34 c2s8bea93e6480 debug Client sent opening to mp5.im Jan 28 03:03:34 c2s8bea93e6480 debug Sent reply to client Jan 28 03:03:34 c2s8bea93e6480 debug Received[c2s_unauthed]: Jan 28 03:03:34 socket debug server.lua: we need to do tls, but delaying until send buffer empty Jan 28 03:03:34 c2s8bea93e6480 debug TLS negotiation started for c2s_unauthed... Jan 28 03:03:34 socket debug server.lua: attempting to start tls on tcp{client}: 0x8bea93e2b98 Jan 28 03:03:34 socket debug server.lua: ssl handshake done Jan 28 03:03:35 c2s8bea93e6480 debug Client sent opening to mp5.im Jan 28 03:03:35 c2s8bea93e6480 debug Sent reply to client Jan 28 03:03:35 c2s8bea93e6480 debug Received[c2s_unauthed]: Jan 28 03:03:35 c2s8bea93e6480 info Authenticated as mp5@mp5.im Jan 28 03:03:35 mp5.im:saslauth debug sasl reply: Jan 28 03:03:35 c2s8bea93e6480 debug Client sent opening to mp5.im Jan 28 03:03:35 c2s8bea93e6480 debug Sent reply to client Jan 28 03:03:35 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:35 rostermanager debug load_roster: asked for: mp5@mp5.im Jan 28 03:03:35 rostermanager debug load_roster: loading for new user: mp5@mp5.im Jan 28 03:03:35 c2s8bea93e6480 debug Resource bound: mp5@mp5.im/home Jan 28 03:03:35 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:35 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:35 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:35 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:35 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:36 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:36 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:36 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:36 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:36 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:36 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:36 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:36 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:36 stanzarouter debug Stanza of type iq from c2s has xmlns: http://jabber.org/protocol/pubsub#owner Jan 28 03:03:36 stanzarouter debug Unhandled c2s stanza: iq; xmlns=http://jabber.org/protocol/pubsub#owner Jan 28 03:03:36 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:37 stanzarouter debug Stanza of type iq from c2s has xmlns: http://jabber.org/protocol/pubsub#owner Jan 28 03:03:37 stanzarouter debug Unhandled c2s stanza: iq; xmlns=http://jabber.org/protocol/pubsub#owner Jan 28 03:03:37 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:37 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:37 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:37 datamanager debug Assuming empty offline storage ('cannot open /var/lib/prosody/mp5%2eim/offline/mp5.list: No such file or directory') for user: mp5@mp5.im Jan 28 03:03:37 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:37 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:37 stanzarouter debug Discarding iq from c2s of type: result Jan 28 03:03:41 c2s8bea93e6480 debug Received[c2s]: Jan 28 03:03:41 stanzarouter debug Routing to remote... Jan 28 03:03:41 mod_s2s debug opening a new outgoing connection for this stanza Jan 28 03:03:41 mod_s2s debug stanza [presence] queued until connection complete Jan 28 03:03:41 mod_s2s debug First attempt to connect to conference.prosody.im, starting with SRV lookup... Jan 28 03:03:41 adns debug Records for _xmpp-server._tcp.conference.prosody.im. not in cache, sending query (thread: 0x8bea94c5f10)... Jan 28 03:03:41 adns debug Sending DNS query to 4.2.2.1 Jan 28 03:03:41 socket debug server.lua: closed client handler and removed socket from list Jan 28 03:03:41 adns debug Reply for _xmpp-server._tcp.conference.prosody.im. (thread: 0x8bea94c5f10) Jan 28 03:03:41 mod_s2s debug conference.prosody.im has SRV records, handling... Jan 28 03:03:41 mod_s2s debug Best record found, will connect to prosody.im.:5269 Jan 28 03:03:41 adns debug Records for prosody.im. not in cache, sending query (thread: 0x8bea94ce3d0)... Jan 28 03:03:41 adns debug Sending DNS query to 4.2.2.1 Jan 28 03:03:41 socket debug server.lua: closed client handler and removed socket from list Jan 28 03:03:41 adns debug Reply for prosody.im. (thread: 0x8bea94ce3d0) Jan 28 03:03:41 mod_s2s debug DNS reply for prosody.im. gives us 89.16.173.64 Jan 28 03:03:41 s2sout8bea94c4960 info Beginning new connection attempt to conference.prosody.im ([89.16.173.64]:5269) Jan 28 03:03:41 s2sout8bea94c4960 debug Connection attempt in progress... Jan 28 03:03:41 s2sout8bea94c4960 debug sending: Jan 28 03:03:41 s2sout8bea94c4960 debug sending: Jan 28 03:03:41 s2sout8bea94c4960 debug Received[s2sout_unauthed]: Jan 28 03:03:41 mp5.im:tls debug Received features element Jan 28 03:03:41 mp5.im:tls debug conference.prosody.im is offering TLS, taking up the offer... Jan 28 03:03:41 s2sout8bea94c4960 debug sending: Jan 28 03:03:42 s2sout8bea94c4960 debug Received[s2sout_unauthed]: Jan 28 03:03:42 mp5.im:tls debug Proceeding with TLS on s2sout... Jan 28 03:03:42 socket debug server.lua: attempting to start tls on tcp{client}: 0x8bea94d3288 Jan 28 03:03:42 socket debug server.lua: ssl handshake done Jan 28 03:03:42 s2sout8bea94c4960 debug Sending stream header... Jan 28 03:03:42 s2sout8bea94c4960 debug sending: Jan 28 03:03:42 s2sout8bea94c4960 debug sending: Jan 28 03:03:42 mod_s2s warn Forbidding insecure connection to/from conference.prosody.im Jan 28 03:03:42 s2sout8bea94c4960 debug sending: Jan 28 03:03:42 s2sout8bea94c4960 debug sending: Jan 28 03:03:42 s2sout8bea94c4960 debug sending: Jan 28 03:03:42 s2sout8bea94c4960 info outgoing s2s stream mp5.im->conference.prosody.im closed: stream closed Jan 28 03:03:42 s2sout8bea94c4960 debug Destroying outgoing session mp5.im->conference.prosody.im Jan 28 03:03:42 s2sout8bea94c4960 info sending error replies for 1 queued stanzas because of failed outgoing connection to conference.prosody.im Jan 28 03:03:42 stanzarouter debug Received[s2sin]: Jan 28 03:03:42 s2sout8bea94c4960 debug s2s disconnected: nil->nil (connection closed) Jan 28 03:03:42 socket debug server.lua: closed client handler and removed socket from list Jan 28 03:03:42 s2sout8bea94c4960 debug Received[s2s_destroyed]: