On Jan 8, 2008 3:14 PM, Tomasz Sterna wrote: > On Wt, 2008-01-08 at 12:42 -0500, Tim Evans wrote: > > --enable-db --disable-mysql --enable-debug --enable-anon
> Since you configured with debug, run c2s and sm with -D option and see > some more messages. I'm getting the same thing as Tim. Here is what I get when I run c2s with -D. This is only the output from when the client first connects until they are disconnected. Tue Jan 8 16:23:00 2008 c2s.c:538 accept action on fd 8 Tue Jan 8 16:23:00 2008 [notice] [8] [192.168.1.115, port=44702] connect sx (sx.c:53) allocated new sx for 8 sx (server.c:236) doing server init for sx 8 sx (server.c:251) waiting for stream header sx (server.c:254) tag 8 event 0 data 0x0 Tue Jan 8 16:23:00 2008 c2s.c:35 want read Tue Jan 8 16:23:00 2008 c2s.c:501 read action on fd 8 sx (io.c:188) 8 ready for reading sx (io.c:194) tag 8 event 2 data 0x680120 Tue Jan 8 16:23:00 2008 c2s.c:45 reading from 8 Tue Jan 8 16:23:00 2008 c2s.c:99 read 22 bytes sx (io.c:210) passed 22 read bytes sx (chain.c:93) calling io read chain sx (io.c:234) decoded read data (22 bytes): <?xml version='1.0' ?> Tue Jan 8 16:23:00 2008 c2s.c:501 read action on fd 8 sx (io.c:188) 8 ready for reading sx (io.c:194) tag 8 event 2 data 0x67fd50 Tue Jan 8 16:23:00 2008 c2s.c:45 reading from 8 Tue Jan 8 16:23:00 2008 c2s.c:99 read 115 bytes sx (io.c:210) passed 115 read bytes sx (chain.c:93) calling io read chain sx (io.c:234) decoded read data (115 bytes): <stream:stream to='inti.local' xmlns='jabber:client' xmlns:stream='http://etherx.jabber.org/streams' version='1.0'> sx (server.c:118) stream request: to inti.local from (null) version 1.0 sx (server.c:133) 8 state change from 0 to 1 sx (server.c:151) stream id is hl99457c2ijdl9pvg26w8qvx3n8it7abtjkxps9r sx (server.c:181) prepared stream response: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' from='inti.local' version='1.0' id='hl99457c2ijdl9pvg26w8qvx3n8it7abtjkxps9r'> sx (io.c:250) tag 8 event 1 data 0x0 Tue Jan 8 16:23:00 2008 c2s.c:40 want write Tue Jan 8 16:23:00 2008 c2s.c:515 write action on fd 8 sx (io.c:322) 8 ready for writing sx (io.c:280) encoding 184 bytes for writing: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' xmlns='jabber:client' from='inti.local' version='1.0' id='hl99457c2ijdl9pvg26w8qvx3n8it7abtjkxps9r'> sx (chain.c:79) calling io write chain sx (io.c:343) handing app 184 bytes to write sx (io.c:344) tag 8 event 3 data 0x680120 Tue Jan 8 16:23:00 2008 c2s.c:137 writing to 8 Tue Jan 8 16:23:00 2008 c2s.c:141 184 bytes written sx (server.c:29) stream established sx (server.c:39) 8 state change from 1 to 3 sx (server.c:40) tag 8 event 4 data 0x0 sx (server.c:45) building features nad sx (sasl_gsasl.c:238) offering sasl mechanisms sx (sasl_gsasl.c:621) in _sx_sasl_gsasl_callback, property: 5 sx (sasl_gsasl.c:258) offering mechanism: PLAIN sx (sasl_gsasl.c:258) offering mechanism: DIGEST-MD5 Tue Jan 8 16:23:00 2008 bind.c:38 not auth'd, offering auth and register sx (io.c:377) tag 8 event 0 data 0x0 Tue Jan 8 16:23:00 2008 c2s.c:35 want read Tue Jan 8 16:23:00 2008 c2s.c:515 write action on fd 8 sx (io.c:322) 8 ready for writing sx (io.c:280) encoding 318 bytes for writing: <stream:features xmlns:stream='http://etherx.jabber.org/streams'><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> sx (chain.c:79) calling io write chain sx (io.c:343) handing app 318 bytes to write sx (io.c:344) tag 8 event 3 data 0x680120 Tue Jan 8 16:23:00 2008 c2s.c:137 writing to 8 Tue Jan 8 16:23:00 2008 c2s.c:141 318 bytes written sx (io.c:377) tag 8 event 0 data 0x0 Tue Jan 8 16:23:00 2008 c2s.c:35 want read Tue Jan 8 16:23:00 2008 c2s.c:501 read action on fd 8 sx (io.c:188) 8 ready for reading sx (io.c:194) tag 8 event 2 data 0x680120 Tue Jan 8 16:23:00 2008 c2s.c:45 reading from 8 Tue Jan 8 16:23:00 2008 c2s.c:99 read 71 bytes sx (io.c:210) passed 71 read bytes sx (chain.c:93) calling io read chain sx (io.c:234) decoded read data (71 bytes): <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/> sx (io.c:89) completed nad: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5'/> sx (chain.c:119) calling nad read chain sx (sasl_gsasl.c:291) auth request from client (mechanism=DIGEST-MD5) Tue Jan 8 16:23:00 2008 main.c:346 sx sasl callback: get realm: realm is 'inti.local' sx (sasl_gsasl.c:334) sasl context initialised for 8 sx (sasl_gsasl.c:395) sasl handshake in progress (challenge: realm="inti.local", nonce="FhSBrlMkiSNB3bkvqM9/4w==", qop="auth, auth-int", charset=utf-8, algorithm=md5-sess) sx (chain.c:106) calling nad write chain sx (io.c:400) queueing for write: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImludGkubG9jYWwiLCBub25jZT0iRmhTQnJsTWtpU05CM2JrdnFNOS80dz09IiwgcW9wPSJhdXRoLCBhdXRoLWludCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge> sx (io.c:250) tag 8 event 1 data 0x0 Tue Jan 8 16:23:00 2008 c2s.c:40 want write Tue Jan 8 16:23:00 2008 c2s.c:515 write action on fd 8 sx (io.c:322) 8 ready for writing sx (io.c:280) encoding 212 bytes for writing: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImludGkubG9jYWwiLCBub25jZT0iRmhTQnJsTWtpU05CM2JrdnFNOS80dz09IiwgcW9wPSJhdXRoLCBhdXRoLWludCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge> sx (chain.c:79) calling io write chain sx (io.c:343) handing app 212 bytes to write sx (io.c:344) tag 8 event 3 data 0x684290 Tue Jan 8 16:23:00 2008 c2s.c:137 writing to 8 Tue Jan 8 16:23:00 2008 c2s.c:141 212 bytes written sx (io.c:377) tag 8 event 0 data 0x0 Tue Jan 8 16:23:00 2008 c2s.c:35 want read Tue Jan 8 16:23:00 2008 c2s.c:501 read action on fd 8 sx (io.c:188) 8 ready for reading sx (io.c:194) tag 8 event 2 data 0x684290 Tue Jan 8 16:23:00 2008 c2s.c:45 reading from 8 Tue Jan 8 16:23:00 2008 c2s.c:99 read 374 bytes sx (io.c:210) passed 374 read bytes sx (chain.c:93) calling io read chain sx (io.c:234) decoded read data (374 bytes): <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9InNhaW50ZGV2IixyZWFsbT0iaW50aS5sb2NhbCIsbm9uY2U9IkZoU0JybE1raVNOQjNia3ZxTTkvNHc9PSIsY25vbmNlPSJ6eDFhZUhqRVphTmlOdVJJcnhrdEtUUzRXWE81ZDBNMWV5SnJWSzJPRG5RPSIsbmM9MDAwMDAwMDEscW9wPWF1dGgtaW50LG1heGJ1Zj00MDk2LGRpZ2VzdC11cmk9InhtcHAvaW50aS5sb2NhbCIscmVzcG9uc2U9NmVhYTg4ODFhY2Y2NDVmYjBmMjg0YjVjMTcyZjg3ZjI=</response> sx (io.c:89) completed nad: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>dXNlcm5hbWU9InNhaW50ZGV2IixyZWFsbT0iaW50aS5sb2NhbCIsbm9uY2U9IkZoU0JybE1raVNOQjNia3ZxTTkvNHc9PSIsY25vbmNlPSJ6eDFhZUhqRVphTmlOdVJJcnhrdEtUUzRXWE81ZDBNMWV5SnJWSzJPRG5RPSIsbmM9MDAwMDAwMDEscW9wPWF1dGgtaW50LG1heGJ1Zj00MDk2LGRpZ2VzdC11cmk9InhtcHAvaW50aS5sb2NhbCIscmVzcG9uc2U9NmVhYTg4ODFhY2Y2NDVmYjBmMjg0YjVjMTcyZjg3ZjI=</response> sx (chain.c:119) calling nad read chain sx (sasl_gsasl.c:371) response from client (decoded: username="saintdev",realm="inti.local",nonce="FhSBrlMkiSNB3bkvqM9/4w==",cnonce="zx1aeHjEZaNiNuRIrxktKTS4WXO5d0M1eyJrVK2ODnQ=",nc=00000001,qop=auth-int,maxbuf=4096,digest-uri="xmpp/inti.local",response=6eaa8881acf645fb0f284b5c172f87f2) sx (sasl_gsasl.c:412) sasl handshake failed; (30): SASL mechanism could not parse input sx (chain.c:106) calling nad write chain sx (io.c:400) queueing for write: <failure xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><malformed-request/></failure> sx (io.c:250) tag 8 event 1 data 0x0 Tue Jan 8 16:23:00 2008 c2s.c:40 want write Tue Jan 8 16:23:00 2008 c2s.c:515 write action on fd 8 sx (io.c:322) 8 ready for writing sx (io.c:280) encoding 80 bytes for writing: <failure xmlns='urn:ietf:params:xml:ns:xmpp-sasl'><malformed-request/></failure> sx (chain.c:79) calling io write chain sx (io.c:343) handing app 80 bytes to write sx (io.c:344) tag 8 event 3 data 0x6841d0 Tue Jan 8 16:23:00 2008 c2s.c:137 writing to 8 Tue Jan 8 16:23:00 2008 c2s.c:141 80 bytes written sx (io.c:377) tag 8 event 0 data 0x0 Tue Jan 8 16:23:00 2008 c2s.c:35 want read Tue Jan 8 16:23:00 2008 c2s.c:501 read action on fd 8 sx (io.c:492) 8 state change from 3 to 6 sx (io.c:493) tag 8 event 7 data 0x0 Tue Jan 8 16:23:00 2008 c2s.c:520 close action on fd 8 Tue Jan 8 16:23:00 2008 [notice] [8] [192.168.1.115, port=44702] disconnect jid=unbound, packets: 0 sx (sx.c:70) freeing sx for 8 sx (sx.c:104) freeing 2 env plugins sx (sasl_gsasl.c:610) cleaning up conn state -- -Nathan Caldwell _______________________________________________ Jabberd2 mailing list [email protected] http://lists.xiaoka.com/listinfo.cgi/jabberd2-xiaoka.com
