[error] request to start session in non-serviced domain [version 2.2.16]
Auro Tripathy <[email protected]> Wed, 25 Jul 2012 21:57:41 +0000
| Newsgroups | gmane.network.jabber.user |
|---|---|
| Message-ID | <[email protected]> |
Please help, I get the following error (complete console log below).
SM : Wed Jul 25 14:41:32 2012 [error] request to start session in non-serviced domain: [email protected]/aurotripathy-OptiPlex-390
I don't understand the jid being tagged with my client machine name, aurotripathy-OptiPlex-390.
My client is a psi client.
/var/log/messages
-----------------
Jul 25 14:40:12 engdev1 jabberd/c2s[15640]: ready for connections
Jul 25 14:41:32 engdev1 jabberd/c2s[15640]: [8] [129.253.54.224, port=17458] connect
Jul 25 14:41:32 engdev1 jabberd/c2s[15640]: [8] DIGEST-MD5 authentication succeeded: [email protected] 129.253.54.224:17458
Jul 25 14:41:32 engdev1 jabberd/c2s[15640]: [8] bound: [email protected]/aurotripathy-OptiPlex-390
Jul 25 14:41:32 engdev1 jabberd/sm[15637]: request to start session in non-serviced domain: [email protected]/aurotripathy-OptiPlex-390
Jul 25 14:41:43 engdev1 jabberd/c2s[15640]: shutting down
Jul 25 14:41:43 engdev1 jabberd/c2s[15640]: connection to router closed
Jul 25 14:41:43 engdev1 jabberd/s2s[15639]: shutting down
Jul 25 14:41:43 engdev1 jabberd/s2s[15639]: connection to router closed
Jul 25 14:41:43 engdev1 jabberd/sm[15637]: shutting down
Jul 25 14:41:43 engdev1 jabberd/sm[15637]: connection to router closed
Jul 25 14:41:43 engdev1 jabberd/router[15636]: [127.0.0.1, port=60582] disconnect
Jul 25 14:41:43 engdev1 jabberd/router[15636]: [localhost.localdomain] offline
Jul 25 14:41:43 engdev1 jabberd/router[15636]: [engdev1.remotewd2.com] offline
Jul 25 14:41:43 engdev1 jabberd/router[15636]: [127.0.0.1, port=60580] disconnect
Jul 25 14:41:43 engdev1 jabberd/router[15636]: [s2s] default route offline
Jul 25 14:41:43 engdev1 jabberd/router[15636]: [s2s] offline
Jul 25 14:41:43 engdev1 jabberd/router[15636]: [127.0.0.1, port=60581] disconnect
Jul 25 14:41:43 engdev1 jabberd/router[15636]: [c2s] offline
Jul 25 14:41:43 engdev1 jabberd/router[15636]: shutting down
Console log in debug mode
--------------------------
JBRD: debug on
JBRD: version(2.2.16)
JBRD: config_dir(/usr/local/etc)
JBRD: LaunchJob: router -> /usr/local/bin/router -c /usr/local/etc/router.xml -D
JBRD: LaunchJob: sm -> /usr/local/bin/sm -c /usr/local/etc/sm.xml -D
JBRD: LaunchJob: s2s -> /usr/local/bin/s2s -c /usr/local/etc/s2s.xml -D
JBRD: LaunchJob: c2s -> /usr/local/bin/c2s -c /usr/local/etc/c2s.xml -D
ROUT: /usr/local/bin/router: /usr/lib64/libgsasl.so.7: no version information available (required by /usr/local/bin/router)
SM : /usr/local/bin/sm: /usr/lib64/libgsasl.so.7: no version information available (required by /usr/local/bin/sm)
S2S : /usr/local/bin/s2s: /usr/lib64/libgsasl.so.7: no version information available (required by /usr/local/bin/s2s)
C2S : /usr/local/bin/c2s: /usr/lib64/libgsasl.so.7: no version information available (required by /usr/local/bin/c2s)
SM : Wed Jul 25 14:40:12 2012 [notice] starting up
SM : Wed Jul 25 14:40:12 2012 [info] process id is 15637, written to /usr/local/var/jabberd/pid/sm.pid
SM : Wed Jul 25 14:40:12 2012 storage.c:96 adding arbitrary types to driver 'mysql'
SM : Wed Jul 25 14:40:12 2012 storage.c:119 driver not loaded, trying to init
SM : Wed Jul 25 14:40:12 2012 [info] loading 'mysql' storage module
SM : Wed Jul 25 14:40:12 2012 storage.c:141 preloaded module 'mysql' (not initialized yet)
SM : Wed Jul 25 14:40:12 2012 storage.c:160 calling driver initializer
SM : Wed Jul 25 14:40:12 2012 [notice] initialised storage driver 'mysql'
SM : Wed Jul 25 14:40:12 2012 aci.c:37 loading aci
SM : Wed Jul 25 14:40:12 2012 aci.c:57 building list for 'all'
SM : Wed Jul 25 14:40:12 2012 aci.c:67 added '[email protected]'
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature iq
SM : Wed Jul 25 14:40:12 2012 [notice] modules search path: /usr/local/lib/jabberd
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'sess-start'
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'status' to chain 'sess-start' (not added yet)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'status' added to chain 'sess-start' (order 0 index 0 seq 0)
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'sess-end'
SM : Wed Jul 25 14:40:12 2012 [notice] module 'status' added to chain 'sess-end' (order 0 index 0 seq 1)
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'iq-last' to chain 'sess-end' (not added yet)
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature jabber:iq:last
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-last' added to chain 'sess-end' (order 1 index 1 seq 0)
S2S : Wed Jul 25 14:40:12 2012 [notice] starting up (interval=60, queue=60, keepalive=0, idle=86400)
C2S : Wed Jul 25 14:40:12 2012 [notice] starting up
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'in-sess'
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'validate' to chain 'in-sess' (not added yet)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'validate' added to chain 'in-sess' (order 0 index 2 seq 0)
S2S : Wed Jul 25 14:40:12 2012 [info] process id is 15639, written to /usr/local/var/jabberd/pid/s2s.pid
C2S : Wed Jul 25 14:40:12 2012 [info] process id is 15640, written to /usr/local/var/jabberd/pid/c2s.pid
SM : Wed Jul 25 14:40:12 2012 [notice] module 'status' added to chain 'in-sess' (order 1 index 0 seq 2)
ROUT: Wed Jul 25 14:40:12 2012 [notice] starting up
S2S : sx (sasl_gsasl.c:933) initialising sasl plugin
ROUT: Wed Jul 25 14:40:12 2012 [info] process id is 15636, written to /usr/local/var/jabberd/pid/router.pid
S2S : sx (sasl_gsasl.c:961) sasl context initialised
ROUT: Wed Jul 25 14:40:12 2012 user.c:33 loading user table
S2S : sx (env.c:75) plugin initialised (index 0)
ROUT: Wed Jul 25 14:40:12 2012 user.c:85 remembering user 'jabberd'
S2S : Wed Jul 25 14:40:12 2012 db.c:56 initialising dialback sx plugin
ROUT: Wed Jul 25 14:40:12 2012 [notice] loaded user table (1 users)
S2S : sx (env.c:75) plugin initialised (index 1)
ROUT: Wed Jul 25 14:40:12 2012 aci.c:37 loading aci
S2S : Wed Jul 25 14:40:12 2012 [notice] attempting connection to router at 127.0.0.1, port=5347
ROUT: Wed Jul 25 14:40:12 2012 aci.c:56 building list for 'all'
ROUT: Wed Jul 25 14:40:12 2012 aci.c:77 added 'jabberd'
ROUT: Wed Jul 25 14:40:12 2012 filter.c:51 loading filter
ROUT: Wed Jul 25 14:40:12 2012 filter.c:93 building filter list
ROUT: Wed Jul 25 14:40:12 2012 [notice] loaded filters (0 rules)
ROUT: sx (sasl_gsasl.c:933) initialising sasl plugin
ROUT: sx (sasl_gsasl.c:961) sasl context initialised
ROUT: sx (env.c:75) plugin initialised (index 0)
ROUT: Wed Jul 25 14:40:12 2012 [notice] [0.0.0.0, port=5347] listening for incoming connections
ROUT: Wed Jul 25 14:40:12 2012 router.c:1085 accept action on fd 6
C2S : Wed Jul 25 14:40:12 2012 [notice] modules search path: /usr/local/lib/jabberd
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'privacy' to chain 'in-sess' (not added yet)
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature jabber:iq:privacy
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature urn:xmpp:blocking
SM : Wed Jul 25 14:40:12 2012 [notice] module 'privacy' added to chain 'in-sess' (order 2 index 3 seq 0)
ROUT: Wed Jul 25 14:40:12 2012 [notice] [127.0.0.1, port=60580] connect
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'roster' to chain 'in-sess' (not added yet)
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature jabber:iq:roster
SM : Wed Jul 25 14:40:12 2012 [notice] module 'roster' added to chain 'in-sess' (order 3 index 4 seq 0)
ROUT: sx (sx.c:61) allocated new sx for 6
S2S : sx (sx.c:61) allocated new sx for 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:1115 new component (0xa8a7000) "127.0.0.1:60580"
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'vacation' to chain 'in-sess' (not added yet)
S2S : sx (client.c:122) doing client init for sx 6
ROUT: sx (server.c:237) doing server init for sx 6
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature http://jabber.org/protocol/vacation
S2S : sx (client.c:138) stream request: ns (null) to (null) from (null) version 1.0
ROUT: sx (server.c:252) waiting for stream header
SM : Wed Jul 25 14:40:12 2012 [notice] module 'vacation' added to chain 'in-sess' (order 4 index 5 seq 0)
S2S : sx (client.c:168) prepared stream header: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
ROUT: sx (server.c:255) tag 6 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'iq-vcard' to chain 'in-sess' (not added yet)
S2S : sx (client.c:175) tag 6 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature vcard-temp
S2S : Wed Jul 25 14:40:12 2012 router.c:39 want write
ROUT: Wed Jul 25 14:40:12 2012 main.c:482 running time checks
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-vcard' added to chain 'in-sess' (order 5 index 6 seq 0)
S2S : Wed Jul 25 14:40:12 2012 router.c:308 write action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 main.c:487 next time check at 1343252472
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'iq-ping' to chain 'in-sess' (not added yet)
S2S : sx (io.c:328) 6 ready for writing
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 6
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature urn:xmpp:ping
S2S : sx (io.c:286) encoding 98 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
ROUT: sx (io.c:191) 6 ready for reading
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-ping' added to chain 'in-sess' (order 6 index 7 seq 0)
S2S : sx (chain.c:79) calling io write chain
ROUT: sx (io.c:197) tag 6 event 2 data 0xa8a8e70
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'iq-private' to chain 'in-sess' (not added yet)
S2S : sx (io.c:349) handing app 98 bytes to write
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 6
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature jabber:iq:private
S2S : sx (io.c:350) tag 6 event 3 data 0x1d8df580
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 98 bytes
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-private' added to chain 'in-sess' (order 7 index 8 seq 0)
S2S : Wed Jul 25 14:40:12 2012 router.c:76 writing to 6
ROUT: sx (io.c:216) passed 98 read bytes
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'disco' to chain 'in-sess' (not added yet)
S2S : Wed Jul 25 14:40:12 2012 router.c:80 98 bytes written
ROUT: sx (chain.c:93) calling io read chain
SM : Wed Jul 25 14:40:12 2012 mod_disco.c:618 disco module init
S2S : sx (client.c:103) 6 state change from 0 to 2
ROUT: sx (io.c:240) decoded read data (98 bytes): <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
SM : Wed Jul 25 14:40:12 2012 mod_disco.c:638 agents compat enabled
S2S : sx (client.c:105) stream header sent, waiting for reply
ROUT: sx (server.c:119) stream request: to (null) from (null) version 1.0
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature http://jabber.org/protocol/disco#info
S2S : sx (io.c:383) tag 6 event 0 data 0x0
ROUT: sx (server.c:134) 6 state change from 0 to 1
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature http://jabber.org/protocol/disco#items
S2S : Wed Jul 25 14:40:12 2012 router.c:34 want read
ROUT: sx (server.c:152) stream id is 7bmc9draafxveyjfacsb35rmn65f36vbhinrve26
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature jabber:iq:agents
S2S : Wed Jul 25 14:40:12 2012 main.c:1038 running time checks
ROUT: sx (server.c:182) prepared stream response: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
SM : Wed Jul 25 14:40:12 2012 mod_disco.c:94 unifying lists
S2S : Wed Jul 25 14:40:12 2012 main.c:1043 next time check at 1343252472
ROUT: sx (io.c:256) tag 6 event 1 data 0x0
SM : Wed Jul 25 14:40:12 2012 [notice] module 'disco' added to chain 'in-sess' (order 8 index 9 seq 0)
S2S : Wed Jul 25 14:40:12 2012 main.c:1048 running dns expiry
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'amp' to chain 'in-sess' (not added yet)
S2S : Wed Jul 25 14:40:12 2012 main.c:1053 next dns expiry at 1343252712
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 6
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature http://jabber.org/protocol/amp
S2S : Wed Jul 25 14:40:12 2012 router.c:297 read action on fd 6
ROUT: sx (io.c:328) 6 ready for writing
SM : Wed Jul 25 14:40:12 2012 [notice] module 'amp' added to chain 'in-sess' (order 9 index 10 seq 0)
S2S : sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:286) encoding 144 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'offline' to chain 'in-sess' (not added yet)
S2S : sx (io.c:197) tag 6 event 2 data 0x1d8df580
ROUT: sx (chain.c:79) calling io write chain
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature msgoffline
S2S : Wed Jul 25 14:40:12 2012 router.c:44 reading from 6
ROUT: sx (io.c:349) handing app 144 bytes to write
SM : Wed Jul 25 14:40:12 2012 [notice] module 'offline' added to chain 'in-sess' (order 10 index 11 seq 0)
S2S : Wed Jul 25 14:40:12 2012 router.c:69 read 326 bytes
ROUT: sx (io.c:350) tag 6 event 3 data 0xa8a92b0
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'announce' to chain 'in-sess' (not added yet)
S2S : sx (io.c:216) passed 326 read bytes
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 6
SM : Wed Jul 25 14:40:12 2012 [notice] module 'announce' added to chain 'in-sess' (order 11 index 12 seq 0)
S2S : sx (chain.c:93) calling io read chain
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 144 bytes written
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'presence' to chain 'in-sess' (not added yet)
S2S : sx (io.c:240) decoded read data (326 bytes): <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'><stream:features xmlns:stream='http://etherx.jabber.org/streams'><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism></mechanisms></stream:features>
ROUT: sx (server.c:29) stream established
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature presence
S2S : sx (client.c:70) stream response: to (null) from (null) version 1.0 id 7bmc9draafxveyjfacsb35rmn65f36vbhinrve26
ROUT: sx (server.c:39) 6 state change from 1 to 3
SM : Wed Jul 25 14:40:12 2012 [notice] module 'presence' added to chain 'in-sess' (order 12 index 13 seq 0)
S2S : sx (client.c:85) 6 state change from 2 to 3
ROUT: sx (server.c:40) tag 6 event 4 data 0x0
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'deliver' to chain 'in-sess' (not added yet)
S2S : sx (client.c:86) tag 6 event 4 data 0x0
ROUT: sx (server.c:45) building features nad
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature message
S2S : sx (io.c:92) completed nad: <stream:features xmlns:stream='http://etherx.jabber.org/streams'><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism></mechanisms></stream:features>
ROUT: sx (sasl_gsasl.c:357) offering sasl mechanisms
SM : Wed Jul 25 14:40:12 2012 [notice] module 'deliver' added to chain 'in-sess' (order 13 index 14 seq 0)
S2S : sx (chain.c:119) calling nad read chain
ROUT: sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 5
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'out-sess'
S2S : sx (io.c:156) tag 6 event 6 data 0x1d8e1110
ROUT: sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 6
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'in-router'
S2S : sx (sasl_gsasl.c:1034) sending auth request to server, mech 'DIGEST-MD5':
ROUT: sx (sasl_gsasl.c:377) offering mechanism: DIGEST-MD5
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'session' to chain 'in-router' (not added yet)
S2S : sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:383) tag 6 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 [notice] module 'session' added to chain 'in-router' (order 0 index 15 seq 0)
S2S : sx (io.c:406) queueing for write: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : Wed Jul 25 14:40:12 2012 [notice] module 'validate' added to chain 'in-router' (order 1 index 2 seq 1)
S2S : sx (io.c:429) tag 6 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 6
SM : Wed Jul 25 14:40:12 2012 [notice] module 'presence' added to chain 'in-router' (order 2 index 13 seq 1)
S2S : Wed Jul 25 14:40:12 2012 router.c:39 want write
ROUT: sx (io.c:328) 6 ready for writing
S2S : Wed Jul 25 14:40:12 2012 router.c:308 write action on fd 6
ROUT: sx (io.c:286) encoding 182 bytes for writing: <stream:features xmlns:stream='http://etherx.jabber.org/streams'><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism></mechanisms></stream:features>
S2S : sx (io.c:328) 6 ready for writing
ROUT: sx (chain.c:79) calling io write chain
S2S : sx (io.c:286) encoding 71 bytes for writing: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
ROUT: sx (io.c:349) handing app 182 bytes to write
S2S : sx (chain.c:79) calling io write chain
ROUT: sx (io.c:350) tag 6 event 3 data 0xa8a92b0
S2S : sx (io.c:349) handing app 71 bytes to write
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 6
S2S : sx (io.c:350) tag 6 event 3 data 0x1d8dfa60
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 182 bytes written
S2S : Wed Jul 25 14:40:12 2012 router.c:76 writing to 6
ROUT: sx (io.c:383) tag 6 event 0 data 0x0
S2S : Wed Jul 25 14:40:12 2012 router.c:80 71 bytes written
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
S2S : sx (io.c:383) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 6
S2S : Wed Jul 25 14:40:12 2012 router.c:34 want read
ROUT: sx (io.c:191) 6 ready for reading
S2S : sx (io.c:431) tag 6 event 0 data 0x0
ROUT: sx (io.c:197) tag 6 event 2 data 0xa8a92b0
S2S : Wed Jul 25 14:40:12 2012 router.c:34 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 6
S2S : Wed Jul 25 14:40:12 2012 router.c:297 read action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 71 bytes
S2S : sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:216) passed 71 read bytes
S2S : sx (io.c:197) tag 6 event 2 data 0x1d8dfa60
ROUT: sx (chain.c:93) calling io read chain
S2S : Wed Jul 25 14:40:12 2012 router.c:44 reading from 6
ROUT: sx (io.c:240) decoded read data (71 bytes): <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
S2S : Wed Jul 25 14:40:12 2012 router.c:69 read 204 bytes
ROUT: sx (io.c:92) completed nad: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
S2S : sx (io.c:216) passed 204 read bytes
ROUT: sx (chain.c:119) calling nad read chain
S2S : sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:417) auth request from client (mechanism=DIGEST-MD5)
S2S : sx (io.c:240) decoded read data (204 bytes): <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9IkwySGdFMDBmd1VWUm51VkJLTnpCSUE9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
ROUT: sx (sasl_gsasl.c:472) sasl context initialised for 6
S2S : sx (io.c:92) completed nad: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9IkwySGdFMDBmd1VWUm51VkJLTnpCSUE9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
ROUT: sx (sasl_gsasl.c:562) sasl handshake in progress (challenge: realm="jabberd-router", nonce="L2HgE00fwUVRnuVBKNzBIA==", qop="auth", charset=utf-8, algorithm=md5-sess)
S2S : sx (chain.c:119) calling nad read chain
ROUT: sx (chain.c:106) calling nad write chain
S2S : sx (sasl_gsasl.c:596) data from client
ROUT: sx (io.c:406) queueing for write: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9IkwySGdFMDBmd1VWUm51VkJLTnpCSUE9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
S2S : sx (sasl_gsasl.c:602) decoded data: realm="jabberd-router", nonce="L2HgE00fwUVRnuVBKNzBIA==", qop="auth", charset=utf-8, algorithm=md5-sess
ROUT: sx (io.c:256) tag 6 event 1 data 0x0
S2S : sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 2
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
S2S : sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 11
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 6
S2S : sx (sasl_gsasl.c:610) sasl handshake in progress (response: username="jabberd", realm="jabberd-router", nonce="L2HgE00fwUVRnuVBKNzBIA==", cnonce="hb9zEWDsMbT3BDWCV3eHwQ==", nc=00000001, qop=auth, digest-uri="jabberd-router/engdev1", response=73f2c78e49b6316f315a0e06ba1d0c8a, charset=utf-8)
ROUT: sx (io.c:328) 6 ready for writing
S2S : sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:286) encoding 204 bytes for writing: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9IkwySGdFMDBmd1VWUm51VkJLTnpCSUE9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
S2S : sx (io.c:406) queueing for write: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0iTDJIZ0UwMGZ3VVZSbnVWQktOekJJQT09IiwgY25vbmNlPSJoYjl6RVdEc01iVDNCRFdDVjNlSHdRPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2VuZ2RldjEiLCByZXNwb25zZT03M2YyYzc4ZTQ5YjYzMTZmMzE1YTBlMDZiYTFkMGM4YSwgY2hhcnNldD11dGYtOA==</response>
ROUT: sx (chain.c:79) calling io write chain
S2S : sx (io.c:256) tag 6 event 1 data 0x0
ROUT: sx (io.c:349) handing app 204 bytes to write
S2S : Wed Jul 25 14:40:12 2012 router.c:39 want write
ROUT: sx (io.c:350) tag 6 event 3 data 0xb4013b0
S2S : Wed Jul 25 14:40:12 2012 router.c:308 write action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 6
S2S : sx (io.c:328) 6 ready for writing
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 204 bytes written
S2S : sx (io.c:286) encoding 370 bytes for writing: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0iTDJIZ0UwMGZ3VVZSbnVWQktOekJJQT09IiwgY25vbmNlPSJoYjl6RVdEc01iVDNCRFdDVjNlSHdRPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2VuZ2RldjEiLCByZXNwb25zZT03M2YyYzc4ZTQ5YjYzMTZmMzE1YTBlMDZiYTFkMGM4YSwgY2hhcnNldD11dGYtOA==</response>
ROUT: sx (io.c:383) tag 6 event 0 data 0x0
S2S : sx (chain.c:79) calling io write chain
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
S2S : sx (io.c:349) handing app 370 bytes to write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 6
S2S : sx (io.c:350) tag 6 event 3 data 0x1d8e11a0
ROUT: sx (io.c:191) 6 ready for reading
S2S : Wed Jul 25 14:40:12 2012 router.c:76 writing to 6
ROUT: sx (io.c:197) tag 6 event 2 data 0xb4013b0
S2S : Wed Jul 25 14:40:12 2012 router.c:80 370 bytes written
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 6
S2S : sx (io.c:383) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 370 bytes
S2S : Wed Jul 25 14:40:12 2012 router.c:34 want read
ROUT: sx (io.c:216) passed 370 read bytes
S2S : Wed Jul 25 14:40:12 2012 router.c:297 read action on fd 6
ROUT: sx (chain.c:93) calling io read chain
S2S : sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:240) decoded read data (370 bytes): <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0iTDJIZ0UwMGZ3VVZSbnVWQktOekJJQT09IiwgY25vbmNlPSJoYjl6RVdEc01iVDNCRFdDVjNlSHdRPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2VuZ2RldjEiLCByZXNwb25zZT03M2YyYzc4ZTQ5YjYzMTZmMzE1YTBlMDZiYTFkMGM4YSwgY2hhcnNldD11dGYtOA==</response>
S2S : sx (io.c:197) tag 6 event 2 data 0x1d8e11a0
ROUT: sx (io.c:92) completed nad: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0iTDJIZ0UwMGZ3VVZSbnVWQktOekJJQT09IiwgY25vbmNlPSJoYjl6RVdEc01iVDNCRFdDVjNlSHdRPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2VuZ2RldjEiLCByZXNwb25zZT03M2YyYzc4ZTQ5YjYzMTZmMzE1YTBlMDZiYTFkMGM4YSwgY2hhcnNldD11dGYtOA==</response>
S2S : Wed Jul 25 14:40:12 2012 router.c:44 reading from 6
ROUT: sx (chain.c:119) calling nad read chain
S2S : Wed Jul 25 14:40:12 2012 router.c:69 read 120 bytes
ROUT: sx (sasl_gsasl.c:528) response from client (decoded: username="jabberd", realm="jabberd-router", nonce="L2HgE00fwUVRnuVBKNzBIA==", cnonce="hb9zEWDsMbT3BDWCV3eHwQ==", nc=00000001, qop=auth, digest-uri="jabberd-router/engdev1", response=73f2c78e49b6316f315a0e06ba1d0c8a, charset=utf-8)
S2S : sx (io.c:216) passed 120 read bytes
ROUT: sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 12
S2S : sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 3
S2S : sx (io.c:240) decoded read data (120 bytes): <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD05MmQ3MmEzYzZmNTQ0ZDNhODBmYWFmZTMxMzAzZjQxYw==</challenge>
ROUT: Wed Jul 25 14:40:12 2012 main.c:225 sx sasl callback: get pass (authnid=jabberd, realm=jabberd-router)
S2S : sx (io.c:92) completed nad: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD05MmQ3MmEzYzZmNTQ0ZDNhODBmYWFmZTMxMzAzZjQxYw==</challenge>
ROUT: sx (sasl_gsasl.c:562) sasl handshake in progress (challenge: rspauth=92d72a3c6f544d3a80faafe31303f41c)
S2S : sx (chain.c:119) calling nad read chain
ROUT: sx (chain.c:106) calling nad write chain
S2S : sx (sasl_gsasl.c:596) data from client
ROUT: sx (io.c:406) queueing for write: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD05MmQ3MmEzYzZmNTQ0ZDNhODBmYWFmZTMxMzAzZjQxYw==</challenge>
S2S : sx (sasl_gsasl.c:602) decoded data: rspauth=92d72a3c6f544d3a80faafe31303f41c
ROUT: sx (io.c:256) tag 6 event 1 data 0x0
S2S : sx (sasl_gsasl.c:610) sasl handshake in progress (response: )
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
S2S : sx (chain.c:106) calling nad write chain
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 6
S2S : sx (io.c:406) queueing for write: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
ROUT: sx (io.c:328) 6 ready for writing
S2S : sx (io.c:256) tag 6 event 1 data 0x0
ROUT: sx (io.c:286) encoding 120 bytes for writing: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD05MmQ3MmEzYzZmNTQ0ZDNhODBmYWFmZTMxMzAzZjQxYw==</challenge>
S2S : Wed Jul 25 14:40:12 2012 router.c:39 want write
ROUT: sx (chain.c:79) calling io write chain
S2S : Wed Jul 25 14:40:12 2012 router.c:308 write action on fd 6
ROUT: sx (io.c:349) handing app 120 bytes to write
S2S : sx (io.c:328) 6 ready for writing
ROUT: sx (io.c:350) tag 6 event 3 data 0xa8aa870
S2S : sx (io.c:286) encoding 52 bytes for writing: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 6
S2S : sx (chain.c:79) calling io write chain
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 120 bytes written
S2S : sx (io.c:349) handing app 52 bytes to write
ROUT: sx (io.c:383) tag 6 event 0 data 0x0
S2S : sx (io.c:350) tag 6 event 3 data 0x1d8e1170
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
S2S : Wed Jul 25 14:40:12 2012 router.c:76 writing to 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 6
S2S : Wed Jul 25 14:40:12 2012 router.c:80 52 bytes written
ROUT: sx (io.c:191) 6 ready for reading
S2S : sx (io.c:383) tag 6 event 0 data 0x0
ROUT: sx (io.c:197) tag 6 event 2 data 0xa8aa870
S2S : Wed Jul 25 14:40:12 2012 router.c:34 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 6
S2S : Wed Jul 25 14:40:12 2012 router.c:297 read action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 52 bytes
S2S : sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:216) passed 52 read bytes
S2S : sx (io.c:197) tag 6 event 2 data 0x1d8e1170
ROUT: sx (chain.c:93) calling io read chain
S2S : Wed Jul 25 14:40:12 2012 router.c:44 reading from 6
ROUT: sx (io.c:240) decoded read data (52 bytes): <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
S2S : Wed Jul 25 14:40:12 2012 router.c:69 read 51 bytes
ROUT: sx (io.c:92) completed nad: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
S2S : sx (io.c:216) passed 51 read bytes
ROUT: sx (chain.c:119) calling nad read chain
S2S : sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:528) response from client (decoded: )
S2S : sx (io.c:240) decoded read data (51 bytes): <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
ROUT: sx (sasl_gsasl.c:536) sasl handshake completed
S2S : sx (io.c:92) completed nad: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
ROUT: sx (chain.c:106) calling nad write chain
S2S : sx (chain.c:119) calling nad read chain
ROUT: sx (io.c:406) queueing for write: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
S2S : sx (sasl_gsasl.c:728) sasl handshake completed, resetting
ROUT: sx (io.c:256) tag 6 event 1 data 0x0
S2S : sx (sx.c:154) resetting stream state
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
S2S : sx (sx.c:78) freeing sx for 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 6
S2S : sx (sx.c:61) allocated new sx for 6
ROUT: sx (io.c:328) 6 ready for writing
S2S : sx (sx.c:211) finished resetting stream state
ROUT: sx (io.c:286) encoding 51 bytes for writing: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
S2S : sx (sasl_gsasl.c:743) restarting stream with sasl layer established
ROUT: sx (chain.c:79) calling io write chain
S2S : sx (client.c:122) doing client init for sx 6
ROUT: sx (io.c:349) handing app 51 bytes to write
S2S : sx (client.c:138) stream request: ns (null) to (null) from (null) version 1.0
ROUT: sx (io.c:350) tag 6 event 3 data 0xa8aa8a0
S2S : sx (client.c:168) prepared stream header: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 6
S2S : sx (client.c:175) tag 6 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 51 bytes written
S2S : Wed Jul 25 14:40:12 2012 router.c:39 want write
ROUT: sx (chain.c:28) adding io plugin
S2S : Wed Jul 25 14:40:12 2012 router.c:308 write action on fd 6
ROUT: sx (sasl_gsasl.c:398) auth completed, resetting
S2S : sx (io.c:328) 6 ready for writing
ROUT: sx (sx.c:154) resetting stream state
S2S : sx (io.c:286) encoding 98 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
ROUT: sx (sx.c:78) freeing sx for 6
S2S : sx (chain.c:79) calling io write chain
ROUT: sx (sx.c:61) allocated new sx for 6
S2S : sx (io.c:349) handing app 98 bytes to write
ROUT: sx (sx.c:211) finished resetting stream state
S2S : sx (io.c:350) tag 6 event 3 data 0x1d8e1590
ROUT: sx (server.c:237) doing server init for sx 6
S2S : Wed Jul 25 14:40:12 2012 router.c:76 writing to 6
ROUT: sx (server.c:252) waiting for stream header
S2S : Wed Jul 25 14:40:12 2012 router.c:80 98 bytes written
ROUT: sx (server.c:255) tag 6 event 0 data 0x0
S2S : sx (client.c:103) 6 state change from 0 to 2
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
S2S : sx (client.c:105) stream header sent, waiting for reply
ROUT: sx (io.c:383) tag 6 event 0 data 0x0
S2S : sx (io.c:383) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 6
ROUT: sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:197) tag 6 event 2 data 0xa8aa8a0
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 98 bytes
ROUT: sx (io.c:216) passed 98 read bytes
ROUT: sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:248) doing sasl decode
ROUT: sx (sasl_gsasl.c:264) 98 bytes decoded from sasl channel
ROUT: sx (io.c:240) decoded read data (98 bytes): <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
ROUT: sx (server.c:119) stream request: to (null) from (null) version 1.0
ROUT: sx (server.c:134) 6 state change from 0 to 1
ROUT: sx (server.c:152) stream id is 7bmc9draafxveyjfacsb35rmn65f36vbhinrve26
ROUT: sx (server.c:182) prepared stream response: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
ROUT: sx (io.c:256) tag 6 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 6
ROUT: sx (io.c:328) 6 ready for writing
ROUT: sx (io.c:286) encoding 144 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 144 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 144 bytes to write
ROUT: sx (io.c:350) tag 6 event 3 data 0xa8aadc0
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 144 bytes written
ROUT: sx (server.c:29) stream established
ROUT: sx (sx.c:140) authenticating stream (method=SASL/DIGEST-MD5; id=jabberd@jabberd-router)
ROUT: sx (sx.c:145) 6 state change from 1 to 4
ROUT: sx (sx.c:146) tag 6 event 5 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 [notice] [127.0.0.1, port=60580] authenticated as jabberd@jabberd-router
ROUT: sx (server.c:45) building features nad
S2S : Wed Jul 25 14:40:12 2012 router.c:34 want read
ROUT: sx (sasl_gsasl.c:341) already auth'd, not offering sasl mechanisms
S2S : Wed Jul 25 14:40:12 2012 router.c:297 read action on fd 6
ROUT: sx (io.c:383) tag 6 event 0 data 0x0
S2S : sx (io.c:191) 6 ready for reading
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
S2S : sx (io.c:197) tag 6 event 2 data 0x1d8e1590
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 6
S2S : Wed Jul 25 14:40:12 2012 router.c:44 reading from 6
ROUT: sx (io.c:328) 6 ready for writing
S2S : Wed Jul 25 14:40:12 2012 router.c:69 read 144 bytes
ROUT: sx (io.c:286) encoding 66 bytes for writing: <stream:features xmlns:stream='http://etherx.jabber.org/streams'/>
S2S : sx (io.c:216) passed 144 read bytes
ROUT: sx (chain.c:79) calling io write chain
S2S : sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
S2S : sx (io.c:240) decoded read data (144 bytes): <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
ROUT: sx (sasl_gsasl.c:236) 66 bytes encoded for sasl channel
S2S : sx (client.c:70) stream response: to (null) from (null) version 1.0 id 7bmc9draafxveyjfacsb35rmn65f36vbhinrve26
ROUT: sx (io.c:349) handing app 66 bytes to write
S2S : sx (sx.c:140) authenticating stream (method=SASL/DIGEST-MD5; id=jabberd@jabberd-router)
ROUT: sx (io.c:350) tag 6 event 3 data 0xa8aadc0
S2S : sx (sx.c:145) 6 state change from 2 to 4
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 6
S2S : sx (sx.c:146) tag 6 event 5 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 66 bytes written
S2S : Wed Jul 25 14:40:12 2012 [notice] connection to router established
ROUT: sx (io.c:383) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 6
C2S : Wed Jul 25 14:40:12 2012 [info] loading 'mysql' authreg module
C2S : Wed Jul 25 14:40:12 2012 authreg.c:73 preloaded module 'mysql' (not initialized yet)
C2S : Wed Jul 25 14:40:12 2012 authreg_mysql.c:518 SQL to create account: INSERT INTO `authreg` ( `username`, `realm` ) VALUES ( '%s', '%s' )
C2S : Wed Jul 25 14:40:12 2012 authreg_mysql.c:519 SQL to query user information: SELECT `password` FROM `authreg` WHERE `username` = '%s' AND `realm` = '%s'
C2S : Wed Jul 25 14:40:12 2012 authreg_mysql.c:520 SQL to set password: UPDATE `authreg` SET `password` = '%s' WHERE `username` = '%s' AND `realm` = '%s'
C2S : Wed Jul 25 14:40:12 2012 authreg_mysql.c:521 SQL to delete account: DELETE FROM `authreg` WHERE `username` = '%s' AND `realm` = '%s'
C2S : Wed Jul 25 14:40:12 2012 authreg_mysql.c:539 mysql connecting as 'jabberd2' to database 'jabberd2' on localhost:3306
SM : Wed Jul 25 14:40:12 2012 [notice] module 'privacy' added to chain 'in-router' (order 3 index 3 seq 1)
ROUT: sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:197) tag 6 event 2 data 0xa8aadc0
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 91 bytes
ROUT: sx (io.c:216) passed 91 read bytes
ROUT: sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:248) doing sasl decode
ROUT: sx (sasl_gsasl.c:264) 91 bytes decoded from sasl channel
ROUT: sx (io.c:240) decoded read data (91 bytes): <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='s2s'><default/></bind>
ROUT: sx (io.c:92) completed nad: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='s2s'><default/></bind>
ROUT: sx (chain.c:119) calling nad read chain
ROUT: sx (io.c:156) tag 6 event 6 data 0xa8ab7e0
ROUT: Wed Jul 25 14:40:12 2012 aci.c:96 checking for 'jabberd' in acl 'all'
ROUT: Wed Jul 25 14:40:12 2012 aci.c:96 checking for 'jabberd' in acl 'all'
ROUT: Wed Jul 25 14:40:12 2012 [notice] [s2s] set as default route
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'out-router'
SM : Wed Jul 25 14:40:12 2012 [notice] module 'privacy' added to chain 'out-router' (order 0 index 3 seq 2)
ROUT: Wed Jul 25 14:40:12 2012 [notice] [s2s] online (bound to 127.0.0.1, port 60580)
C2S : Wed Jul 25 14:40:12 2012 [notice] initialized auth module 'mysql'
C2S : sx (ssl.c:818) initialising ssl plugin
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'pkt-sm'
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-last' added to chain 'pkt-sm' (order 0 index 1 seq 1)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-ping' added to chain 'pkt-sm' (order 1 index 7 seq 1)
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'iq-time' to chain 'pkt-sm' (not added yet)
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature jabber:iq:time
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature urn:xmpp:time
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-time' added to chain 'pkt-sm' (order 2 index 16 seq 0)
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'iq-version' to chain 'pkt-sm' (not added yet)
SM : Wed Jul 25 14:40:12 2012 feature.c:39 registering feature jabber:iq:version
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-version' added to chain 'pkt-sm' (order 3 index 17 seq 0)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'amp' added to chain 'pkt-sm' (order 4 index 10 seq 1)
C2S : sx (ssl.c:918) No CA chain specified. Loading SSL default CA certs: /etc/ssl/certs
C2S : sx (ssl.c:950) setting ssl context '*' verify mode to 00
C2S : sx (ssl.c:971) ssl context '*' initialised; certificate and key loaded from /usr/local/etc/server.pem
C2S : sx (env.c:75) plugin initialised (index 0)
C2S : Wed Jul 25 14:40:12 2012 ack.c:104 initialising stanza acknowledgements sx plugin
C2S : sx (env.c:75) plugin initialised (index 1)
C2S : Wed Jul 25 14:40:12 2012 address.c:43 initialising address sx plugin
C2S : sx (env.c:75) plugin initialised (index 2)
C2S : sx (sasl_gsasl.c:933) initialising sasl plugin
C2S : sx (sasl_gsasl.c:961) sasl context initialised
C2S : sx (env.c:75) plugin initialised (index 3)
C2S : Wed Jul 25 14:40:12 2012 bind.c:72 initialising resource bind sx plugin
C2S : sx (env.c:75) plugin initialised (index 4)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'disco' added to chain 'pkt-sm' (order 5 index 9 seq 1)
C2S : Wed Jul 25 14:40:12 2012 [notice] [engdev1.remotewd2.com] configured; realm=engdev1.remotewd2.com, registration enabled, using PEM:Default
SM : Wed Jul 25 14:40:12 2012 [notice] module 'announce' added to chain 'pkt-sm' (order 6 index 12 seq 1)
C2S : Wed Jul 25 14:40:12 2012 [notice] attempting connection to router at 127.0.0.1, port=5347
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0'><default/></bind>
ROUT: sx (io.c:429) tag 6 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 6
ROUT: sx (io.c:328) 6 ready for writing
ROUT: sx (io.c:286) encoding 80 bytes for writing: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0'><default/></bind>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 80 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 80 bytes to write
ROUT: sx (io.c:350) tag 6 event 3 data 0xa8ab870
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 80 bytes written
ROUT: sx (io.c:383) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:431) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:55 advertising s2s to all routes (unavail=0)
ROUT: Wed Jul 25 14:40:12 2012 router.c:1085 accept action on fd 7
C2S : sx (sx.c:61) allocated new sx for 6
C2S : sx (client.c:122) doing client init for sx 6
C2S : sx (client.c:138) stream request: ns (null) to (null) from (null) version 1.0
C2S : Wed Jul 25 14:40:12 2012 ack.c:30 hacking ack namespace decl onto stream header
C2S : sx (client.c:168) prepared stream header: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xmlns:ack='http://www.xmpp.org/extensions/xep-0198.html#ns'>
C2S : sx (client.c:175) tag 6 event 1 data 0x0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:716 want write
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1373 write action on fd 6
C2S : sx (io.c:328) 6 ready for writing
C2S : sx (io.c:286) encoding 158 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xmlns:ack='http://www.xmpp.org/extensions/xep-0198.html#ns'>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (io.c:349) handing app 158 bytes to write
C2S : sx (io.c:350) tag 6 event 3 data 0x1063ff20
C2S : Wed Jul 25 14:40:12 2012 c2s.c:753 writing to 6
C2S : Wed Jul 25 14:40:12 2012 c2s.c:757 158 bytes written
C2S : sx (client.c:103) 6 state change from 0 to 2
C2S : sx (client.c:105) stream header sent, waiting for reply
C2S : sx (io.c:383) tag 6 event 0 data 0x0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:711 want read
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'help' to chain 'pkt-sm' (not added yet)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'help' added to chain 'pkt-sm' (order 7 index 18 seq 0)
ROUT: Wed Jul 25 14:40:12 2012 [notice] [127.0.0.1, port=60581] connect
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1362 read action on fd 6
C2S : sx (io.c:191) 6 ready for reading
C2S : sx (io.c:197) tag 6 event 2 data 0x1063ff20
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'echo' to chain 'pkt-sm' (not added yet)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'echo' added to chain 'pkt-sm' (order 8 index 19 seq 0)
C2S : Wed Jul 25 14:40:12 2012 c2s.c:721 reading from 6
C2S : Wed Jul 25 14:40:12 2012 c2s.c:746 read 326 bytes
C2S : sx (io.c:216) passed 326 read bytes
C2S : sx (chain.c:93) calling io read chain
C2S : sx (io.c:240) decoded read data (326 bytes): <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'><stream:features xmlns:stream='http://etherx.jabber.org/streams'><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism></mechanisms></stream:features>
C2S : sx (client.c:70) stream response: to (null) from (null) version 1.0 id 7bmc9draafxveyjfacsb35rmn65f36vbhinrve26
C2S : sx (client.c:85) 6 state change from 2 to 3
C2S : sx (client.c:86) tag 6 event 4 data 0x0
C2S : sx (io.c:92) completed nad: <stream:features xmlns:stream='http://etherx.jabber.org/streams'><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism></mechanisms></stream:features>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (io.c:156) tag 6 event 6 data 0x10672970
C2S : sx (sasl_gsasl.c:1034) sending auth request to server, mech 'DIGEST-MD5':
C2S : sx (chain.c:106) calling nad write chain
C2S : sx (io.c:406) queueing for write: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
C2S : sx (io.c:429) tag 6 event 1 data 0x0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:716 want write
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1373 write action on fd 6
C2S : sx (io.c:328) 6 ready for writing
C2S : sx (io.c:286) encoding 71 bytes for writing: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (io.c:349) handing app 71 bytes to write
C2S : sx (io.c:350) tag 6 event 3 data 0x106abb00
C2S : Wed Jul 25 14:40:12 2012 c2s.c:753 writing to 6
ROUT: sx (sx.c:61) allocated new sx for 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:1115 new component (0xa8a7c20) "127.0.0.1:60581"
ROUT: sx (server.c:237) doing server init for sx 7
ROUT: sx (server.c:252) waiting for stream header
ROUT: sx (server.c:255) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 7
ROUT: sx (io.c:191) 7 ready for reading
ROUT: sx (io.c:197) tag 7 event 2 data 0xa8ab810
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 158 bytes
ROUT: sx (io.c:216) passed 158 read bytes
ROUT: sx (chain.c:93) calling io read chain
ROUT: sx (io.c:240) decoded read data (158 bytes): <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xmlns:ack='http://www.xmpp.org/extensions/xep-0198.html#ns'>
ROUT: sx (server.c:119) stream request: to (null) from (null) version 1.0
ROUT: sx (server.c:134) 7 state change from 0 to 1
ROUT: sx (server.c:152) stream id is 7bmc9draafxveyjfacsb35rmn65f36vbhinrve26
ROUT: sx (server.c:182) prepared stream response: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
ROUT: sx (io.c:256) tag 7 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 7
ROUT: sx (io.c:328) 7 ready for writing
ROUT: sx (io.c:286) encoding 144 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (io.c:349) handing app 144 bytes to write
ROUT: sx (io.c:350) tag 7 event 3 data 0xb3ffdd0
SM : Wed Jul 25 14:40:12 2012 [notice] module 'status' added to chain 'pkt-sm' (order 9 index 0 seq 3)
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 144 bytes written
ROUT: sx (server.c:29) stream established
ROUT: sx (server.c:39) 7 state change from 1 to 3
ROUT: sx (server.c:40) tag 7 event 4 data 0x0
ROUT: sx (server.c:45) building features nad
ROUT: sx (sasl_gsasl.c:357) offering sasl mechanisms
ROUT: sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 5
ROUT: sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 6
ROUT: sx (sasl_gsasl.c:377) offering mechanism: DIGEST-MD5
ROUT: sx (io.c:383) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 7
ROUT: sx (io.c:328) 7 ready for writing
ROUT: sx (io.c:286) encoding 182 bytes for writing: <stream:features xmlns:stream='http://etherx.jabber.org/streams'><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism></mechanisms></stream:features>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (io.c:349) handing app 182 bytes to write
ROUT: sx (io.c:350) tag 7 event 3 data 0xb3ffdd0
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 182 bytes written
ROUT: sx (io.c:383) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 7
C2S : Wed Jul 25 14:40:12 2012 c2s.c:757 71 bytes written
C2S : sx (io.c:383) tag 6 event 0 data 0x0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:711 want read
C2S : sx (io.c:431) tag 6 event 0 data 0x0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:711 want read
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1362 read action on fd 6
C2S : sx (io.c:191) 6 ready for reading
C2S : sx (io.c:197) tag 6 event 2 data 0x106eba30
C2S : Wed Jul 25 14:40:12 2012 c2s.c:721 reading from 6
C2S : Wed Jul 25 14:40:12 2012 c2s.c:746 read 204 bytes
C2S : sx (io.c:216) passed 204 read bytes
C2S : sx (chain.c:93) calling io read chain
C2S : sx (io.c:240) decoded read data (204 bytes): <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9Im44OG5XK3A5YkhOa2VmQW81eGtCSVE9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
C2S : sx (io.c:92) completed nad: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9Im44OG5XK3A5YkhOa2VmQW81eGtCSVE9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (sasl_gsasl.c:596) data from client
C2S : sx (sasl_gsasl.c:602) decoded data: realm="jabberd-router", nonce="n88nW+p9bHNkefAo5xkBIQ==", qop="auth", charset=utf-8, algorithm=md5-sess
C2S : sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 2
C2S : sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 11
C2S : sx (sasl_gsasl.c:610) sasl handshake in progress (response: username="jabberd", realm="jabberd-router", nonce="n88nW+p9bHNkefAo5xkBIQ==", cnonce="2ERhRBw+jL3UvZv3pb/wlQ==", nc=00000001, qop=auth, digest-uri="jabberd-router/engdev1", response=fb13029428fe53b8acbce1c04d996d3e, charset=utf-8)
C2S : sx (chain.c:106) calling nad write chain
C2S : sx (io.c:406) queueing for write: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0ibjg4blcrcDliSE5rZWZBbzV4a0JJUT09IiwgY25vbmNlPSIyRVJoUkJ3K2pMM1V2WnYzcGIvd2xRPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2VuZ2RldjEiLCByZXNwb25zZT1mYjEzMDI5NDI4ZmU1M2I4YWNiY2UxYzA0ZDk5NmQzZSwgY2hhcnNldD11dGYtOA==</response>
C2S : sx (io.c:256) tag 6 event 1 data 0x0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:716 want write
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1373 write action on fd 6
C2S : sx (io.c:328) 6 ready for writing
C2S : sx (io.c:286) encoding 370 bytes for writing: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0ibjg4blcrcDliSE5rZWZBbzV4a0JJUT09IiwgY25vbmNlPSIyRVJoUkJ3K2pMM1V2WnYzcGIvd2xRPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2VuZ2RldjEiLCByZXNwb25zZT1mYjEzMDI5NDI4ZmU1M2I4YWNiY2UxYzA0ZDk5NmQzZSwgY2hhcnNldD11dGYtOA==</response>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (io.c:349) handing app 370 bytes to write
C2S : sx (io.c:350) tag 6 event 3 data 0x106abd60
C2S : Wed Jul 25 14:40:12 2012 c2s.c:753 writing to 6
SM : Wed Jul 25 14:40:12 2012 [notice] module 'presence' added to chain 'pkt-sm' (order 10 index 13 seq 2)
ROUT: sx (io.c:191) 7 ready for reading
ROUT: sx (io.c:197) tag 7 event 2 data 0xb3ffdd0
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 71 bytes
ROUT: sx (io.c:216) passed 71 read bytes
ROUT: sx (chain.c:93) calling io read chain
ROUT: sx (io.c:240) decoded read data (71 bytes): <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
ROUT: sx (io.c:92) completed nad: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
ROUT: sx (chain.c:119) calling nad read chain
ROUT: sx (sasl_gsasl.c:417) auth request from client (mechanism=DIGEST-MD5)
ROUT: sx (sasl_gsasl.c:472) sasl context initialised for 7
ROUT: sx (sasl_gsasl.c:562) sasl handshake in progress (challenge: realm="jabberd-router", nonce="n88nW+p9bHNkefAo5xkBIQ==", qop="auth", charset=utf-8, algorithm=md5-sess)
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9Im44OG5XK3A5YkhOa2VmQW81eGtCSVE9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
ROUT: sx (io.c:256) tag 7 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 7
ROUT: sx (io.c:328) 7 ready for writing
ROUT: sx (io.c:286) encoding 204 bytes for writing: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9Im44OG5XK3A5YkhOa2VmQW81eGtCSVE9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (io.c:349) handing app 204 bytes to write
ROUT: sx (io.c:350) tag 7 event 3 data 0xb406d90
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 204 bytes written
ROUT: sx (io.c:383) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 7
C2S : Wed Jul 25 14:40:12 2012 c2s.c:757 370 bytes written
C2S : sx (io.c:383) tag 6 event 0 data 0x0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:711 want read
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1362 read action on fd 6
C2S : sx (io.c:191) 6 ready for reading
C2S : sx (io.c:197) tag 6 event 2 data 0x106abd60
C2S : Wed Jul 25 14:40:12 2012 c2s.c:721 reading from 6
C2S : Wed Jul 25 14:40:12 2012 c2s.c:746 read 120 bytes
C2S : sx (io.c:216) passed 120 read bytes
C2S : sx (chain.c:93) calling io read chain
C2S : sx (io.c:240) decoded read data (120 bytes): <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD1lZTM4ZjdlNWU5NDQ0YzNhYjc1YjFiNzY4NmNiOGU0Mw==</challenge>
C2S : sx (io.c:92) completed nad: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD1lZTM4ZjdlNWU5NDQ0YzNhYjc1YjFiNzY4NmNiOGU0Mw==</challenge>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (sasl_gsasl.c:596) data from client
C2S : sx (sasl_gsasl.c:602) decoded data: rspauth=ee38f7e5e9444c3ab75b1b7686cb8e43
C2S : sx (sasl_gsasl.c:610) sasl handshake in progress (response: )
C2S : sx (chain.c:106) calling nad write chain
C2S : sx (io.c:406) queueing for write: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
C2S : sx (io.c:256) tag 6 event 1 data 0x0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:716 want write
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1373 write action on fd 6
C2S : sx (io.c:328) 6 ready for writing
C2S : sx (io.c:286) encoding 52 bytes for writing: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'pkt-user'
SM : Wed Jul 25 14:40:12 2012 [notice] module 'roster' added to chain 'pkt-user' (order 0 index 4 seq 1)
C2S : sx (chain.c:79) calling io write chain
C2S : sx (io.c:349) handing app 52 bytes to write
C2S : sx (io.c:350) tag 6 event 3 data 0x106abd60
C2S : Wed Jul 25 14:40:12 2012 c2s.c:753 writing to 6
ROUT: sx (io.c:191) 7 ready for reading
ROUT: sx (io.c:197) tag 7 event 2 data 0xb406d90
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 370 bytes
ROUT: sx (io.c:216) passed 370 read bytes
ROUT: sx (chain.c:93) calling io read chain
ROUT: sx (io.c:240) decoded read data (370 bytes): <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0ibjg4blcrcDliSE5rZWZBbzV4a0JJUT09IiwgY25vbmNlPSIyRVJoUkJ3K2pMM1V2WnYzcGIvd2xRPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2VuZ2RldjEiLCByZXNwb25zZT1mYjEzMDI5NDI4ZmU1M2I4YWNiY2UxYzA0ZDk5NmQzZSwgY2hhcnNldD11dGYtOA==</response>
ROUT: sx (io.c:92) completed nad: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0ibjg4blcrcDliSE5rZWZBbzV4a0JJUT09IiwgY25vbmNlPSIyRVJoUkJ3K2pMM1V2WnYzcGIvd2xRPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2VuZ2RldjEiLCByZXNwb25zZT1mYjEzMDI5NDI4ZmU1M2I4YWNiY2UxYzA0ZDk5NmQzZSwgY2hhcnNldD11dGYtOA==</response>
ROUT: sx (chain.c:119) calling nad read chain
ROUT: sx (sasl_gsasl.c:528) response from client (decoded: username="jabberd", realm="jabberd-router", nonce="n88nW+p9bHNkefAo5xkBIQ==", cnonce="2ERhRBw+jL3UvZv3pb/wlQ==", nc=00000001, qop=auth, digest-uri="jabberd-router/engdev1", response=fb13029428fe53b8acbce1c04d996d3e, charset=utf-8)
ROUT: sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 12
ROUT: sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 3
ROUT: Wed Jul 25 14:40:12 2012 main.c:225 sx sasl callback: get pass (authnid=jabberd, realm=jabberd-router)
ROUT: sx (sasl_gsasl.c:562) sasl handshake in progress (challenge: rspauth=ee38f7e5e9444c3ab75b1b7686cb8e43)
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD1lZTM4ZjdlNWU5NDQ0YzNhYjc1YjFiNzY4NmNiOGU0Mw==</challenge>
ROUT: sx (io.c:256) tag 7 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 7
ROUT: sx (io.c:328) 7 ready for writing
ROUT: sx (io.c:286) encoding 120 bytes for writing: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD1lZTM4ZjdlNWU5NDQ0YzNhYjc1YjFiNzY4NmNiOGU0Mw==</challenge>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (io.c:349) handing app 120 bytes to write
ROUT: sx (io.c:350) tag 7 event 3 data 0xb407ba0
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 120 bytes written
ROUT: sx (io.c:383) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 7
C2S : Wed Jul 25 14:40:12 2012 c2s.c:757 52 bytes written
C2S : sx (io.c:383) tag 6 event 0 data 0x0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:711 want read
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1362 read action on fd 6
C2S : sx (io.c:191) 6 ready for reading
C2S : sx (io.c:197) tag 6 event 2 data 0x106abd60
C2S : Wed Jul 25 14:40:12 2012 c2s.c:721 reading from 6
C2S : Wed Jul 25 14:40:12 2012 c2s.c:746 read 51 bytes
C2S : sx (io.c:216) passed 51 read bytes
C2S : sx (chain.c:93) calling io read chain
C2S : sx (io.c:240) decoded read data (51 bytes): <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
C2S : sx (io.c:92) completed nad: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (sasl_gsasl.c:728) sasl handshake completed, resetting
C2S : sx (sx.c:154) resetting stream state
C2S : sx (sx.c:78) freeing sx for 6
C2S : sx (sx.c:61) allocated new sx for 6
C2S : sx (sx.c:211) finished resetting stream state
C2S : sx (sasl_gsasl.c:743) restarting stream with sasl layer established
C2S : sx (client.c:122) doing client init for sx 6
C2S : sx (client.c:138) stream request: ns (null) to (null) from (null) version 1.0
C2S : Wed Jul 25 14:40:12 2012 ack.c:30 hacking ack namespace decl onto stream header
C2S : sx (client.c:168) prepared stream header: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xmlns:ack='http://www.xmpp.org/extensions/xep-0198.html#ns'>
C2S : sx (client.c:175) tag 6 event 1 data 0x0
SM : Wed Jul 25 14:40:12 2012 [notice] module 'presence' added to chain 'pkt-user' (order 1 index 13 seq 3)
C2S : Wed Jul 25 14:40:12 2012 c2s.c:716 want write
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1373 write action on fd 6
C2S : sx (io.c:328) 6 ready for writing
C2S : sx (io.c:286) encoding 158 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xmlns:ack='http://www.xmpp.org/extensions/xep-0198.html#ns'>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (io.c:349) handing app 158 bytes to write
C2S : sx (io.c:350) tag 6 event 3 data 0x106abb30
C2S : Wed Jul 25 14:40:12 2012 c2s.c:753 writing to 6
ROUT: sx (io.c:191) 7 ready for reading
ROUT: sx (io.c:197) tag 7 event 2 data 0xb407710
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 52 bytes
ROUT: sx (io.c:216) passed 52 read bytes
ROUT: sx (chain.c:93) calling io read chain
ROUT: sx (io.c:240) decoded read data (52 bytes): <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
ROUT: sx (io.c:92) completed nad: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
ROUT: sx (chain.c:119) calling nad read chain
ROUT: sx (sasl_gsasl.c:528) response from client (decoded: )
ROUT: sx (sasl_gsasl.c:536) sasl handshake completed
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
ROUT: sx (io.c:256) tag 7 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 7
ROUT: sx (io.c:328) 7 ready for writing
ROUT: sx (io.c:286) encoding 51 bytes for writing: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (io.c:349) handing app 51 bytes to write
ROUT: sx (io.c:350) tag 7 event 3 data 0xb406e30
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 51 bytes written
ROUT: sx (chain.c:28) adding io plugin
ROUT: sx (sasl_gsasl.c:398) auth completed, resetting
ROUT: sx (sx.c:154) resetting stream state
ROUT: sx (sx.c:78) freeing sx for 7
ROUT: sx (sx.c:61) allocated new sx for 7
ROUT: sx (sx.c:211) finished resetting stream state
ROUT: sx (server.c:237) doing server init for sx 7
ROUT: sx (server.c:252) waiting for stream header
ROUT: sx (server.c:255) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:383) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 7
C2S : Wed Jul 25 14:40:12 2012 c2s.c:757 158 bytes written
C2S : sx (client.c:103) 6 state change from 0 to 2
C2S : sx (client.c:105) stream header sent, waiting for reply
C2S : sx (io.c:383) tag 6 event 0 data 0x0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:711 want read
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1362 read action on fd 6
C2S : sx (io.c:191) 6 ready for reading
C2S : sx (io.c:197) tag 6 event 2 data 0x106abd90
C2S : Wed Jul 25 14:40:12 2012 c2s.c:721 reading from 6
C2S : Wed Jul 25 14:40:12 2012 c2s.c:746 read 144 bytes
C2S : sx (io.c:216) passed 144 read bytes
C2S : sx (chain.c:93) calling io read chain
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-vcard' added to chain 'pkt-user' (order 2 index 6 seq 1)
C2S : sx (io.c:240) decoded read data (144 bytes): <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
C2S : sx (client.c:70) stream response: to (null) from (null) version 1.0 id 7bmc9draafxveyjfacsb35rmn65f36vbhinrve26
C2S : sx (sx.c:140) authenticating stream (method=SASL/DIGEST-MD5; id=jabberd@jabberd-router)
C2S : sx (sx.c:145) 6 state change from 2 to 4
C2S : sx (sx.c:146) tag 6 event 5 data 0x0
ROUT: sx (io.c:191) 7 ready for reading
ROUT: sx (io.c:197) tag 7 event 2 data 0xb406e30
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 158 bytes
ROUT: sx (io.c:216) passed 158 read bytes
ROUT: sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:248) doing sasl decode
ROUT: sx (sasl_gsasl.c:264) 158 bytes decoded from sasl channel
ROUT: sx (io.c:240) decoded read data (158 bytes): <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' xmlns:ack='http://www.xmpp.org/extensions/xep-0198.html#ns'>
ROUT: sx (server.c:119) stream request: to (null) from (null) version 1.0
ROUT: sx (server.c:134) 7 state change from 0 to 1
ROUT: sx (server.c:152) stream id is 7bmc9draafxveyjfacsb35rmn65f36vbhinrve26
ROUT: sx (server.c:182) prepared stream response: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
ROUT: sx (io.c:256) tag 7 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 7
ROUT: sx (io.c:328) 7 ready for writing
ROUT: sx (io.c:286) encoding 144 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 144 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 144 bytes to write
ROUT: sx (io.c:350) tag 7 event 3 data 0xb3ffdd0
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 144 bytes written
ROUT: sx (server.c:29) stream established
ROUT: sx (sx.c:140) authenticating stream (method=SASL/DIGEST-MD5; id=jabberd@jabberd-router)
ROUT: sx (sx.c:145) 7 state change from 1 to 4
ROUT: sx (sx.c:146) tag 7 event 5 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 [notice] [127.0.0.1, port=60581] authenticated as jabberd@jabberd-router
SM : Wed Jul 25 14:40:12 2012 [notice] module 'amp' added to chain 'pkt-user' (order 3 index 10 seq 2)
C2S : Wed Jul 25 14:40:12 2012 [notice] connection to router established
C2S : Wed Jul 25 14:40:12 2012 c2s.c:793 requesting component bind for 'c2s'
C2S : sx (chain.c:106) calling nad write chain
C2S : sx (io.c:406) queueing for write: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='c2s'/>
C2S : sx (io.c:429) tag 6 event 1 data 0x0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:716 want write
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1373 write action on fd 6
C2S : sx (io.c:328) 6 ready for writing
C2S : sx (io.c:286) encoding 75 bytes for writing: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='c2s'/>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (io.c:349) handing app 75 bytes to write
C2S : sx (io.c:350) tag 6 event 3 data 0x10653c60
C2S : Wed Jul 25 14:40:12 2012 c2s.c:753 writing to 6
ROUT: sx (server.c:45) building features nad
ROUT: sx (sasl_gsasl.c:341) already auth'd, not offering sasl mechanisms
ROUT: sx (io.c:383) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 7
ROUT: sx (io.c:328) 7 ready for writing
ROUT: sx (io.c:286) encoding 66 bytes for writing: <stream:features xmlns:stream='http://etherx.jabber.org/streams'/>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 66 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 66 bytes to write
ROUT: sx (io.c:350) tag 7 event 3 data 0xb3ffdd0
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 66 bytes written
ROUT: sx (io.c:383) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 7
C2S : Wed Jul 25 14:40:12 2012 c2s.c:757 75 bytes written
C2S : sx (io.c:383) tag 6 event 0 data 0x0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:711 want read
C2S : sx (io.c:431) tag 6 event 0 data 0x0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:711 want read
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1362 read action on fd 6
C2S : sx (io.c:191) 6 ready for reading
C2S : sx (io.c:197) tag 6 event 2 data 0x106abb30
C2S : Wed Jul 25 14:40:12 2012 c2s.c:721 reading from 6
C2S : Wed Jul 25 14:40:12 2012 c2s.c:746 read 66 bytes
C2S : sx (io.c:216) passed 66 read bytes
C2S : sx (chain.c:93) calling io read chain
C2S : sx (io.c:240) decoded read data (66 bytes): <stream:features xmlns:stream='http://etherx.jabber.org/streams'/>
C2S : sx (io.c:92) completed nad: <stream:features xmlns:stream='http://etherx.jabber.org/streams'/>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (io.c:156) tag 6 event 6 data 0x1069adf0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:846 got a packet from router, but we're not online, dropping
SM : Wed Jul 25 14:40:12 2012 [notice] module 'deliver' added to chain 'pkt-user' (order 4 index 14 seq 1)
ROUT: sx (io.c:191) 7 ready for reading
ROUT: sx (io.c:197) tag 7 event 2 data 0xb3ffdd0
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 75 bytes
ROUT: sx (io.c:216) passed 75 read bytes
ROUT: sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:248) doing sasl decode
ROUT: sx (sasl_gsasl.c:264) 75 bytes decoded from sasl channel
ROUT: sx (io.c:240) decoded read data (75 bytes): <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='c2s'/>
ROUT: sx (io.c:92) completed nad: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='c2s'/>
ROUT: sx (chain.c:119) calling nad read chain
ROUT: sx (io.c:156) tag 7 event 6 data 0xb406f90
ROUT: Wed Jul 25 14:40:12 2012 aci.c:96 checking for 'jabberd' in acl 'all'
ROUT: Wed Jul 25 14:40:12 2012 [notice] [c2s] online (bound to 127.0.0.1, port 60581)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'vacation' added to chain 'pkt-user' (order 5 index 5 seq 1)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'offline' added to chain 'pkt-user' (order 6 index 11 seq 1)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-last' added to chain 'pkt-user' (order 7 index 1 seq 2)
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'pkt-router'
SM : Wed Jul 25 14:40:12 2012 [notice] module 'session' added to chain 'pkt-router' (order 0 index 15 seq 1)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'disco' added to chain 'pkt-router' (order 1 index 9 seq 2)
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'user-load'
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'active' to chain 'user-load' (not added yet)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'active' added to chain 'user-load' (order 0 index 20 seq 0)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'roster' added to chain 'user-load' (order 1 index 4 seq 2)
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'roster-publish' to chain 'user-load' (not added yet)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'roster-publish' added to chain 'user-load' (order 2 index 21 seq 0)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'privacy' added to chain 'user-load' (order 3 index 3 seq 3)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'vacation' added to chain 'user-load' (order 4 index 5 seq 2)
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'user-unload'
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'user-create'
SM : Wed Jul 25 14:40:12 2012 [notice] module 'active' added to chain 'user-create' (order 0 index 20 seq 1)
SM : Wed Jul 25 14:40:12 2012 mm.c:202 preloaded module 'template-roster' to chain 'user-create' (not added yet)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'template-roster' added to chain 'user-create' (order 1 index 22 seq 0)
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'user-delete'
SM : Wed Jul 25 14:40:12 2012 [notice] module 'active' added to chain 'user-delete' (order 0 index 20 seq 2)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'announce' added to chain 'user-delete' (order 1 index 12 seq 2)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'offline' added to chain 'user-delete' (order 2 index 11 seq 2)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'privacy' added to chain 'user-delete' (order 3 index 3 seq 4)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'roster' added to chain 'user-delete' (order 4 index 4 seq 3)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'vacation' added to chain 'user-delete' (order 5 index 5 seq 3)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'status' added to chain 'user-delete' (order 6 index 0 seq 4)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-last' added to chain 'user-delete' (order 7 index 1 seq 3)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-private' added to chain 'user-delete' (order 8 index 8 seq 1)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-vcard' added to chain 'user-delete' (order 9 index 6 seq 2)
SM : Wed Jul 25 14:40:12 2012 mm.c:79 processing config for chain 'disco-extend'
SM : Wed Jul 25 14:40:12 2012 [notice] module 'iq-version' added to chain 'disco-extend' (order 0 index 17 seq 1)
SM : Wed Jul 25 14:40:12 2012 [notice] module 'help' added to chain 'disco-extend' (order 1 index 18 seq 1)
SM : Wed Jul 25 14:40:12 2012 [notice] version: jabberd sm 2.2.16
SM : sx (sasl_gsasl.c:933) initialising sasl plugin
SM : sx (sasl_gsasl.c:961) sasl context initialised
SM : sx (env.c:75) plugin initialised (index 0)
SM : Wed Jul 25 14:40:12 2012 [notice] [localhost.localdomain] configured
ROUT: sx (chain.c:106) calling nad write chain
SM : Wed Jul 25 14:40:12 2012 [notice] attempting connection to router at 127.0.0.1, port=5347
ROUT: sx (io.c:406) queueing for write: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0'/>
ROUT: sx (io.c:429) tag 7 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 7
ROUT: sx (io.c:328) 7 ready for writing
ROUT: sx (io.c:286) encoding 64 bytes for writing: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0'/>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 64 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 64 bytes to write
ROUT: sx (io.c:350) tag 7 event 3 data 0xb406f90
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 64 bytes written
ROUT: sx (io.c:383) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:431) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:55 advertising c2s to all routes (unavail=0)
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s'/>
ROUT: sx (io.c:429) tag 6 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 6
ROUT: sx (io.c:328) 6 ready for writing
ROUT: sx (io.c:286) encoding 79 bytes for writing: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s'/>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 79 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 79 bytes to write
ROUT: sx (io.c:350) tag 6 event 3 data 0xb406fc0
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 79 bytes written
ROUT: sx (io.c:383) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:431) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:89 informing component about s2s
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='s2s'/>
ROUT: sx (io.c:429) tag 7 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 7
ROUT: sx (io.c:328) 7 ready for writing
ROUT: sx (io.c:286) encoding 79 bytes for writing: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='s2s'/>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 79 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 79 bytes to write
ROUT: sx (io.c:350) tag 7 event 3 data 0xb406f90
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 79 bytes written
ROUT: sx (io.c:383) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:431) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1085 accept action on fd 8
ROUT: Wed Jul 25 14:40:12 2012 [notice] [127.0.0.1, port=60582] connect
SM : sx (sx.c:61) allocated new sx for 6
S2S : Wed Jul 25 14:40:12 2012 router.c:118 requesting component bind for 's2s'
ROUT: sx (sx.c:61) allocated new sx for 8
SM : sx (client.c:122) doing client init for sx 6
S2S : sx (chain.c:106) calling nad write chain
ROUT: Wed Jul 25 14:40:12 2012 router.c:1115 new component (0xb403c90) "127.0.0.1:60582"
SM : sx (client.c:138) stream request: ns (null) to (null) from (null) version 1.0
S2S : sx (io.c:406) queueing for write: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='s2s'><default/></bind>
ROUT: sx (server.c:237) doing server init for sx 8
SM : sx (client.c:168) prepared stream header: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
S2S : sx (io.c:429) tag 6 event 1 data 0x0
ROUT: sx (server.c:252) waiting for stream header
SM : sx (client.c:175) tag 6 event 1 data 0x0
S2S : Wed Jul 25 14:40:12 2012 router.c:39 want write
ROUT: sx (server.c:255) tag 8 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:49 want write
S2S : Wed Jul 25 14:40:12 2012 router.c:308 write action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : Wed Jul 25 14:40:12 2012 sm.c:258 write action on fd 6
S2S : sx (io.c:328) 6 ready for writing
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 8
SM : sx (io.c:328) 6 ready for writing
S2S : sx (io.c:286) encoding 91 bytes for writing: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='s2s'><default/></bind>
ROUT: sx (io.c:191) 8 ready for reading
SM : sx (io.c:286) encoding 98 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
S2S : sx (chain.c:79) calling io write chain
ROUT: sx (io.c:197) tag 8 event 2 data 0xb404390
SM : sx (chain.c:79) calling io write chain
S2S : sx (io.c:349) handing app 91 bytes to write
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 8
SM : sx (io.c:349) handing app 98 bytes to write
S2S : sx (io.c:350) tag 6 event 3 data 0x1d8e16e0
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 98 bytes
SM : sx (io.c:350) tag 6 event 3 data 0x1495a900
S2S : Wed Jul 25 14:40:12 2012 router.c:76 writing to 6
ROUT: sx (io.c:216) passed 98 read bytes
SM : Wed Jul 25 14:40:12 2012 sm.c:86 writing to 6
S2S : Wed Jul 25 14:40:12 2012 router.c:80 91 bytes written
ROUT: sx (chain.c:93) calling io read chain
SM : Wed Jul 25 14:40:12 2012 sm.c:90 98 bytes written
S2S : sx (io.c:383) tag 6 event 0 data 0x0
ROUT: sx (io.c:240) decoded read data (98 bytes): <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
SM : sx (client.c:103) 6 state change from 0 to 2
S2S : Wed Jul 25 14:40:12 2012 router.c:34 want read
ROUT: sx (server.c:119) stream request: to (null) from (null) version 1.0
SM : sx (client.c:105) stream header sent, waiting for reply
S2S : sx (io.c:431) tag 6 event 0 data 0x0
ROUT: sx (server.c:134) 8 state change from 0 to 1
SM : sx (io.c:383) tag 6 event 0 data 0x0
S2S : Wed Jul 25 14:40:12 2012 router.c:34 want read
ROUT: sx (server.c:152) stream id is 7bmc9draafxveyjfacsb35rmn65f36vbhinrve26
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
S2S : Wed Jul 25 14:40:12 2012 router.c:297 read action on fd 6
ROUT: sx (server.c:182) prepared stream response: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
SM : Wed Jul 25 14:40:12 2012 sm.c:247 read action on fd 6
S2S : sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:256) tag 8 event 1 data 0x0
SM : sx (io.c:191) 6 ready for reading
S2S : sx (io.c:197) tag 6 event 2 data 0x1d8e1500
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
SM : sx (io.c:197) tag 6 event 2 data 0x1495a900
S2S : Wed Jul 25 14:40:12 2012 router.c:44 reading from 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 8
SM : Wed Jul 25 14:40:12 2012 sm.c:54 reading from 6
S2S : Wed Jul 25 14:40:12 2012 router.c:69 read 66 bytes
ROUT: sx (io.c:328) 8 ready for writing
SM : Wed Jul 25 14:40:12 2012 sm.c:79 read 326 bytes
S2S : sx (io.c:216) passed 66 read bytes
ROUT: sx (io.c:286) encoding 144 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
SM : sx (io.c:216) passed 326 read bytes
S2S : sx (chain.c:93) calling io read chain
ROUT: sx (chain.c:79) calling io write chain
SM : sx (chain.c:93) calling io read chain
S2S : sx (io.c:240) decoded read data (66 bytes): <stream:features xmlns:stream='http://etherx.jabber.org/streams'/>
ROUT: sx (io.c:349) handing app 144 bytes to write
SM : sx (io.c:240) decoded read data (326 bytes): <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'><stream:features xmlns:stream='http://etherx.jabber.org/streams'><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism></mechanisms></stream:features>
S2S : sx (io.c:92) completed nad: <stream:features xmlns:stream='http://etherx.jabber.org/streams'/>
ROUT: sx (io.c:350) tag 8 event 3 data 0xb403d50
SM : sx (client.c:70) stream response: to (null) from (null) version 1.0 id 7bmc9draafxveyjfacsb35rmn65f36vbhinrve26
S2S : sx (chain.c:119) calling nad read chain
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 8
SM : sx (client.c:85) 6 state change from 2 to 3
S2S : sx (io.c:156) tag 6 event 6 data 0x1d8e1730
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 144 bytes written
SM : sx (client.c:86) tag 6 event 4 data 0x0
S2S : Wed Jul 25 14:40:12 2012 router.c:171 got a packet from router, but we're not online, dropping
ROUT: sx (server.c:29) stream established
SM : sx (io.c:92) completed nad: <stream:features xmlns:stream='http://etherx.jabber.org/streams'><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism></mechanisms></stream:features>
S2S : Wed Jul 25 14:40:12 2012 router.c:297 read action on fd 6
ROUT: sx (server.c:39) 8 state change from 1 to 3
SM : sx (chain.c:119) calling nad read chain
ROUT: sx (server.c:40) tag 8 event 4 data 0x0
SM : sx (io.c:156) tag 6 event 6 data 0x1495c490
ROUT: sx (server.c:45) building features nad
SM : sx (sasl_gsasl.c:1034) sending auth request to server, mech 'DIGEST-MD5':
ROUT: sx (sasl_gsasl.c:357) offering sasl mechanisms
SM : sx (chain.c:106) calling nad write chain
ROUT: sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 5
SM : sx (io.c:406) queueing for write: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
ROUT: sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 6
SM : sx (io.c:429) tag 6 event 1 data 0x0
ROUT: sx (sasl_gsasl.c:377) offering mechanism: DIGEST-MD5
SM : Wed Jul 25 14:40:12 2012 sm.c:49 want write
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:258 write action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : sx (io.c:328) 6 ready for writing
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 8
SM : sx (io.c:286) encoding 71 bytes for writing: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
ROUT: sx (io.c:328) 8 ready for writing
SM : sx (chain.c:79) calling io write chain
ROUT: sx (io.c:286) encoding 182 bytes for writing: <stream:features xmlns:stream='http://etherx.jabber.org/streams'><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>DIGEST-MD5</mechanism></mechanisms></stream:features>
SM : sx (io.c:349) handing app 71 bytes to write
ROUT: sx (chain.c:79) calling io write chain
SM : sx (io.c:350) tag 6 event 3 data 0x1495ade0
ROUT: sx (io.c:349) handing app 182 bytes to write
SM : Wed Jul 25 14:40:12 2012 sm.c:86 writing to 6
ROUT: sx (io.c:350) tag 8 event 3 data 0xb403d50
SM : Wed Jul 25 14:40:12 2012 sm.c:90 71 bytes written
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 8
SM : sx (io.c:383) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 182 bytes written
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
SM : sx (io.c:431) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 8
SM : Wed Jul 25 14:40:12 2012 sm.c:247 read action on fd 6
ROUT: sx (io.c:191) 8 ready for reading
SM : sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:197) tag 8 event 2 data 0xb403d50
SM : sx (io.c:197) tag 6 event 2 data 0x1495ade0
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 8
SM : Wed Jul 25 14:40:12 2012 sm.c:54 reading from 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 71 bytes
SM : Wed Jul 25 14:40:12 2012 sm.c:79 read 204 bytes
ROUT: sx (io.c:216) passed 71 read bytes
SM : sx (io.c:216) passed 204 read bytes
ROUT: sx (chain.c:93) calling io read chain
SM : sx (chain.c:93) calling io read chain
ROUT: sx (io.c:240) decoded read data (71 bytes): <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
SM : sx (io.c:240) decoded read data (204 bytes): <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9Inc4a1M3aVE3Nzk1Q3dJTjlzcXlkL2c9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
ROUT: sx (io.c:92) completed nad: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
SM : sx (io.c:92) completed nad: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9Inc4a1M3aVE3Nzk1Q3dJTjlzcXlkL2c9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
ROUT: sx (chain.c:119) calling nad read chain
SM : sx (chain.c:119) calling nad read chain
ROUT: sx (sasl_gsasl.c:417) auth request from client (mechanism=DIGEST-MD5)
SM : sx (sasl_gsasl.c:596) data from client
ROUT: sx (sasl_gsasl.c:472) sasl context initialised for 8
SM : sx (sasl_gsasl.c:602) decoded data: realm="jabberd-router", nonce="w8kS7iQ7795CwIN9sqyd/g==", qop="auth", charset=utf-8, algorithm=md5-sess
ROUT: sx (sasl_gsasl.c:562) sasl handshake in progress (challenge: realm="jabberd-router", nonce="w8kS7iQ7795CwIN9sqyd/g==", qop="auth", charset=utf-8, algorithm=md5-sess)
SM : sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 2
ROUT: sx (chain.c:106) calling nad write chain
SM : sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 11
ROUT: sx (io.c:406) queueing for write: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9Inc4a1M3aVE3Nzk1Q3dJTjlzcXlkL2c9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
SM : sx (sasl_gsasl.c:610) sasl handshake in progress (response: username="jabberd", realm="jabberd-router", nonce="w8kS7iQ7795CwIN9sqyd/g==", cnonce="h2NwoAOuLY8bZzJxdn5OpA==", nc=00000001, qop=auth, digest-uri="jabberd-router/engdev1", response=cd3fc179e00a336c978963fc04a48464, charset=utf-8)
S2S : sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:256) tag 8 event 1 data 0x0
SM : sx (chain.c:106) calling nad write chain
S2S : sx (io.c:197) tag 6 event 2 data 0x1d8e1730
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
SM : sx (io.c:406) queueing for write: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0idzhrUzdpUTc3OTVDd0lOOXNxeWQvZz09IiwgY25vbmNlPSJoMk53b0FPdUxZOGJaekp4ZG41T3BBPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2VuZ2RldjEiLCByZXNwb25zZT1jZDNmYzE3OWUwMGEzMzZjOTc4OTYzZmMwNGE0ODQ2NCwgY2hhcnNldD11dGYtOA==</response>
S2S : Wed Jul 25 14:40:12 2012 router.c:44 reading from 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 8
SM : sx (io.c:256) tag 6 event 1 data 0x0
S2S : Wed Jul 25 14:40:12 2012 router.c:69 read 159 bytes
ROUT: sx (io.c:328) 8 ready for writing
SM : Wed Jul 25 14:40:12 2012 sm.c:49 want write
S2S : sx (io.c:216) passed 159 read bytes
ROUT: sx (io.c:286) encoding 204 bytes for writing: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9Inc4a1M3aVE3Nzk1Q3dJTjlzcXlkL2c9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge>
SM : Wed Jul 25 14:40:12 2012 sm.c:258 write action on fd 6
S2S : sx (chain.c:93) calling io read chain
ROUT: sx (chain.c:79) calling io write chain
SM : sx (io.c:328) 6 ready for writing
S2S : sx (io.c:240) decoded read data (159 bytes): <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0'><default/></bind><presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s'/>
ROUT: sx (io.c:349) handing app 204 bytes to write
SM : sx (io.c:286) encoding 370 bytes for writing: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0idzhrUzdpUTc3OTVDd0lOOXNxeWQvZz09IiwgY25vbmNlPSJoMk53b0FPdUxZOGJaekp4ZG41T3BBPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2VuZ2RldjEiLCByZXNwb25zZT1jZDNmYzE3OWUwMGEzMzZjOTc4OTYzZmMwNGE0ODQ2NCwgY2hhcnNldD11dGYtOA==</response>
S2S : sx (io.c:92) completed nad: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0'><default/></bind>
ROUT: sx (io.c:350) tag 8 event 3 data 0xb40adf0
SM : sx (chain.c:79) calling io write chain
S2S : sx (chain.c:119) calling nad read chain
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 8
SM : sx (io.c:349) handing app 370 bytes to write
S2S : sx (io.c:156) tag 6 event 6 data 0x1d8e0cc0
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 204 bytes written
SM : sx (io.c:350) tag 6 event 3 data 0x1495ae10
S2S : Wed Jul 25 14:40:12 2012 router.c:183 coming online
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:86 writing to 6
S2S : Wed Jul 25 14:40:12 2012 [notice] [0.0.0.0, port=5269] listening for connections
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : Wed Jul 25 14:40:12 2012 sm.c:90 370 bytes written
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 8
SM : sx (io.c:383) tag 6 event 0 data 0x0
ROUT: sx (io.c:191) 8 ready for reading
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
ROUT: sx (io.c:197) tag 8 event 2 data 0xb40adf0
SM : Wed Jul 25 14:40:12 2012 sm.c:247 read action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 8
SM : sx (io.c:191) 6 ready for reading
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 370 bytes
SM : sx (io.c:197) tag 6 event 2 data 0x1495ae10
ROUT: sx (io.c:216) passed 370 read bytes
SM : Wed Jul 25 14:40:12 2012 sm.c:54 reading from 6
ROUT: sx (chain.c:93) calling io read chain
SM : Wed Jul 25 14:40:12 2012 sm.c:79 read 120 bytes
ROUT: sx (io.c:240) decoded read data (370 bytes): <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0idzhrUzdpUTc3OTVDd0lOOXNxeWQvZz09IiwgY25vbmNlPSJoMk53b0FPdUxZOGJaekp4ZG41T3BBPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2VuZ2RldjEiLCByZXNwb25zZT1jZDNmYzE3OWUwMGEzMzZjOTc4OTYzZmMwNGE0ODQ2NCwgY2hhcnNldD11dGYtOA==</response>
SM : sx (io.c:216) passed 120 read bytes
ROUT: sx (io.c:92) completed nad: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9ImphYmJlcmQiLCByZWFsbT0iamFiYmVyZC1yb3V0ZXIiLCBub25jZT0idzhrUzdpUTc3OTVDd0lOOXNxeWQvZz09IiwgY25vbmNlPSJoMk53b0FPdUxZOGJaekp4ZG41T3BBPT0iLCBuYz0wMDAwMDAwMSwgcW9wPWF1dGgsIGRpZ2VzdC11cmk9ImphYmJlcmQtcm91dGVyL2VuZ2RldjEiLCByZXNwb25zZT1jZDNmYzE3OWUwMGEzMzZjOTc4OTYzZmMwNGE0ODQ2NCwgY2hhcnNldD11dGYtOA==</response>
SM : sx (chain.c:93) calling io read chain
ROUT: sx (chain.c:119) calling nad read chain
SM : sx (io.c:240) decoded read data (120 bytes): <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD1jMjZhZDE4YzNiODA5ZWM2NGRlMDUxYzZhOWYxN2FkYQ==</challenge>
ROUT: sx (sasl_gsasl.c:528) response from client (decoded: username="jabberd", realm="jabberd-router", nonce="w8kS7iQ7795CwIN9sqyd/g==", cnonce="h2NwoAOuLY8bZzJxdn5OpA==", nc=00000001, qop=auth, digest-uri="jabberd-router/engdev1", response=cd3fc179e00a336c978963fc04a48464, charset=utf-8)
SM : sx (io.c:92) completed nad: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD1jMjZhZDE4YzNiODA5ZWM2NGRlMDUxYzZhOWYxN2FkYQ==</challenge>
ROUT: sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 12
SM : sx (chain.c:119) calling nad read chain
ROUT: sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 3
SM : sx (sasl_gsasl.c:596) data from client
ROUT: Wed Jul 25 14:40:12 2012 main.c:225 sx sasl callback: get pass (authnid=jabberd, realm=jabberd-router)
SM : sx (sasl_gsasl.c:602) decoded data: rspauth=c26ad18c3b809ec64de051c6a9f17ada
ROUT: sx (sasl_gsasl.c:562) sasl handshake in progress (challenge: rspauth=c26ad18c3b809ec64de051c6a9f17ada)
SM : sx (sasl_gsasl.c:610) sasl handshake in progress (response: )
ROUT: sx (chain.c:106) calling nad write chain
SM : sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD1jMjZhZDE4YzNiODA5ZWM2NGRlMDUxYzZhOWYxN2FkYQ==</challenge>
SM : sx (io.c:406) queueing for write: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
ROUT: sx (io.c:256) tag 8 event 1 data 0x0
SM : sx (io.c:256) tag 6 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
SM : Wed Jul 25 14:40:12 2012 sm.c:49 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 8
SM : Wed Jul 25 14:40:12 2012 sm.c:258 write action on fd 6
ROUT: sx (io.c:328) 8 ready for writing
SM : sx (io.c:328) 6 ready for writing
ROUT: sx (io.c:286) encoding 120 bytes for writing: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD1jMjZhZDE4YzNiODA5ZWM2NGRlMDUxYzZhOWYxN2FkYQ==</challenge>
SM : sx (io.c:286) encoding 52 bytes for writing: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
ROUT: sx (chain.c:79) calling io write chain
SM : sx (chain.c:79) calling io write chain
ROUT: sx (io.c:349) handing app 120 bytes to write
SM : sx (io.c:349) handing app 52 bytes to write
ROUT: sx (io.c:350) tag 8 event 3 data 0xb40bc10
SM : sx (io.c:350) tag 6 event 3 data 0x1495c550
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 8
SM : Wed Jul 25 14:40:12 2012 sm.c:86 writing to 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 120 bytes written
SM : Wed Jul 25 14:40:12 2012 sm.c:90 52 bytes written
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
SM : sx (io.c:383) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 8
SM : Wed Jul 25 14:40:12 2012 sm.c:247 read action on fd 6
ROUT: sx (io.c:191) 8 ready for reading
SM : sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:197) tag 8 event 2 data 0xb40b780
SM : sx (io.c:197) tag 6 event 2 data 0x1495c550
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 8
SM : Wed Jul 25 14:40:12 2012 sm.c:54 reading from 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 52 bytes
SM : Wed Jul 25 14:40:12 2012 sm.c:79 read 51 bytes
ROUT: sx (io.c:216) passed 52 read bytes
SM : sx (io.c:216) passed 51 read bytes
ROUT: sx (chain.c:93) calling io read chain
SM : sx (chain.c:93) calling io read chain
ROUT: sx (io.c:240) decoded read data (52 bytes): <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
SM : sx (io.c:240) decoded read data (51 bytes): <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
ROUT: sx (io.c:92) completed nad: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
SM : sx (io.c:92) completed nad: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
ROUT: sx (chain.c:119) calling nad read chain
SM : sx (chain.c:119) calling nad read chain
ROUT: sx (sasl_gsasl.c:528) response from client (decoded: )
SM : sx (sasl_gsasl.c:728) sasl handshake completed, resetting
ROUT: sx (sasl_gsasl.c:536) sasl handshake completed
SM : sx (sx.c:154) resetting stream state
ROUT: sx (chain.c:106) calling nad write chain
SM : sx (sx.c:78) freeing sx for 6
ROUT: sx (io.c:406) queueing for write: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
SM : sx (sx.c:61) allocated new sx for 6
ROUT: sx (io.c:256) tag 8 event 1 data 0x0
SM : sx (sx.c:211) finished resetting stream state
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
SM : sx (sasl_gsasl.c:743) restarting stream with sasl layer established
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 8
SM : sx (client.c:122) doing client init for sx 6
ROUT: sx (io.c:328) 8 ready for writing
SM : sx (client.c:138) stream request: ns (null) to (null) from (null) version 1.0
ROUT: sx (io.c:286) encoding 51 bytes for writing: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
SM : sx (client.c:168) prepared stream header: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
ROUT: sx (chain.c:79) calling io write chain
SM : sx (client.c:175) tag 6 event 1 data 0x0
ROUT: sx (io.c:349) handing app 51 bytes to write
SM : Wed Jul 25 14:40:12 2012 sm.c:49 want write
ROUT: sx (io.c:350) tag 8 event 3 data 0xb40b710
SM : Wed Jul 25 14:40:12 2012 sm.c:258 write action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 8
SM : sx (io.c:328) 6 ready for writing
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 51 bytes written
SM : sx (io.c:286) encoding 98 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
ROUT: sx (chain.c:28) adding io plugin
SM : sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:398) auth completed, resetting
SM : sx (io.c:349) handing app 98 bytes to write
ROUT: sx (sx.c:154) resetting stream state
SM : sx (io.c:350) tag 6 event 3 data 0x1495acf0
ROUT: sx (sx.c:78) freeing sx for 8
SM : Wed Jul 25 14:40:12 2012 sm.c:86 writing to 6
ROUT: sx (sx.c:61) allocated new sx for 8
SM : Wed Jul 25 14:40:12 2012 sm.c:90 98 bytes written
ROUT: sx (sx.c:211) finished resetting stream state
SM : sx (client.c:103) 6 state change from 0 to 2
ROUT: sx (server.c:237) doing server init for sx 8
SM : sx (client.c:105) stream header sent, waiting for reply
ROUT: sx (server.c:252) waiting for stream header
SM : sx (io.c:383) tag 6 event 0 data 0x0
ROUT: sx (server.c:255) tag 8 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : Wed Jul 25 14:40:12 2012 sm.c:247 read action on fd 6
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
SM : sx (io.c:191) 6 ready for reading
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 8
ROUT: sx (io.c:191) 8 ready for reading
ROUT: sx (io.c:197) tag 8 event 2 data 0xb40b710
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 8
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 98 bytes
ROUT: sx (io.c:216) passed 98 read bytes
ROUT: sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:248) doing sasl decode
ROUT: sx (sasl_gsasl.c:264) 98 bytes decoded from sasl channel
ROUT: sx (io.c:240) decoded read data (98 bytes): <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0'>
S2S : Wed Jul 25 14:40:12 2012 [notice] ready for connections
ROUT: sx (server.c:119) stream request: to (null) from (null) version 1.0
ROUT: sx (server.c:134) 8 state change from 0 to 1
ROUT: sx (server.c:152) stream id is 7bmc9draafxveyjfacsb35rmn65f36vbhinrve26
ROUT: sx (server.c:182) prepared stream response: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
ROUT: sx (io.c:256) tag 8 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 8
ROUT: sx (io.c:328) 8 ready for writing
ROUT: sx (io.c:286) encoding 144 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 144 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 144 bytes to write
ROUT: sx (io.c:350) tag 8 event 3 data 0xb406fc0
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 8
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 144 bytes written
ROUT: sx (server.c:29) stream established
ROUT: sx (sx.c:140) authenticating stream (method=SASL/DIGEST-MD5; id=jabberd@jabberd-router)
ROUT: sx (sx.c:145) 8 state change from 1 to 4
ROUT: sx (sx.c:146) tag 8 event 5 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 [notice] [127.0.0.1, port=60582] authenticated as jabberd@jabberd-router
ROUT: sx (server.c:45) building features nad
ROUT: sx (sasl_gsasl.c:341) already auth'd, not offering sasl mechanisms
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 8
ROUT: sx (io.c:328) 8 ready for writing
ROUT: sx (io.c:286) encoding 66 bytes for writing: <stream:features xmlns:stream='http://etherx.jabber.org/streams'/>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 66 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 66 bytes to write
ROUT: sx (io.c:350) tag 8 event 3 data 0xb406fc0
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 8
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 66 bytes written
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 8
ROUT: sx (io.c:191) 8 ready for reading
ROUT: sx (io.c:197) tag 8 event 2 data 0xb406fc0
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 8
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 93 bytes
ROUT: sx (io.c:216) passed 93 read bytes
ROUT: sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:248) doing sasl decode
ROUT: sx (sasl_gsasl.c:264) 93 bytes decoded from sasl channel
ROUT: sx (io.c:240) decoded read data (93 bytes): <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='engdev1.remotewd2.com'/>
ROUT: sx (io.c:92) completed nad: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='engdev1.remotewd2.com'/>
ROUT: sx (chain.c:119) calling nad read chain
ROUT: sx (io.c:156) tag 8 event 6 data 0xb40bb60
ROUT: Wed Jul 25 14:40:12 2012 aci.c:96 checking for 'jabberd' in acl 'all'
ROUT: Wed Jul 25 14:40:12 2012 [notice] [engdev1.remotewd2.com] online (bound to 127.0.0.1, port 60582)
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0'/>
ROUT: sx (io.c:429) tag 8 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 8
ROUT: sx (io.c:328) 8 ready for writing
ROUT: sx (io.c:286) encoding 64 bytes for writing: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0'/>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 64 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 64 bytes to write
ROUT: sx (io.c:350) tag 8 event 3 data 0xb40bb60
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 8
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 64 bytes written
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:431) tag 8 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:55 advertising engdev1.remotewd2.com to all routes (unavail=0)
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com'/>
ROUT: sx (io.c:429) tag 6 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 6
ROUT: sx (io.c:328) 6 ready for writing
ROUT: sx (io.c:286) encoding 97 bytes for writing: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com'/>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 97 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 97 bytes to write
ROUT: sx (io.c:350) tag 6 event 3 data 0xb408460
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 97 bytes written
ROUT: sx (io.c:383) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:431) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com'/>
ROUT: sx (io.c:429) tag 7 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 7
ROUT: sx (io.c:328) 7 ready for writing
ROUT: sx (io.c:286) encoding 97 bytes for writing: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com'/>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 97 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 97 bytes to write
ROUT: sx (io.c:350) tag 7 event 3 data 0xb40bb60
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 97 bytes written
ROUT: sx (io.c:383) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:431) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:89 informing component about s2s
S2S : sx (io.c:92) completed nad: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s'/>
ROUT: sx (chain.c:106) calling nad write chain
S2S : sx (chain.c:119) calling nad read chain
ROUT: sx (io.c:406) queueing for write: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='s2s'/>
S2S : sx (io.c:156) tag 6 event 6 data 0x1d8e10a0
ROUT: sx (io.c:429) tag 8 event 1 data 0x0
S2S : Wed Jul 25 14:40:12 2012 router.c:205 got a packet
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
S2S : Wed Jul 25 14:40:12 2012 router.c:215 dropping non-route packet
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 8
S2S : Wed Jul 25 14:40:12 2012 router.c:297 read action on fd 6
ROUT: sx (io.c:328) 8 ready for writing
S2S : sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:286) encoding 79 bytes for writing: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='s2s'/>
S2S : sx (io.c:197) tag 6 event 2 data 0x1d8e16e0
ROUT: sx (chain.c:79) calling io write chain
S2S : Wed Jul 25 14:40:12 2012 router.c:44 reading from 6
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
S2S : Wed Jul 25 14:40:12 2012 router.c:69 read 97 bytes
ROUT: sx (sasl_gsasl.c:236) 79 bytes encoded for sasl channel
S2S : sx (io.c:216) passed 97 read bytes
ROUT: sx (io.c:349) handing app 79 bytes to write
S2S : sx (chain.c:93) calling io read chain
ROUT: sx (io.c:350) tag 8 event 3 data 0xb408460
S2S : sx (io.c:240) decoded read data (97 bytes): <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com'/>
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 8
S2S : sx (io.c:92) completed nad: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com'/>
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 79 bytes written
S2S : sx (chain.c:119) calling nad read chain
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
S2S : sx (io.c:156) tag 6 event 6 data 0x1d8e0b60
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
S2S : Wed Jul 25 14:40:12 2012 router.c:205 got a packet
ROUT: sx (io.c:431) tag 8 event 0 data 0x0
S2S : Wed Jul 25 14:40:12 2012 router.c:215 dropping non-route packet
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
S2S : Wed Jul 25 14:40:12 2012 router.c:297 read action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:89 informing component about c2s
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s'/>
ROUT: sx (io.c:429) tag 8 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 8
ROUT: sx (io.c:328) 8 ready for writing
ROUT: sx (io.c:286) encoding 79 bytes for writing: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s'/>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 79 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 79 bytes to write
SM : sx (io.c:197) tag 6 event 2 data 0x1495acf0
ROUT: sx (io.c:350) tag 8 event 3 data 0xb40bb60
SM : Wed Jul 25 14:40:12 2012 sm.c:54 reading from 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 8
SM : Wed Jul 25 14:40:12 2012 sm.c:79 read 144 bytes
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 79 bytes written
SM : sx (io.c:216) passed 144 read bytes
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
SM : sx (chain.c:93) calling io read chain
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : sx (io.c:240) decoded read data (144 bytes): <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'>
ROUT: sx (io.c:431) tag 8 event 0 data 0x0
SM : sx (client.c:70) stream response: to (null) from (null) version 1.0 id 7bmc9draafxveyjfacsb35rmn65f36vbhinrve26
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : sx (sx.c:140) authenticating stream (method=SASL/DIGEST-MD5; id=jabberd@jabberd-router)
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 8
SM : sx (sx.c:145) 6 state change from 2 to 4
ROUT: sx (io.c:191) 8 ready for reading
SM : sx (sx.c:146) tag 6 event 5 data 0x0
ROUT: sx (io.c:197) tag 8 event 2 data 0xb40bb60
SM : Wed Jul 25 14:40:12 2012 [notice] connection to router established
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 8
SM : Wed Jul 25 14:40:12 2012 sm.c:125 requesting component bind for 'engdev1.remotewd2.com'
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 104 bytes
SM : sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:216) passed 104 read bytes
SM : sx (io.c:406) queueing for write: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='engdev1.remotewd2.com'/>
ROUT: sx (chain.c:93) calling io read chain
SM : sx (io.c:429) tag 6 event 1 data 0x0
ROUT: sx (sasl_gsasl.c:248) doing sasl decode
SM : Wed Jul 25 14:40:12 2012 sm.c:49 want write
ROUT: sx (sasl_gsasl.c:264) 104 bytes decoded from sasl channel
SM : Wed Jul 25 14:40:12 2012 sm.c:258 write action on fd 6
ROUT: sx (io.c:240) decoded read data (104 bytes): <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' multi='to' name='localhost.localdomain'/>
SM : sx (io.c:328) 6 ready for writing
ROUT: sx (io.c:92) completed nad: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='localhost.localdomain' multi='to'/>
SM : sx (io.c:286) encoding 93 bytes for writing: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' name='engdev1.remotewd2.com'/>
ROUT: sx (chain.c:119) calling nad read chain
SM : sx (chain.c:79) calling io write chain
ROUT: sx (io.c:156) tag 8 event 6 data 0xb40b6d0
SM : sx (io.c:349) handing app 93 bytes to write
ROUT: Wed Jul 25 14:40:12 2012 aci.c:96 checking for 'jabberd' in acl 'all'
SM : sx (io.c:350) tag 6 event 3 data 0x149458b0
ROUT: Wed Jul 25 14:40:12 2012 [notice] [localhost.localdomain] online (bound to 127.0.0.1, port 60582)
SM : Wed Jul 25 14:40:12 2012 sm.c:86 writing to 6
ROUT: sx (chain.c:106) calling nad write chain
SM : Wed Jul 25 14:40:12 2012 sm.c:90 93 bytes written
ROUT: sx (io.c:406) queueing for write: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' multi='to'/>
SM : sx (io.c:383) tag 6 event 0 data 0x0
ROUT: sx (io.c:429) tag 8 event 1 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
SM : sx (io.c:431) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 8
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
ROUT: sx (io.c:328) 8 ready for writing
SM : Wed Jul 25 14:40:12 2012 sm.c:141 requesting domain bind for 'localhost.localdomain'
ROUT: sx (io.c:286) encoding 75 bytes for writing: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' multi='to'/>
SM : sx (chain.c:106) calling nad write chain
ROUT: sx (chain.c:79) calling io write chain
SM : sx (io.c:406) queueing for write: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' multi='to' name='localhost.localdomain'/>
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
SM : sx (io.c:429) tag 6 event 1 data 0x0
ROUT: sx (sasl_gsasl.c:236) 75 bytes encoded for sasl channel
SM : Wed Jul 25 14:40:12 2012 sm.c:49 want write
ROUT: sx (io.c:349) handing app 75 bytes to write
SM : Wed Jul 25 14:40:12 2012 sm.c:258 write action on fd 6
ROUT: sx (io.c:350) tag 8 event 3 data 0xb408330
SM : sx (io.c:328) 6 ready for writing
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 8
SM : sx (io.c:286) encoding 104 bytes for writing: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' multi='to' name='localhost.localdomain'/>
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 75 bytes written
SM : sx (chain.c:79) calling io write chain
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
SM : sx (io.c:349) handing app 104 bytes to write
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : sx (io.c:350) tag 6 event 3 data 0x14945910
ROUT: sx (io.c:431) tag 8 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:86 writing to 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : Wed Jul 25 14:40:12 2012 sm.c:90 104 bytes written
ROUT: Wed Jul 25 14:40:12 2012 router.c:55 advertising localhost.localdomain to all routes (unavail=0)
SM : sx (io.c:383) tag 6 event 0 data 0x0
ROUT: sx (chain.c:106) calling nad write chain
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
ROUT: sx (io.c:406) queueing for write: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='localhost.localdomain'/>
SM : sx (io.c:431) tag 6 event 0 data 0x0
ROUT: sx (io.c:429) tag 6 event 1 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
SM : Wed Jul 25 14:40:12 2012 sm.c:247 read action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 6
SM : sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:328) 6 ready for writing
SM : sx (io.c:197) tag 6 event 2 data 0x1495c610
ROUT: sx (io.c:286) encoding 97 bytes for writing: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='localhost.localdomain'/>
SM : Wed Jul 25 14:40:12 2012 sm.c:54 reading from 6
ROUT: sx (chain.c:79) calling io write chain
SM : Wed Jul 25 14:40:12 2012 sm.c:79 read 66 bytes
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
SM : sx (io.c:216) passed 66 read bytes
SM : sx (chain.c:93) calling io read chain
SM : sx (io.c:240) decoded read data (66 bytes): <stream:features xmlns:stream='http://etherx.jabber.org/streams'/>
SM : sx (io.c:92) completed nad: <stream:features xmlns:stream='http://etherx.jabber.org/streams'/>
SM : sx (chain.c:119) calling nad read chain
SM : sx (io.c:156) tag 6 event 6 data 0x1495bee0
SM : Wed Jul 25 14:40:12 2012 sm.c:197 got a packet from router, but we're not online, dropping
SM : Wed Jul 25 14:40:12 2012 sm.c:247 read action on fd 6
SM : sx (io.c:191) 6 ready for reading
SM : sx (io.c:197) tag 6 event 2 data 0x1495caa0
SM : Wed Jul 25 14:40:12 2012 sm.c:54 reading from 6
SM : Wed Jul 25 14:40:12 2012 sm.c:79 read 64 bytes
SM : sx (io.c:216) passed 64 read bytes
SM : sx (chain.c:93) calling io read chain
SM : sx (io.c:240) decoded read data (64 bytes): <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0'/>
SM : sx (io.c:92) completed nad: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0'/>
SM : sx (chain.c:119) calling nad read chain
SM : sx (io.c:156) tag 6 event 6 data 0x1495bee0
SM : Wed Jul 25 14:40:12 2012 sm.c:209 coming online
SM : Wed Jul 25 14:40:12 2012 [notice] engdev1.remotewd2.com ready for sessions
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1362 read action on fd 6
C2S : sx (io.c:191) 6 ready for reading
C2S : sx (io.c:197) tag 6 event 2 data 0x1063fef0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:721 reading from 6
C2S : Wed Jul 25 14:40:12 2012 c2s.c:746 read 337 bytes
C2S : sx (io.c:216) passed 337 read bytes
C2S : sx (chain.c:93) calling io read chain
C2S : sx (io.c:240) decoded read data (337 bytes): <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0'/><presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='s2s'/><presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com'/><presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='localhost.localdomain'/>
C2S : sx (io.c:92) completed nad: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0'/>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (io.c:156) tag 6 event 6 data 0x1063a4b0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:858 coming online
C2S : Wed Jul 25 14:40:12 2012 [notice] [0.0.0.0, port=5222] listening for connections
C2S : Wed Jul 25 14:40:12 2012 [notice] ready for connections
C2S : sx (io.c:92) completed nad: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='s2s'/>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (io.c:156) tag 6 event 6 data 0x10648d40
C2S : Wed Jul 25 14:40:12 2012 c2s.c:662 component available from 's2s'
C2S : Wed Jul 25 14:40:12 2012 c2s.c:664 sm for serviced domain 's2s' online
C2S : sx (io.c:92) completed nad: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com'/>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (io.c:156) tag 6 event 6 data 0x106392c0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:662 component available from 'engdev1.remotewd2.com'
C2S : Wed Jul 25 14:40:12 2012 c2s.c:664 sm for serviced domain 'engdev1.remotewd2.com' online
C2S : sx (io.c:92) completed nad: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='localhost.localdomain'/>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (io.c:156) tag 6 event 6 data 0x1063f780
C2S : Wed Jul 25 14:40:12 2012 c2s.c:662 component available from 'localhost.localdomain'
C2S : Wed Jul 25 14:40:12 2012 c2s.c:664 sm for serviced domain 'localhost.localdomain' online
ROUT: sx (sasl_gsasl.c:236) 97 bytes encoded for sasl channel
SM : Wed Jul 25 14:40:12 2012 sm.c:247 read action on fd 6
S2S : sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:349) handing app 97 bytes to write
SM : sx (io.c:191) 6 ready for reading
S2S : sx (io.c:197) tag 6 event 2 data 0x1d8e0cc0
ROUT: sx (io.c:350) tag 6 event 3 data 0xb4083f0
SM : sx (io.c:197) tag 6 event 2 data 0x14945830
S2S : Wed Jul 25 14:40:12 2012 router.c:44 reading from 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 6
SM : Wed Jul 25 14:40:12 2012 sm.c:54 reading from 6
S2S : Wed Jul 25 14:40:12 2012 router.c:69 read 97 bytes
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 97 bytes written
SM : Wed Jul 25 14:40:12 2012 sm.c:79 read 391 bytes
S2S : sx (io.c:216) passed 97 read bytes
ROUT: sx (io.c:383) tag 6 event 0 data 0x0
SM : sx (io.c:216) passed 391 read bytes
S2S : sx (chain.c:93) calling io read chain
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : sx (chain.c:93) calling io read chain
S2S : sx (io.c:240) decoded read data (97 bytes): <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='localhost.localdomain'/>
ROUT: sx (io.c:431) tag 6 event 0 data 0x0
SM : sx (io.c:240) decoded read data (391 bytes): <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='s2s'/><presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s'/><bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' multi='to'/><presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='s2s'/><presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s'/>
S2S : sx (io.c:92) completed nad: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='localhost.localdomain'/>
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : sx (io.c:92) completed nad: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='s2s'/>
S2S : sx (chain.c:119) calling nad read chain
ROUT: sx (chain.c:106) calling nad write chain
SM : sx (chain.c:119) calling nad read chain
S2S : sx (io.c:156) tag 6 event 6 data 0x1d8e0b60
ROUT: sx (io.c:406) queueing for write: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='localhost.localdomain'/>
SM : sx (io.c:156) tag 6 event 6 data 0x1495c0a0
S2S : Wed Jul 25 14:40:12 2012 router.c:205 got a packet
ROUT: sx (io.c:429) tag 7 event 1 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:219 got a packet
S2S : Wed Jul 25 14:40:12 2012 router.c:215 dropping non-route packet
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
SM : Wed Jul 25 14:40:12 2012 pkt.c:118 creating new packet
S2S : Wed Jul 25 14:40:12 2012 router.c:297 read action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 7
SM : Wed Jul 25 14:40:12 2012 mm.c:632 dispatching pkt-router chain
ROUT: sx (io.c:328) 7 ready for writing
SM : Wed Jul 25 14:40:12 2012 mm.c:645 calling module session
ROUT: sx (io.c:286) encoding 97 bytes for writing: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='localhost.localdomain'/>
SM : Wed Jul 25 14:40:12 2012 mm.c:645 calling module disco
ROUT: sx (chain.c:79) calling io write chain
SM : Wed Jul 25 14:40:12 2012 mod_disco.c:544 presence from component s2s, issuing discovery request
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
SM : Wed Jul 25 14:40:12 2012 pkt.c:118 creating new packet
ROUT: sx (sasl_gsasl.c:236) 97 bytes encoded for sasl channel
SM : Wed Jul 25 14:40:12 2012 pkt.c:385 delivering pkt to router
ROUT: sx (io.c:349) handing app 97 bytes to write
SM : Wed Jul 25 14:40:12 2012 mm.c:540 dispatching out-router chain
ROUT: sx (io.c:350) tag 7 event 3 data 0xb408330
SM : Wed Jul 25 14:40:12 2012 mm.c:553 calling module privacy
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 7
SM : Wed Jul 25 14:40:12 2012 mm.c:560 out-router chain returning 1
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 97 bytes written
SM : sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:383) tag 7 event 0 data 0x0
SM : sx (io.c:406) queueing for write: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='s2s'><iq xmlns='jabber:client' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26' from='engdev1.remotewd2.com' to='s2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : sx (io.c:429) tag 6 event 1 data 0x0
ROUT: sx (io.c:431) tag 7 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:49 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : Wed Jul 25 14:40:12 2012 sm.c:258 write action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:89 informing component about s2s
SM : sx (io.c:328) 6 ready for writing
ROUT: sx (chain.c:106) calling nad write chain
SM : sx (io.c:286) encoding 290 bytes for writing: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='s2s'><iq xmlns='jabber:client' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26' from='engdev1.remotewd2.com' to='s2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (io.c:406) queueing for write: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='s2s'/>
SM : sx (chain.c:79) calling io write chain
ROUT: sx (io.c:429) tag 8 event 1 data 0x0
SM : sx (io.c:349) handing app 290 bytes to write
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
SM : sx (io.c:350) tag 6 event 3 data 0x1495df80
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 8
SM : Wed Jul 25 14:40:12 2012 sm.c:86 writing to 6
ROUT: sx (io.c:328) 8 ready for writing
SM : Wed Jul 25 14:40:12 2012 sm.c:90 290 bytes written
ROUT: sx (io.c:286) encoding 79 bytes for writing: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='s2s'/>
SM : sx (io.c:383) tag 6 event 0 data 0x0
ROUT: sx (chain.c:79) calling io write chain
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
SM : sx (io.c:431) tag 6 event 0 data 0x0
ROUT: sx (sasl_gsasl.c:236) 79 bytes encoded for sasl channel
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
ROUT: sx (io.c:349) handing app 79 bytes to write
SM : Wed Jul 25 14:40:12 2012 pkt.c:316 freeing pkt
ROUT: sx (io.c:350) tag 8 event 3 data 0xb4083f0
SM : Wed Jul 25 14:40:12 2012 pkt.c:316 freeing pkt
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 8
SM : Wed Jul 25 14:40:12 2012 mm.c:652 pkt-router chain returning 0
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 79 bytes written
SM : sx (io.c:92) completed nad: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s'/>
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
SM : sx (chain.c:119) calling nad read chain
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : sx (io.c:156) tag 6 event 6 data 0x1495c100
ROUT: sx (io.c:431) tag 8 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:219 got a packet
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : Wed Jul 25 14:40:12 2012 pkt.c:118 creating new packet
ROUT: Wed Jul 25 14:40:12 2012 router.c:89 informing component about c2s
SM : Wed Jul 25 14:40:12 2012 mm.c:632 dispatching pkt-router chain
ROUT: sx (chain.c:106) calling nad write chain
SM : Wed Jul 25 14:40:12 2012 mm.c:645 calling module session
ROUT: sx (io.c:406) queueing for write: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s'/>
SM : Wed Jul 25 14:40:12 2012 mm.c:645 calling module disco
ROUT: sx (io.c:429) tag 8 event 1 data 0x0
SM : Wed Jul 25 14:40:12 2012 mod_disco.c:544 presence from component c2s, issuing discovery request
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
SM : Wed Jul 25 14:40:12 2012 pkt.c:118 creating new packet
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 8
SM : Wed Jul 25 14:40:12 2012 pkt.c:385 delivering pkt to router
ROUT: sx (io.c:328) 8 ready for writing
SM : Wed Jul 25 14:40:12 2012 mm.c:540 dispatching out-router chain
ROUT: sx (io.c:286) encoding 79 bytes for writing: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s'/>
SM : Wed Jul 25 14:40:12 2012 mm.c:553 calling module privacy
ROUT: sx (chain.c:79) calling io write chain
SM : Wed Jul 25 14:40:12 2012 mm.c:560 out-router chain returning 1
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
SM : sx (chain.c:106) calling nad write chain
ROUT: sx (sasl_gsasl.c:236) 79 bytes encoded for sasl channel
SM : sx (io.c:406) queueing for write: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='c2s'><iq xmlns='jabber:client' id='uz18ykn9xgk0mcnaisqlzlwg4k8zya6sa819tpiq' from='engdev1.remotewd2.com' to='c2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (io.c:349) handing app 79 bytes to write
SM : sx (io.c:429) tag 6 event 1 data 0x0
ROUT: sx (io.c:350) tag 8 event 3 data 0xb408330
SM : Wed Jul 25 14:40:12 2012 sm.c:49 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 8
SM : Wed Jul 25 14:40:12 2012 sm.c:258 write action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 79 bytes written
SM : sx (io.c:328) 6 ready for writing
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
SM : sx (io.c:286) encoding 290 bytes for writing: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='c2s'><iq xmlns='jabber:client' id='uz18ykn9xgk0mcnaisqlzlwg4k8zya6sa819tpiq' from='engdev1.remotewd2.com' to='c2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : sx (chain.c:79) calling io write chain
ROUT: sx (io.c:431) tag 8 event 0 data 0x0
SM : sx (io.c:349) handing app 290 bytes to write
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
SM : sx (io.c:350) tag 6 event 3 data 0x149458b0
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 8
SM : Wed Jul 25 14:40:12 2012 sm.c:86 writing to 6
SM : Wed Jul 25 14:40:12 2012 sm.c:90 290 bytes written
SM : sx (io.c:383) tag 6 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
SM : sx (io.c:431) tag 6 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
SM : Wed Jul 25 14:40:12 2012 pkt.c:316 freeing pkt
SM : Wed Jul 25 14:40:12 2012 pkt.c:316 freeing pkt
SM : Wed Jul 25 14:40:12 2012 mm.c:652 pkt-router chain returning 0
SM : sx (io.c:92) completed nad: <bind xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' multi='to'/>
SM : sx (chain.c:119) calling nad read chain
SM : sx (io.c:156) tag 6 event 6 data 0x1495d100
SM : Wed Jul 25 14:40:12 2012 sm.c:219 got a packet
SM : Wed Jul 25 14:40:12 2012 pkt.c:118 creating new packet
SM : Wed Jul 25 14:40:12 2012 pkt.c:309 invalid component packet
SM : Wed Jul 25 14:40:12 2012 pkt.c:316 freeing pkt
SM : Wed Jul 25 14:40:12 2012 sm.c:223 invalid packet, dropping
SM : sx (io.c:92) completed nad: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='s2s'/>
SM : sx (chain.c:119) calling nad read chain
SM : sx (io.c:156) tag 6 event 6 data 0x1495d490
SM : Wed Jul 25 14:40:12 2012 sm.c:219 got a packet
SM : Wed Jul 25 14:40:12 2012 pkt.c:118 creating new packet
SM : Wed Jul 25 14:40:12 2012 mm.c:632 dispatching pkt-router chain
SM : Wed Jul 25 14:40:12 2012 mm.c:645 calling module session
SM : Wed Jul 25 14:40:12 2012 mm.c:645 calling module disco
SM : Wed Jul 25 14:40:12 2012 mod_disco.c:544 presence from component s2s, issuing discovery request
SM : Wed Jul 25 14:40:12 2012 pkt.c:118 creating new packet
SM : Wed Jul 25 14:40:12 2012 pkt.c:385 delivering pkt to router
SM : Wed Jul 25 14:40:12 2012 mm.c:540 dispatching out-router chain
SM : Wed Jul 25 14:40:12 2012 mm.c:553 calling module privacy
SM : Wed Jul 25 14:40:12 2012 mm.c:560 out-router chain returning 1
SM : sx (chain.c:106) calling nad write chain
SM : sx (io.c:406) queueing for write: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='s2s'><iq xmlns='jabber:client' id='62qtfd3x6tj5fgmj0vjz5psgxupqj7hpa7iplmns' from='engdev1.remotewd2.com' to='s2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
SM : sx (io.c:429) tag 6 event 1 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:49 want write
SM : Wed Jul 25 14:40:12 2012 sm.c:258 write action on fd 6
SM : sx (io.c:328) 6 ready for writing
SM : sx (io.c:286) encoding 290 bytes for writing: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='s2s'><iq xmlns='jabber:client' id='62qtfd3x6tj5fgmj0vjz5psgxupqj7hpa7iplmns' from='engdev1.remotewd2.com' to='s2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
SM : sx (chain.c:79) calling io write chain
SM : sx (io.c:349) handing app 290 bytes to write
SM : sx (io.c:350) tag 6 event 3 data 0x1495c040
SM : Wed Jul 25 14:40:12 2012 sm.c:86 writing to 6
SM : Wed Jul 25 14:40:12 2012 sm.c:90 290 bytes written
SM : sx (io.c:383) tag 6 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
SM : sx (io.c:431) tag 6 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
SM : Wed Jul 25 14:40:12 2012 pkt.c:316 freeing pkt
SM : Wed Jul 25 14:40:12 2012 pkt.c:316 freeing pkt
SM : Wed Jul 25 14:40:12 2012 mm.c:652 pkt-router chain returning 0
SM : sx (io.c:92) completed nad: <presence xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s'/>
SM : sx (chain.c:119) calling nad read chain
SM : sx (io.c:156) tag 6 event 6 data 0x1495d820
ROUT: sx (io.c:191) 8 ready for reading
S2S : sx (io.c:191) 6 ready for reading
ROUT: sx (io.c:197) tag 8 event 2 data 0xb408330
S2S : sx (io.c:197) tag 6 event 2 data 0x1d8e0cf0
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 8
S2S : Wed Jul 25 14:40:12 2012 router.c:44 reading from 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 290 bytes
S2S : Wed Jul 25 14:40:12 2012 router.c:69 read 290 bytes
ROUT: sx (io.c:216) passed 290 read bytes
S2S : sx (io.c:216) passed 290 read bytes
ROUT: sx (chain.c:93) calling io read chain
S2S : sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:248) doing sasl decode
S2S : sx (io.c:240) decoded read data (290 bytes): <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='s2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='s2s' from='engdev1.remotewd2.com' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (sasl_gsasl.c:264) 290 bytes decoded from sasl channel
S2S : sx (io.c:92) completed nad: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='s2s'><iq xmlns='jabber:client' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26' from='engdev1.remotewd2.com' to='s2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (io.c:240) decoded read data (290 bytes): <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='s2s'><iq xmlns='jabber:client' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26' from='engdev1.remotewd2.com' to='s2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
S2S : sx (chain.c:119) calling nad read chain
ROUT: sx (io.c:92) completed nad: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='s2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='s2s' from='engdev1.remotewd2.com' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
S2S : sx (io.c:156) tag 6 event 6 data 0x1d8e0f30
ROUT: sx (chain.c:119) calling nad read chain
S2S : Wed Jul 25 14:40:12 2012 router.c:205 got a packet
ROUT: sx (io.c:156) tag 8 event 6 data 0xb408360
S2S : Wed Jul 25 14:40:12 2012 router.c:229 dropping unknown or invalid packet for s2s component proper
ROUT: Wed Jul 25 14:40:12 2012 router.c:449 unicast route from engdev1.remotewd2.com to s2s
S2S : Wed Jul 25 14:40:12 2012 router.c:297 read action on fd 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:563 writing route for 's2s'*1 to 127.0.0.1, port 60580
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='s2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='s2s' from='engdev1.remotewd2.com' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (io.c:429) tag 6 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 6
ROUT: sx (io.c:328) 6 ready for writing
ROUT: sx (io.c:286) encoding 290 bytes for writing: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='s2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='s2s' from='engdev1.remotewd2.com' id='7bmc9draafxveyjfacsb35rmn65f36vbhinrve26'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 290 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 290 bytes to write
ROUT: sx (io.c:350) tag 6 event 3 data 0xb40a6f0
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 6
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 290 bytes written
ROUT: sx (io.c:383) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:431) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:40:12 2012 router.c:1036 read action on fd 8
ROUT: sx (io.c:191) 8 ready for reading
ROUT: sx (io.c:197) tag 8 event 2 data 0xb40a610
ROUT: Wed Jul 25 14:40:12 2012 router.c:698 reading from 8
ROUT: Wed Jul 25 14:40:12 2012 router.c:756 read 870 bytes
ROUT: sx (io.c:216) passed 870 read bytes
ROUT: sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:248) doing sasl decode
ROUT: sx (sasl_gsasl.c:264) 870 bytes decoded from sasl channel
ROUT: sx (io.c:240) decoded read data (870 bytes): <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='c2s'><iq xmlns='jabber:client' id='uz18ykn9xgk0mcnaisqlzlwg4k8zya6sa819tpiq' from='engdev1.remotewd2.com' to='c2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route><route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='s2s'><iq xmlns='jabber:client' id='62qtfd3x6tj5fgmj0vjz5psgxupqj7hpa7iplmns' from='engdev1.remotewd2.com' to='s2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route><route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='c2s'><iq xmlns='jabber:client' id='f6yunleogxnmng2karbtzsj902ymolf3sdygzc4g' from='engdev1.remotewd2.com' to='c2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (io.c:92) completed nad: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='c2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='c2s' from='engdev1.remotewd2.com' id='uz18ykn9xgk0mcnaisqlzlwg4k8zya6sa819tpiq'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (chain.c:119) calling nad read chain
ROUT: sx (io.c:156) tag 8 event 6 data 0xb40a640
ROUT: Wed Jul 25 14:40:12 2012 router.c:449 unicast route from engdev1.remotewd2.com to c2s
ROUT: Wed Jul 25 14:40:12 2012 router.c:563 writing route for 'c2s'*1 to 127.0.0.1, port 60581
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='c2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='c2s' from='engdev1.remotewd2.com' id='uz18ykn9xgk0mcnaisqlzlwg4k8zya6sa819tpiq'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (io.c:429) tag 7 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 7
ROUT: sx (io.c:328) 7 ready for writing
ROUT: sx (io.c:286) encoding 290 bytes for writing: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='c2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='c2s' from='engdev1.remotewd2.com' id='uz18ykn9xgk0mcnaisqlzlwg4k8zya6sa819tpiq'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 290 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 290 bytes to write
ROUT: sx (io.c:350) tag 7 event 3 data 0xb40c850
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 290 bytes written
ROUT: sx (io.c:383) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:431) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:92) completed nad: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='s2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='s2s' from='engdev1.remotewd2.com' id='62qtfd3x6tj5fgmj0vjz5psgxupqj7hpa7iplmns'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (chain.c:119) calling nad read chain
ROUT: sx (io.c:156) tag 8 event 6 data 0xb40a980
ROUT: Wed Jul 25 14:40:12 2012 router.c:449 unicast route from engdev1.remotewd2.com to s2s
ROUT: Wed Jul 25 14:40:12 2012 router.c:563 writing route for 's2s'*1 to 127.0.0.1, port 60580
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='s2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='s2s' from='engdev1.remotewd2.com' id='62qtfd3x6tj5fgmj0vjz5psgxupqj7hpa7iplmns'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
C2S : Wed Jul 25 14:40:12 2012 c2s.c:1362 read action on fd 6
C2S : sx (io.c:191) 6 ready for reading
C2S : sx (io.c:197) tag 6 event 2 data 0x10653c60
C2S : Wed Jul 25 14:40:12 2012 c2s.c:721 reading from 6
C2S : Wed Jul 25 14:40:12 2012 c2s.c:746 read 580 bytes
C2S : sx (io.c:216) passed 580 read bytes
C2S : sx (chain.c:93) calling io read chain
C2S : sx (io.c:240) decoded read data (580 bytes): <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='c2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='c2s' from='engdev1.remotewd2.com' id='uz18ykn9xgk0mcnaisqlzlwg4k8zya6sa819tpiq'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route><route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='c2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='c2s' from='engdev1.remotewd2.com' id='f6yunleogxnmng2karbtzsj902ymolf3sdygzc4g'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
C2S : sx (io.c:92) completed nad: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='c2s'><iq xmlns='jabber:client' id='uz18ykn9xgk0mcnaisqlzlwg4k8zya6sa819tpiq' from='engdev1.remotewd2.com' to='c2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (io.c:156) tag 6 event 6 data 0x1066aae0
C2S : Wed Jul 25 14:40:12 2012 c2s.c:945 not a c2s packet, dropping
C2S : sx (io.c:92) completed nad: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='c2s'><iq xmlns='jabber:client' id='f6yunleogxnmng2karbtzsj902ymolf3sdygzc4g' from='engdev1.remotewd2.com' to='c2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (io.c:156) tag 6 event 6 data 0x106ed300
C2S : Wed Jul 25 14:40:12 2012 c2s.c:945 not a c2s packet, dropping
ROUT: sx (io.c:429) tag 6 event 1 data 0x0
S2S : sx (io.c:191) 6 ready for reading
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
S2S : sx (io.c:197) tag 6 event 2 data 0x1d8e0cc0
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 6
S2S : Wed Jul 25 14:40:12 2012 router.c:44 reading from 6
ROUT: sx (io.c:328) 6 ready for writing
S2S : Wed Jul 25 14:40:12 2012 router.c:69 read 290 bytes
ROUT: sx (io.c:286) encoding 290 bytes for writing: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='s2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='s2s' from='engdev1.remotewd2.com' id='62qtfd3x6tj5fgmj0vjz5psgxupqj7hpa7iplmns'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
S2S : sx (io.c:216) passed 290 read bytes
ROUT: sx (chain.c:79) calling io write chain
S2S : sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
S2S : sx (io.c:240) decoded read data (290 bytes): <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='s2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='s2s' from='engdev1.remotewd2.com' id='62qtfd3x6tj5fgmj0vjz5psgxupqj7hpa7iplmns'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (sasl_gsasl.c:236) 290 bytes encoded for sasl channel
S2S : sx (io.c:92) completed nad: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='s2s'><iq xmlns='jabber:client' id='62qtfd3x6tj5fgmj0vjz5psgxupqj7hpa7iplmns' from='engdev1.remotewd2.com' to='s2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (io.c:349) handing app 290 bytes to write
S2S : sx (chain.c:119) calling nad read chain
ROUT: sx (io.c:350) tag 6 event 3 data 0xb40bb90
S2S : sx (io.c:156) tag 6 event 6 data 0x1d8e0f30
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 6
S2S : Wed Jul 25 14:40:12 2012 router.c:205 got a packet
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 290 bytes written
S2S : Wed Jul 25 14:40:12 2012 router.c:229 dropping unknown or invalid packet for s2s component proper
ROUT: sx (io.c:383) tag 6 event 0 data 0x0
S2S : Wed Jul 25 14:41:12 2012 main.c:1038 running time checks
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:431) tag 6 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:92) completed nad: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='c2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='c2s' from='engdev1.remotewd2.com' id='f6yunleogxnmng2karbtzsj902ymolf3sdygzc4g'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (chain.c:119) calling nad read chain
ROUT: sx (io.c:156) tag 8 event 6 data 0xb40bf90
ROUT: Wed Jul 25 14:40:12 2012 router.c:449 unicast route from engdev1.remotewd2.com to c2s
ROUT: Wed Jul 25 14:40:12 2012 router.c:563 writing route for 'c2s'*1 to 127.0.0.1, port 60581
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='c2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='c2s' from='engdev1.remotewd2.com' id='f6yunleogxnmng2karbtzsj902ymolf3sdygzc4g'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (io.c:429) tag 7 event 1 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:693 want write
ROUT: Wed Jul 25 14:40:12 2012 router.c:1050 write action on fd 7
ROUT: sx (io.c:328) 7 ready for writing
ROUT: sx (io.c:286) encoding 290 bytes for writing: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='c2s' from='engdev1.remotewd2.com'><iq xmlns='jabber:client' type='get' to='c2s' from='engdev1.remotewd2.com' id='f6yunleogxnmng2karbtzsj902ymolf3sdygzc4g'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 290 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 290 bytes to write
ROUT: sx (io.c:350) tag 7 event 3 data 0xb40a6f0
ROUT: Wed Jul 25 14:40:12 2012 router.c:763 writing to 7
ROUT: Wed Jul 25 14:40:12 2012 router.c:767 290 bytes written
ROUT: sx (io.c:383) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: sx (io.c:431) tag 7 event 0 data 0x0
ROUT: Wed Jul 25 14:40:12 2012 router.c:688 want read
ROUT: Wed Jul 25 14:41:12 2012 main.c:482 running time checks
C2S : Wed Jul 25 14:41:32 2012 c2s.c:583 accept action on fd 8
C2S : Wed Jul 25 14:41:32 2012 [notice] [8] [129.253.54.224, port=17458] connect
C2S : sx (sx.c:61) allocated new sx for 8
C2S : sx (server.c:237) doing server init for sx 8
C2S : sx (server.c:252) waiting for stream header
C2S : sx (server.c:255) tag 8 event 0 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:37 want read
C2S : Wed Jul 25 14:41:32 2012 c2s.c:546 read action on fd 8
C2S : sx (io.c:191) 8 ready for reading
C2S : sx (io.c:197) tag 8 event 2 data 0x106ed2c0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:47 reading from 8
C2S : Wed Jul 25 14:41:32 2012 c2s.c:106 read 212 bytes
C2S : sx (io.c:216) passed 212 read bytes
C2S : sx (chain.c:93) calling io read chain
C2S : sx (io.c:240) decoded read data (212 bytes): <?xml version="1.0"?>
C2S : <stream:stream xmlns:stream="http://etherx.jabber.org/streams" version="1.0" xmlns="jabber:client" to="engdev1.remotewd2.com" xml:lang="en" xmlns:xml="http://www.w3.org/XML/1998/namespace">
C2S :
C2S : sx (server.c:119) stream request: to engdev1.remotewd2.com from (null) version 1.0
C2S : sx (server.c:134) 8 state change from 0 to 1
C2S : sx (server.c:152) stream id is 9182frv826dyjssgfsq3feghzgtcoygyzo0ffvni
C2S : Wed Jul 25 14:41:32 2012 ack.c:30 hacking ack namespace decl onto stream header
C2S : sx (server.c:182) prepared stream response: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' from='engdev1.remotewd2.com' version='1.0' id='9182frv826dyjssgfsq3feghzgtcoygyzo0ffvni' xmlns:ack='http://www.xmpp.org/extensions/xep-0198.html#ns'>
C2S : sx (io.c:256) tag 8 event 1 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:42 want write
C2S : Wed Jul 25 14:41:32 2012 c2s.c:560 write action on fd 8
C2S : sx (io.c:328) 8 ready for writing
C2S : sx (io.c:286) encoding 255 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' from='engdev1.remotewd2.com' version='1.0' id='9182frv826dyjssgfsq3feghzgtcoygyzo0ffvni' xmlns:ack='http://www.xmpp.org/extensions/xep-0198.html#ns'>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (io.c:349) handing app 255 bytes to write
C2S : sx (io.c:350) tag 8 event 3 data 0x106ed2f0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:144 writing to 8
C2S : Wed Jul 25 14:41:32 2012 c2s.c:148 255 bytes written
C2S : sx (server.c:29) stream established
C2S : sx (server.c:39) 8 state change from 1 to 3
C2S : sx (server.c:40) tag 8 event 4 data 0x0
C2S : sx (server.c:45) building features nad
C2S : sx (address.c:34) adding address feature
C2S : sx (sasl_gsasl.c:357) offering sasl mechanisms
C2S : sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 5
C2S : sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 6
C2S : sx (sasl_gsasl.c:377) offering mechanism: PLAIN
C2S : sx (sasl_gsasl.c:377) offering mechanism: DIGEST-MD5
C2S : Wed Jul 25 14:41:32 2012 bind.c:38 not auth'd, offering auth and register
C2S : sx (io.c:383) tag 8 event 0 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:37 want read
C2S : Wed Jul 25 14:41:32 2012 c2s.c:560 write action on fd 8
C2S : sx (io.c:328) 8 ready for writing
C2S : sx (io.c:286) encoding 393 bytes for writing: <stream:features xmlns:stream='http://etherx.jabber.org/streams'><address xmlns='http://affinix.com/jabber/address'>129.253.54.224</address><mechanisms xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><mechanism>PLAIN</mechanism><mechanism>DIGEST-MD5</mechanism></mechanisms><auth xmlns='http://jabber.org/features/iq-auth'/><register xmlns='http://jabber.org/features/iq-register'/></stream:features>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (io.c:349) handing app 393 bytes to write
C2S : sx (io.c:350) tag 8 event 3 data 0x106ed2f0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:144 writing to 8
C2S : Wed Jul 25 14:41:32 2012 c2s.c:148 393 bytes written
C2S : sx (io.c:383) tag 8 event 0 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:37 want read
C2S : Wed Jul 25 14:41:32 2012 c2s.c:546 read action on fd 8
C2S : sx (io.c:191) 8 ready for reading
C2S : sx (io.c:197) tag 8 event 2 data 0x106ed2f0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:47 reading from 8
C2S : Wed Jul 25 14:41:32 2012 c2s.c:106 read 71 bytes
C2S : sx (io.c:216) passed 71 read bytes
C2S : sx (chain.c:93) calling io read chain
C2S : sx (io.c:240) decoded read data (71 bytes): <auth xmlns="urn:ietf:params:xml:ns:xmpp-sasl" mechanism="DIGEST-MD5"/>
C2S : sx (io.c:92) completed nad: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (sasl_gsasl.c:417) auth request from client (mechanism=DIGEST-MD5)
C2S : Wed Jul 25 14:41:32 2012 main.c:427 sx sasl callback: get realm: realm is 'engdev1.remotewd2.com'
C2S : sx (sasl_gsasl.c:472) sasl context initialised for 8
C2S : sx (sasl_gsasl.c:562) sasl handshake in progress (challenge: realm="engdev1.remotewd2.com", nonce="AKKtUFvihyEKPTO4UFeuAA==", qop="auth", charset=utf-8, algorithm=md5-sess)
C2S : sx (chain.c:106) calling nad write chain
C2S : sx (io.c:406) queueing for write: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImVuZ2RldjEucmVtb3Rld2QyLmNvbSIsIG5vbmNlPSJBS0t0VUZ2aWh5RUtQVE80VUZldUFBPT0iLCBxb3A9ImF1dGgiLCBjaGFyc2V0PXV0Zi04LCBhbGdvcml0aG09bWQ1LXNlc3M=</challenge>
C2S : sx (io.c:256) tag 8 event 1 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:42 want write
C2S : Wed Jul 25 14:41:32 2012 c2s.c:560 write action on fd 8
C2S : sx (io.c:328) 8 ready for writing
C2S : sx (io.c:286) encoding 212 bytes for writing: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImVuZ2RldjEucmVtb3Rld2QyLmNvbSIsIG5vbmNlPSJBS0t0VUZ2aWh5RUtQVE80VUZldUFBPT0iLCBxb3A9ImF1dGgiLCBjaGFyc2V0PXV0Zi04LCBhbGdvcml0aG09bWQ1LXNlc3M=</challenge>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (io.c:349) handing app 212 bytes to write
C2S : sx (io.c:350) tag 8 event 3 data 0x106f01a0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:144 writing to 8
C2S : Wed Jul 25 14:41:32 2012 c2s.c:148 212 bytes written
C2S : sx (io.c:383) tag 8 event 0 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:37 want read
C2S : Wed Jul 25 14:41:32 2012 c2s.c:546 read action on fd 8
C2S : sx (io.c:191) 8 ready for reading
C2S : sx (io.c:197) tag 8 event 2 data 0x106f01a0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:47 reading from 8
C2S : Wed Jul 25 14:41:32 2012 c2s.c:106 read 402 bytes
C2S : sx (io.c:216) passed 402 read bytes
C2S : sx (chain.c:93) calling io read chain
C2S : sx (io.c:240) decoded read data (402 bytes): <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl">dXNlcm5hbWU9Im1lcmN1dGlvIixyZWFsbT0iZW5nZGV2MS5yZW1vdGV3ZDIuY29tIixub25jZT0iQUtLdFVGdmloeUVLUFRPNFVGZXVBQT09Iixjbm9uY2U9Ijl4cGFYazBDU3dJbmlEblB6K1dSd2l1bHoxcXVGYzROaHl5aXVNdklLTU09IixuYz0wMDAwMDAwMSxkaWdlc3QtdXJpPSJ4bXBwL2VuZ2RldjEucmVtb3Rld2QyLmNvbSIscW9wPWF1dGgscmVzcG9uc2U9NWZiNzc3YTlhYWQzN2I1MGQzYjgxMDcwM2U0Y2M1MjUsY2hhcnNldD11dGYtOA==</response>
C2S : sx (io.c:92) completed nad: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9Im1lcmN1dGlvIixyZWFsbT0iZW5nZGV2MS5yZW1vdGV3ZDIuY29tIixub25jZT0iQUtLdFVGdmloeUVLUFRPNFVGZXVBQT09Iixjbm9uY2U9Ijl4cGFYazBDU3dJbmlEblB6K1dSd2l1bHoxcXVGYzROaHl5aXVNdklLTU09IixuYz0wMDAwMDAwMSxkaWdlc3QtdXJpPSJ4bXBwL2VuZ2RldjEucmVtb3Rld2QyLmNvbSIscW9wPWF1dGgscmVzcG9uc2U9NWZiNzc3YTlhYWQzN2I1MGQzYjgxMDcwM2U0Y2M1MjUsY2hhcnNldD11dGYtOA==</response>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (sasl_gsasl.c:528) response from client (decoded: username="mercutio",realm="engdev1.remotewd2.com",nonce="AKKtUFvihyEKPTO4UFeuAA==",cnonce="9xpaXk0CSwIniDnPz+WRwiulz1quFc4NhyyiuMvIKMM=",nc=00000001,digest-uri="xmpp/engdev1.remotewd2.com",qop=auth,response=5fb777a9aad37b50d3b810703e4cc525,charset=utf-8)
C2S : sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 12
C2S : sx (sasl_gsasl.c:799) in _sx_sasl_gsasl_callback, property: 3
C2S : Wed Jul 25 14:41:32 2012 main.c:434 sx sasl callback: get pass (authnid=mercutio, realm=engdev1.remotewd2.com)
C2S : Wed Jul 25 14:41:32 2012 authreg_mysql.c:109 prepared sql: SELECT `password` FROM `authreg` WHERE `username` = 'mercutio' AND `realm` = 'engdev1.remotewd2.com'
C2S : sx (sasl_gsasl.c:562) sasl handshake in progress (challenge: rspauth=cf34074f936d3ba55e1b66f85a552751)
C2S : sx (chain.c:106) calling nad write chain
C2S : sx (io.c:406) queueing for write: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD1jZjM0MDc0ZjkzNmQzYmE1NWUxYjY2Zjg1YTU1Mjc1MQ==</challenge>
C2S : sx (io.c:256) tag 8 event 1 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:42 want write
C2S : Wed Jul 25 14:41:32 2012 c2s.c:560 write action on fd 8
C2S : sx (io.c:328) 8 ready for writing
C2S : sx (io.c:286) encoding 120 bytes for writing: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cnNwYXV0aD1jZjM0MDc0ZjkzNmQzYmE1NWUxYjY2Zjg1YTU1Mjc1MQ==</challenge>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (io.c:349) handing app 120 bytes to write
C2S : sx (io.c:350) tag 8 event 3 data 0x106f0920
C2S : Wed Jul 25 14:41:32 2012 c2s.c:144 writing to 8
C2S : Wed Jul 25 14:41:32 2012 c2s.c:148 120 bytes written
C2S : sx (io.c:383) tag 8 event 0 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:37 want read
C2S : Wed Jul 25 14:41:32 2012 c2s.c:546 read action on fd 8
C2S : sx (io.c:191) 8 ready for reading
C2S : sx (io.c:197) tag 8 event 2 data 0x106f0920
C2S : Wed Jul 25 14:41:32 2012 c2s.c:47 reading from 8
C2S : Wed Jul 25 14:41:32 2012 c2s.c:106 read 52 bytes
C2S : sx (io.c:216) passed 52 read bytes
C2S : sx (chain.c:93) calling io read chain
C2S : sx (io.c:240) decoded read data (52 bytes): <response xmlns="urn:ietf:params:xml:ns:xmpp-sasl"/>
C2S : sx (io.c:92) completed nad: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (sasl_gsasl.c:528) response from client (decoded: )
C2S : sx (sasl_gsasl.c:536) sasl handshake completed
C2S : sx (chain.c:106) calling nad write chain
C2S : sx (io.c:406) queueing for write: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
C2S : sx (io.c:256) tag 8 event 1 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:42 want write
C2S : Wed Jul 25 14:41:32 2012 c2s.c:560 write action on fd 8
C2S : sx (io.c:328) 8 ready for writing
C2S : sx (io.c:286) encoding 51 bytes for writing: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (io.c:349) handing app 51 bytes to write
C2S : sx (io.c:350) tag 8 event 3 data 0x106f0920
C2S : Wed Jul 25 14:41:32 2012 c2s.c:144 writing to 8
C2S : Wed Jul 25 14:41:32 2012 c2s.c:148 51 bytes written
C2S : sx (chain.c:28) adding io plugin
C2S : sx (sasl_gsasl.c:398) auth completed, resetting
C2S : sx (sx.c:154) resetting stream state
C2S : sx (sx.c:78) freeing sx for 8
C2S : sx (sx.c:61) allocated new sx for 8
C2S : sx (sx.c:211) finished resetting stream state
C2S : sx (server.c:237) doing server init for sx 8
C2S : sx (server.c:252) waiting for stream header
C2S : sx (server.c:255) tag 8 event 0 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:37 want read
C2S : sx (io.c:383) tag 8 event 0 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:37 want read
C2S : Wed Jul 25 14:41:32 2012 c2s.c:546 read action on fd 8
C2S : sx (io.c:191) 8 ready for reading
C2S : sx (io.c:197) tag 8 event 2 data 0x106f0920
C2S : Wed Jul 25 14:41:32 2012 c2s.c:47 reading from 8
C2S : Wed Jul 25 14:41:32 2012 c2s.c:106 read 212 bytes
C2S : sx (io.c:216) passed 212 read bytes
C2S : sx (chain.c:93) calling io read chain
C2S : sx (sasl_gsasl.c:248) doing sasl decode
C2S : sx (sasl_gsasl.c:264) 212 bytes decoded from sasl channel
C2S : sx (io.c:240) decoded read data (212 bytes): <?xml version="1.0"?>
C2S : <stream:stream xmlns:stream="http://etherx.jabber.org/streams" version="1.0" xmlns="jabber:client" to="engdev1.remotewd2.com" xml:lang="en" xmlns:xml="http://www.w3.org/XML/1998/namespace">
C2S :
C2S : sx (server.c:119) stream request: to engdev1.remotewd2.com from (null) version 1.0
C2S : sx (server.c:134) 8 state change from 0 to 1
C2S : sx (server.c:152) stream id is 9182frv826dyjssgfsq3feghzgtcoygyzo0ffvni
C2S : Wed Jul 25 14:41:32 2012 ack.c:30 hacking ack namespace decl onto stream header
C2S : sx (server.c:182) prepared stream response: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' from='engdev1.remotewd2.com' version='1.0' id='9182frv826dyjssgfsq3feghzgtcoygyzo0ffvni' xmlns:ack='http://www.xmpp.org/extensions/xep-0198.html#ns'>
C2S : sx (io.c:256) tag 8 event 1 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:42 want write
C2S : Wed Jul 25 14:41:32 2012 c2s.c:560 write action on fd 8
C2S : sx (io.c:328) 8 ready for writing
C2S : sx (io.c:286) encoding 255 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' from='engdev1.remotewd2.com' version='1.0' id='9182frv826dyjssgfsq3feghzgtcoygyzo0ffvni' xmlns:ack='http://www.xmpp.org/extensions/xep-0198.html#ns'>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (sasl_gsasl.c:220) doing sasl encode
C2S : sx (sasl_gsasl.c:236) 255 bytes encoded for sasl channel
C2S : sx (io.c:349) handing app 255 bytes to write
C2S : sx (io.c:350) tag 8 event 3 data 0x10653c90
C2S : Wed Jul 25 14:41:32 2012 c2s.c:144 writing to 8
C2S : Wed Jul 25 14:41:32 2012 c2s.c:148 255 bytes written
C2S : sx (server.c:29) stream established
C2S : sx (sx.c:140) authenticating stream (method=SASL/DIGEST-MD5; [email protected])
C2S : sx (sx.c:145) 8 state change from 1 to 4
C2S : sx (sx.c:146) tag 8 event 5 data 0x0
C2S : Wed Jul 25 14:41:32 2012 [notice] [8] DIGEST-MD5 authentication succeeded: [email protected] 129.253.54.224:17458
C2S : sx (server.c:45) building features nad
C2S : sx (sasl_gsasl.c:341) already auth'd, not offering sasl mechanisms
C2S : Wed Jul 25 14:41:32 2012 bind.c:51 auth'd, offering resource bind and session
C2S : sx (io.c:383) tag 8 event 0 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:37 want read
C2S : Wed Jul 25 14:41:32 2012 c2s.c:560 write action on fd 8
C2S : sx (io.c:328) 8 ready for writing
C2S : sx (io.c:286) encoding 304 bytes for writing: <stream:features xmlns:stream='http://etherx.jabber.org/streams'><ack:ack/><bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'><required/></bind><unbind xmlns='urn:ietf:params:xml:ns:xmpp-bind'/><session xmlns='urn:ietf:params:xml:ns:xmpp-session'/><ver xmlns='urn:xmpp:features:rosterver'/></stream:features>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (sasl_gsasl.c:220) doing sasl encode
C2S : sx (sasl_gsasl.c:236) 304 bytes encoded for sasl channel
C2S : sx (io.c:349) handing app 304 bytes to write
C2S : sx (io.c:350) tag 8 event 3 data 0x10653c90
C2S : Wed Jul 25 14:41:32 2012 c2s.c:144 writing to 8
C2S : Wed Jul 25 14:41:32 2012 c2s.c:148 304 bytes written
C2S : sx (io.c:383) tag 8 event 0 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:37 want read
C2S : Wed Jul 25 14:41:32 2012 c2s.c:546 read action on fd 8
ROUT: Wed Jul 25 14:41:12 2012 main.c:487 next time check at 1343252532
ROUT: Wed Jul 25 14:41:32 2012 router.c:1036 read action on fd 7
SM : Wed Jul 25 14:40:12 2012 sm.c:219 got a packet
SM : Wed Jul 25 14:40:12 2012 pkt.c:118 creating new packet
SM : Wed Jul 25 14:40:12 2012 mm.c:632 dispatching pkt-router chain
SM : Wed Jul 25 14:40:12 2012 mm.c:645 calling module session
SM : Wed Jul 25 14:40:12 2012 mm.c:645 calling module disco
SM : Wed Jul 25 14:40:12 2012 mod_disco.c:544 presence from component c2s, issuing discovery request
SM : Wed Jul 25 14:40:12 2012 pkt.c:118 creating new packet
SM : Wed Jul 25 14:40:12 2012 pkt.c:385 delivering pkt to router
SM : Wed Jul 25 14:40:12 2012 mm.c:540 dispatching out-router chain
SM : Wed Jul 25 14:40:12 2012 mm.c:553 calling module privacy
SM : Wed Jul 25 14:40:12 2012 mm.c:560 out-router chain returning 1
SM : sx (chain.c:106) calling nad write chain
SM : sx (io.c:406) queueing for write: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='c2s'><iq xmlns='jabber:client' id='f6yunleogxnmng2karbtzsj902ymolf3sdygzc4g' from='engdev1.remotewd2.com' to='c2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
SM : sx (io.c:429) tag 6 event 1 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:49 want write
SM : Wed Jul 25 14:40:12 2012 sm.c:258 write action on fd 6
SM : sx (io.c:328) 6 ready for writing
SM : sx (io.c:286) encoding 290 bytes for writing: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='c2s'><iq xmlns='jabber:client' id='f6yunleogxnmng2karbtzsj902ymolf3sdygzc4g' from='engdev1.remotewd2.com' to='c2s' type='get'><query xmlns='http://jabber.org/protocol/disco#info'/></iq></route>
SM : sx (chain.c:79) calling io write chain
SM : sx (io.c:349) handing app 290 bytes to write
SM : sx (io.c:350) tag 6 event 3 data 0x149458b0
SM : Wed Jul 25 14:40:12 2012 sm.c:86 writing to 6
SM : Wed Jul 25 14:40:12 2012 sm.c:90 290 bytes written
SM : sx (io.c:383) tag 6 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
SM : sx (io.c:431) tag 6 event 0 data 0x0
SM : Wed Jul 25 14:40:12 2012 sm.c:44 want read
SM : Wed Jul 25 14:40:12 2012 pkt.c:316 freeing pkt
SM : Wed Jul 25 14:40:12 2012 pkt.c:316 freeing pkt
SM : Wed Jul 25 14:40:12 2012 mm.c:652 pkt-router chain returning 0
SM : Wed Jul 25 14:41:32 2012 sm.c:247 read action on fd 6
SM : sx (io.c:191) 6 ready for reading
SM : sx (io.c:197) tag 6 event 2 data 0x149458b0
SM : Wed Jul 25 14:41:32 2012 sm.c:54 reading from 6
SM : Wed Jul 25 14:41:32 2012 sm.c:79 read 319 bytes
SM : sx (io.c:216) passed 319 read bytes
SM : sx (chain.c:93) calling io read chain
SM : sx (io.c:240) decoded read data (319 bytes): <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='engdev1.remotewd2.com' from='c2s'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/session/1.0' sc:c2s='8' action='start' target='[email protected]/aurotripathy-OptiPlex-390' id='be10436d047e58489cbd130e7a7a137ceca676f4'/></route>
SM : sx (io.c:92) completed nad: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s' to='engdev1.remotewd2.com'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/session/1.0' id='be10436d047e58489cbd130e7a7a137ceca676f4' target='[email protected]/aurotripathy-OptiPlex-390' action='start' sc:c2s='8'/></route>
SM : sx (chain.c:119) calling nad read chain
SM : sx (io.c:156) tag 6 event 6 data 0x1495c1e0
SM : Wed Jul 25 14:41:32 2012 sm.c:219 got a packet
SM : Wed Jul 25 14:41:32 2012 pkt.c:118 creating new packet
SM : Wed Jul 25 14:41:32 2012 mm.c:477 dispatching in-router chain
SM : Wed Jul 25 14:41:32 2012 mm.c:491 calling module session
SM : Wed Jul 25 14:41:32 2012 sess.c:111 session requested for [email protected]/aurotripathy-OptiPlex-390
SM : Wed Jul 25 14:41:32 2012 [error] request to start session in non-serviced domain: [email protected]/aurotripathy-OptiPlex-390
SM : sx (chain.c:106) calling nad write chain
SM : sx (io.c:406) queueing for write: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='c2s'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/session/1.0' sc:failed='1' id='be10436d047e58489cbd130e7a7a137ceca676f4' target='[email protected]/aurotripathy-OptiPlex-390' action='start' sc:c2s='8'/></route>
SM : sx (io.c:429) tag 6 event 1 data 0x0
SM : Wed Jul 25 14:41:32 2012 sm.c:49 want write
SM : Wed Jul 25 14:41:32 2012 sm.c:258 write action on fd 6
SM : sx (io.c:328) 6 ready for writing
SM : sx (io.c:286) encoding 333 bytes for writing: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='engdev1.remotewd2.com' to='c2s'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/session/1.0' sc:failed='1' id='be10436d047e58489cbd130e7a7a137ceca676f4' target='[email protected]/aurotripathy-OptiPlex-390' action='start' sc:c2s='8'/></route>
SM : sx (chain.c:79) calling io write chain
SM : sx (io.c:349) handing app 333 bytes to write
SM : sx (io.c:350) tag 6 event 3 data 0x1495d340
SM : Wed Jul 25 14:41:32 2012 sm.c:86 writing to 6
ROUT: sx (io.c:191) 7 ready for reading
ROUT: sx (io.c:197) tag 7 event 2 data 0xb40a640
ROUT: Wed Jul 25 14:41:32 2012 router.c:698 reading from 7
ROUT: Wed Jul 25 14:41:32 2012 router.c:756 read 319 bytes
ROUT: sx (io.c:216) passed 319 read bytes
ROUT: sx (chain.c:93) calling io read chain
ROUT: sx (sasl_gsasl.c:248) doing sasl decode
ROUT: sx (sasl_gsasl.c:264) 319 bytes decoded from sasl channel
ROUT: sx (io.c:240) decoded read data (319 bytes): <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s' to='engdev1.remotewd2.com'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/session/1.0' id='be10436d047e58489cbd130e7a7a137ceca676f4' target='[email protected]/aurotripathy-OptiPlex-390' action='start' sc:c2s='8'/></route>
ROUT: sx (io.c:92) completed nad: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='engdev1.remotewd2.com' from='c2s'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/session/1.0' sc:c2s='8' action='start' target='[email protected]/aurotripathy-OptiPlex-390' id='be10436d047e58489cbd130e7a7a137ceca676f4'/></route>
ROUT: sx (chain.c:119) calling nad read chain
ROUT: sx (io.c:156) tag 7 event 6 data 0xb408360
ROUT: Wed Jul 25 14:41:32 2012 router.c:449 unicast route from c2s to engdev1.remotewd2.com
ROUT: Wed Jul 25 14:41:32 2012 router.c:563 writing route for 'engdev1.remotewd2.com'*1 to 127.0.0.1, port 60582
ROUT: sx (chain.c:106) calling nad write chain
ROUT: sx (io.c:406) queueing for write: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='engdev1.remotewd2.com' from='c2s'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/session/1.0' sc:c2s='8' action='start' target='[email protected]/aurotripathy-OptiPlex-390' id='be10436d047e58489cbd130e7a7a137ceca676f4'/></route>
ROUT: sx (io.c:429) tag 8 event 1 data 0x0
ROUT: Wed Jul 25 14:41:32 2012 router.c:693 want write
ROUT: Wed Jul 25 14:41:32 2012 router.c:1050 write action on fd 8
ROUT: sx (io.c:328) 8 ready for writing
ROUT: sx (io.c:286) encoding 319 bytes for writing: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' to='engdev1.remotewd2.com' from='c2s'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/session/1.0' sc:c2s='8' action='start' target='[email protected]/aurotripathy-OptiPlex-390' id='be10436d047e58489cbd130e7a7a137ceca676f4'/></route>
ROUT: sx (chain.c:79) calling io write chain
ROUT: sx (sasl_gsasl.c:220) doing sasl encode
ROUT: sx (sasl_gsasl.c:236) 319 bytes encoded for sasl channel
ROUT: sx (io.c:349) handing app 319 bytes to write
ROUT: sx (io.c:350) tag 8 event 3 data 0xb40a670
ROUT: Wed Jul 25 14:41:32 2012 router.c:763 writing to 8
ROUT: Wed Jul 25 14:41:32 2012 router.c:767 319 bytes written
ROUT: sx (io.c:383) tag 8 event 0 data 0x0
ROUT: Wed Jul 25 14:41:32 2012 router.c:688 want read
ROUT: sx (io.c:431) tag 8 event 0 data 0x0
ROUT: Wed Jul 25 14:41:32 2012 router.c:688 want read
ROUT: Wed Jul 25 14:41:32 2012 router.c:1036 read action on fd 8
C2S : sx (io.c:191) 8 ready for reading
C2S : sx (io.c:197) tag 8 event 2 data 0x10653c90
C2S : Wed Jul 25 14:41:32 2012 c2s.c:47 reading from 8
C2S : Wed Jul 25 14:41:32 2012 c2s.c:106 read 137 bytes
C2S : sx (io.c:216) passed 137 read bytes
C2S : sx (chain.c:93) calling io read chain
C2S : sx (sasl_gsasl.c:248) doing sasl decode
C2S : sx (sasl_gsasl.c:264) 137 bytes decoded from sasl channel
C2S : sx (io.c:240) decoded read data (137 bytes): <iq type="set" id="bind_1">
C2S : <bind xmlns="urn:ietf:params:xml:ns:xmpp-bind">
C2S : <resource>aurotripathy-OptiPlex-390</resource>
C2S : </bind>
C2S : </iq>
C2S :
C2S : sx (io.c:92) completed nad: <iq xmlns='jabber:client' id='bind_1' type='set'>
C2S : <bind xmlns='urn:ietf:params:xml:ns:xmpp-bind'>
C2S : <resource>aurotripathy-OptiPlex-390</resource>
C2S : </bind>
C2S : </iq>
C2S : sx (chain.c:119) calling nad read chain
C2S : sx (io.c:156) tag 8 event 6 data 0x106f0730
C2S : Wed Jul 25 14:41:32 2012 [notice] [8] bound: [email protected]/aurotripathy-OptiPlex-390
C2S : Wed Jul 25 14:41:32 2012 sm.c:61 built new route nad for [email protected]/aurotripathy-OptiPlex-390 action start target [email protected]/aurotripathy-OptiPlex-390 id be10436d047e58489cbd130e7a7a137ceca676f4
C2S : sx (chain.c:106) calling nad write chain
C2S : sx (io.c:406) queueing for write: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s' to='engdev1.remotewd2.com'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/session/1.0' id='be10436d047e58489cbd130e7a7a137ceca676f4' target='[email protected]/aurotripathy-OptiPlex-390' action='start' sc:c2s='8'/></route>
C2S : sx (io.c:429) tag 6 event 1 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:716 want write
C2S : Wed Jul 25 14:41:32 2012 c2s.c:1373 write action on fd 6
C2S : sx (io.c:328) 6 ready for writing
C2S : sx (io.c:286) encoding 319 bytes for writing: <route xmlns='http://jabberd.jabberstudio.org/ns/component/1.0' from='c2s' to='engdev1.remotewd2.com'><sc:session xmlns:sc='http://jabberd.jabberstudio.org/ns/session/1.0' id='be10436d047e58489cbd130e7a7a137ceca676f4' target='[email protected]/aurotripathy-OptiPlex-390' action='start' sc:c2s='8'/></route>
C2S : sx (chain.c:79) calling io write chain
C2S : sx (io.c:349) handing app 319 bytes to write
C2S : sx (io.c:350) tag 6 event 3 data 0x106ef120
C2S : Wed Jul 25 14:41:32 2012 c2s.c:753 writing to 6
C2S : Wed Jul 25 14:41:32 2012 c2s.c:757 319 bytes written
C2S : sx (io.c:383) tag 6 event 0 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:711 want read
C2S : sx (io.c:431) tag 6 event 0 data 0x0
C2S : Wed Jul 25 14:41:32 2012 c2s.c:711 want read
C2S : Wed Jul 25 14:41:32 2012 c2s.c:1362 read action on fd 6
SM : Wed Jul 25 14:41:32 2012 sm.c:90 333 bytes written
SM : sx (io.c:383) tag 6 event 0 data 0x0
SM : Wed Jul 25 14:41:32 2012 sm.c:44 want read
SM : sx (io.c:431) tag 6 event 0 data 0x0
SM : Wed Jul 25 14:41:32 2012 sm.c:44 want read
SM : Wed Jul 25 14:41:32 2012 pkt.c:316 freeing pkt
SM : Wed Jul 25 14:41:32 2012 mm.c:498 in-router chain returning 0
JBRD: sending INT to 15640 : c2s
JBRD: sending INT to 15639 : s2s
JBRD: sending INT to 15637 : sm
JBRD: sending INT to 15636 : router
Shutting down.
:
_______________________________________________
This is JUser -- a mailing list for end users
of Jabber/XMPP clients.
To unsubscribe, send email to
[email protected]
or go to the following web
page, scroll all the way down,
and type in your email address:
http://mail.jabber.org/mailman/listinfo/juser
_______________________________________________