Hello list, today I made jabberd 2.2.11 segfault :) First of all: I was developing an implementation of the "jabberd 2.0 Component Protocol" and maybe I was doing some ugly stuff - but you'll agree me when I say that this should not make jabberd2 segfault :)
Here is what I did: W: <stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='de' version='1.0'> R: <stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='zixbt01lq257lfyy6hvyl3si7bdehy4gg1sa1uvs'> <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> W: <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5' /> R: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>[...]</challenge> W: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>[...]</response> R: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>[...]</challenge> W: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl' /> R: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/> W: <stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='de' version='1.0' > R: <stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='w00igzgngcl2feknpx26w6md8fna9j25k3n124oi'> <stream:features xmlns:stream='http://etherx.jabber.org/streams'/> W: <bind name='[...]' /> ... and here it passed away. I traced the segfault down to router/router.c on line 889 (function _router_sx_callback): if(NAD_NURI_L(nad, NAD_ENS(nad, 0)) != strlen(uri_COMPONENT) || \ strncmp(uri_COMPONENT, NAD_NURI(nad, NAD_ENS(nad, 0)), \ strlen(uri_COMPONENT)) != 0) { [...] In my case NAD_ENS(nad, 0) returned -1 and nad->nss pointed to NULL. I'm not that deep into the jabberd2-code, but I think that at this point exists two issues: NAD_ENS(nad, 0) should not return -1 (even its unsigned representation is quite too big) because it is being used as Index in the Macro NAD_NURI_L later on. nad->nss should not be NULL, as it is used by the Macro NAD_NURI_L without any further checks. Does anyone on the list have an idea why all this happens and maybe where a good start could be if I want to write a small patch? Kind regards, Bernd P.S.: I attached the debug-output from the router-process -- \\\||/// \\ - - // ( @ @ ) -oOo--( )--oOo------------------------------------------------------- Firma Bernd Holzmüller www.tiggerswelt.net i...@tiggerswelt.net Mönchstrasse 25 Tel: 07 11 / 550 425-90 70191 Stuttgart Fax: 07 11 / 550 425-99 Deutschland/Germany OpenPGP/GnuPG: 0x957C378B
Wed Aug 18 00:16:01 2010 [notice] starting up Wed Aug 18 00:16:01 2010 [info] process id is 6415, written to /root/xmpp/router.pid Wed Aug 18 00:16:01 2010 user.c:33 loading user table Wed Aug 18 00:16:01 2010 user.c:85 remembering user 'jabberd' Wed Aug 18 00:16:01 2010 [notice] loaded user table (1 users) Wed Aug 18 00:16:01 2010 aci.c:37 loading aci Wed Aug 18 00:16:01 2010 aci.c:56 building list for 'all' Wed Aug 18 00:16:01 2010 aci.c:77 added 'jabberd' Wed Aug 18 00:16:01 2010 filter.c:51 loading filter Wed Aug 18 00:16:01 2010 filter.c:93 building filter list Wed Aug 18 00:16:01 2010 [notice] loaded filters (0 rules) sx (sasl_gsasl.c:913) initialising sasl plugin sx (sasl_gsasl.c:941) sasl context initialised sx (env.c:75) plugin initialised (index 0) Wed Aug 18 00:16:01 2010 [notice] [0.0.0.0, port=5347] listening for incoming connections Wed Aug 18 00:16:03 2010 router.c:1073 accept action on fd 5 Wed Aug 18 00:16:03 2010 [notice] [127.0.0.1, port=39156] connect sx (sx.c:51) allocated new sx for 5 Wed Aug 18 00:16:03 2010 router.c:1103 new component (0x80772e0) "127.0.0.1:39156" sx (server.c:236) doing server init for sx 5 sx (server.c:251) waiting for stream header sx (server.c:254) tag 5 event 0 data 0x0 Wed Aug 18 00:16:03 2010 main.c:456 running time checks Wed Aug 18 00:16:03 2010 main.c:461 next time check at 1282083423 Wed Aug 18 00:16:03 2010 router.c:1024 read action on fd 5 sx (io.c:191) 5 ready for reading sx (io.c:197) tag 5 event 2 data 0x807e390 Wed Aug 18 00:16:03 2010 router.c:663 reading from 5 Wed Aug 18 00:16:03 2010 router.c:721 read 22 bytes sx (io.c:216) passed 22 read bytes sx (chain.c:93) calling io read chain sx (io.c:240) decoded read data (22 bytes): <?xml version="1.0"?> Wed Aug 18 00:16:03 2010 router.c:1024 read action on fd 5 sx (io.c:191) 5 ready for reading sx (io.c:197) tag 5 event 2 data 0x807e7b0 Wed Aug 18 00:16:03 2010 router.c:663 reading from 5 Wed Aug 18 00:16:03 2010 router.c:721 read 92 bytes sx (io.c:216) passed 92 read bytes sx (chain.c:93) calling io read chain sx (io.c:240) decoded read data (92 bytes): <stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='de' version='1.0' > sx (server.c:118) stream request: to (null) from (null) version 1.0 sx (server.c:133) 5 state change from 0 to 1 sx (server.c:151) stream id is lbab9tt9zi73joj9g6fs5pij21lwzpgk0rwalqkl sx (server.c:181) prepared stream response: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='lbab9tt9zi73joj9g6fs5pij21lwzpgk0rwalqkl'> sx (io.c:256) tag 5 event 1 data 0x0 Wed Aug 18 00:16:03 2010 router.c:658 want write Wed Aug 18 00:16:03 2010 router.c:1038 write action on fd 5 sx (io.c:328) 5 ready for writing 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='lbab9tt9zi73joj9g6fs5pij21lwzpgk0rwalqkl'> sx (chain.c:79) calling io write chain sx (io.c:349) handing app 144 bytes to write sx (io.c:350) tag 5 event 3 data 0x807e798 Wed Aug 18 00:16:03 2010 router.c:728 writing to 5 Wed Aug 18 00:16:03 2010 router.c:732 144 bytes written sx (server.c:29) stream established sx (server.c:39) 5 state change from 1 to 3 sx (server.c:40) tag 5 event 4 data 0x0 sx (server.c:45) building features nad sx (sasl_gsasl.c:355) offering sasl mechanisms sx (sasl_gsasl.c:375) offering mechanism: DIGEST-MD5 sx (io.c:383) tag 5 event 0 data 0x0 Wed Aug 18 00:16:03 2010 router.c:653 want read Wed Aug 18 00:16:03 2010 router.c:1038 write action on fd 5 sx (io.c:328) 5 ready for writing 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> sx (chain.c:79) calling io write chain sx (io.c:349) handing app 182 bytes to write sx (io.c:350) tag 5 event 3 data 0x807e798 Wed Aug 18 00:16:03 2010 router.c:728 writing to 5 Wed Aug 18 00:16:03 2010 router.c:732 182 bytes written sx (io.c:383) tag 5 event 0 data 0x0 Wed Aug 18 00:16:03 2010 router.c:653 want read Wed Aug 18 00:16:03 2010 router.c:1024 read action on fd 5 sx (io.c:191) 5 ready for reading sx (io.c:197) tag 5 event 2 data 0x807e798 Wed Aug 18 00:16:03 2010 router.c:663 reading from 5 Wed Aug 18 00:16:03 2010 router.c:721 read 72 bytes sx (io.c:216) passed 72 read bytes sx (chain.c:93) calling io read chain sx (io.c:240) decoded read data (72 bytes): <auth xmlns='urn:ietf:params:xml:ns:xmpp-sasl' mechanism='DIGEST-MD5' /> sx (io.c:92) 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:412) auth request from client (mechanism=DIGEST-MD5) sx (sasl_gsasl.c:467) sasl context initialised for 5 sx (sasl_gsasl.c:779) in _sx_sasl_gsasl_callback, property: 13 sx (sasl_gsasl.c:547) sasl handshake in progress (challenge: realm="jabberd-router", nonce="r2HgC9Um+wogMKa0El889w==", qop="auth", charset=utf-8, algorithm=md5-sess) sx (chain.c:106) calling nad write chain sx (io.c:406) queueing for write: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9InIySGdDOVVtK3dvZ01LYTBFbDg4OXc9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge> sx (io.c:256) tag 5 event 1 data 0x0 Wed Aug 18 00:16:03 2010 router.c:658 want write Wed Aug 18 00:16:03 2010 router.c:1038 write action on fd 5 sx (io.c:328) 5 ready for writing sx (io.c:286) encoding 204 bytes for writing: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>cmVhbG09ImphYmJlcmQtcm91dGVyIiwgbm9uY2U9InIySGdDOVVtK3dvZ01LYTBFbDg4OXc9PSIsIHFvcD0iYXV0aCIsIGNoYXJzZXQ9dXRmLTgsIGFsZ29yaXRobT1tZDUtc2Vzcw==</challenge> sx (chain.c:79) calling io write chain sx (io.c:349) handing app 204 bytes to write sx (io.c:350) tag 5 event 3 data 0x807f5e8 Wed Aug 18 00:16:03 2010 router.c:728 writing to 5 Wed Aug 18 00:16:03 2010 router.c:732 204 bytes written sx (io.c:383) tag 5 event 0 data 0x0 Wed Aug 18 00:16:03 2010 router.c:653 want read Wed Aug 18 00:16:03 2010 router.c:1024 read action on fd 5 sx (io.c:191) 5 ready for reading sx (io.c:197) tag 5 event 2 data 0x807f5e8 Wed Aug 18 00:16:03 2010 router.c:663 reading from 5 Wed Aug 18 00:16:03 2010 router.c:721 read 378 bytes sx (io.c:216) passed 378 read bytes sx (chain.c:93) calling io read chain sx (io.c:240) decoded read data (378 bytes): <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>[...]</response> sx (io.c:92) completed nad: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>[...]</response> sx (chain.c:119) calling nad read chain sx (sasl_gsasl.c:523) response from client (decoded: [...]) sx (sasl_gsasl.c:779) in _sx_sasl_gsasl_callback, property: 12 sx (sasl_gsasl.c:779) in _sx_sasl_gsasl_callback, property: 3 Wed Aug 18 00:16:03 2010 main.c:209 sx sasl callback: get pass (authnid=jabberd, realm=jabberd-router) sx (sasl_gsasl.c:547) sasl handshake in progress (challenge: [...]) sx (chain.c:106) calling nad write chain sx (io.c:406) queueing for write: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>[...]</challenge> sx (io.c:256) tag 5 event 1 data 0x0 Wed Aug 18 00:16:03 2010 router.c:658 want write Wed Aug 18 00:16:03 2010 router.c:1038 write action on fd 5 sx (io.c:328) 5 ready for writing sx (io.c:286) encoding 120 bytes for writing: <challenge xmlns='urn:ietf:params:xml:ns:xmpp-sasl'>[...]</challenge> sx (chain.c:79) calling io write chain sx (io.c:349) handing app 120 bytes to write sx (io.c:350) tag 5 event 3 data 0x807f2c0 Wed Aug 18 00:16:03 2010 router.c:728 writing to 5 Wed Aug 18 00:16:03 2010 router.c:732 120 bytes written sx (io.c:383) tag 5 event 0 data 0x0 Wed Aug 18 00:16:03 2010 router.c:653 want read Wed Aug 18 00:16:03 2010 router.c:1024 read action on fd 5 sx (io.c:191) 5 ready for reading sx (io.c:197) tag 5 event 2 data 0x807f2c0 Wed Aug 18 00:16:03 2010 router.c:663 reading from 5 Wed Aug 18 00:16:03 2010 router.c:721 read 53 bytes sx (io.c:216) passed 53 read bytes sx (chain.c:93) calling io read chain sx (io.c:240) decoded read data (53 bytes): <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl' /> sx (io.c:92) completed nad: <response xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/> sx (chain.c:119) calling nad read chain sx (sasl_gsasl.c:523) response from client (decoded: ) sx (sasl_gsasl.c:531) sasl handshake completed sx (chain.c:106) calling nad write chain sx (io.c:406) queueing for write: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/> sx (io.c:256) tag 5 event 1 data 0x0 Wed Aug 18 00:16:03 2010 router.c:658 want write Wed Aug 18 00:16:03 2010 router.c:1038 write action on fd 5 sx (io.c:328) 5 ready for writing sx (io.c:286) encoding 51 bytes for writing: <success xmlns='urn:ietf:params:xml:ns:xmpp-sasl'/> sx (chain.c:79) calling io write chain sx (io.c:349) handing app 51 bytes to write sx (io.c:350) tag 5 event 3 data 0x807f298 Wed Aug 18 00:16:03 2010 router.c:728 writing to 5 Wed Aug 18 00:16:03 2010 router.c:732 51 bytes written sx (chain.c:28) adding io plugin sx (sasl_gsasl.c:396) auth completed, resetting sx (sx.c:144) resetting stream state sx (sx.c:68) freeing sx for 5 sx (sx.c:51) allocated new sx for 5 sx (sx.c:199) finished resetting stream state sx (server.c:236) doing server init for sx 5 sx (server.c:251) waiting for stream header sx (server.c:254) tag 5 event 0 data 0x0 Wed Aug 18 00:16:03 2010 router.c:653 want read sx (io.c:383) tag 5 event 0 data 0x0 Wed Aug 18 00:16:03 2010 router.c:653 want read Wed Aug 18 00:16:03 2010 router.c:1024 read action on fd 5 sx (io.c:191) 5 ready for reading sx (io.c:197) tag 5 event 2 data 0x807f298 Wed Aug 18 00:16:03 2010 router.c:663 reading from 5 Wed Aug 18 00:16:03 2010 router.c:721 read 92 bytes sx (io.c:216) passed 92 read bytes sx (chain.c:93) calling io read chain sx (sasl_gsasl.c:246) doing sasl decode sx (sasl_gsasl.c:262) 92 bytes decoded from sasl channel sx (io.c:240) decoded read data (92 bytes): <stream:stream xmlns:stream='http://etherx.jabber.org/streams' xml:lang='de' version='1.0' > sx (server.c:118) stream request: to (null) from (null) version 1.0 sx (server.c:133) 5 state change from 0 to 1 sx (server.c:151) stream id is 8rosg72xehqk6838ao5aelvfcrpyi9jr18jhflft sx (server.c:181) prepared stream response: <?xml version='1.0'?><stream:stream xmlns:stream='http://etherx.jabber.org/streams' version='1.0' id='8rosg72xehqk6838ao5aelvfcrpyi9jr18jhflft'> sx (io.c:256) tag 5 event 1 data 0x0 Wed Aug 18 00:16:03 2010 router.c:658 want write Wed Aug 18 00:16:03 2010 router.c:1038 write action on fd 5 sx (io.c:328) 5 ready for writing 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='8rosg72xehqk6838ao5aelvfcrpyi9jr18jhflft'> sx (chain.c:79) calling io write chain sx (sasl_gsasl.c:218) doing sasl encode sx (sasl_gsasl.c:234) 144 bytes encoded for sasl channel sx (io.c:349) handing app 144 bytes to write sx (io.c:350) tag 5 event 3 data 0x807e390 Wed Aug 18 00:16:03 2010 router.c:728 writing to 5 Wed Aug 18 00:16:03 2010 router.c:732 144 bytes written sx (server.c:29) stream established sx (sx.c:130) authenticating stream (method=SASL/DIGEST-MD5; id=jabb...@jabberd-router) sx (sx.c:135) 5 state change from 1 to 4 sx (sx.c:136) tag 5 event 5 data 0x0 Wed Aug 18 00:16:03 2010 [notice] [127.0.0.1, port=39156] authenticated as jabb...@jabberd-router sx (server.c:45) building features nad sx (sasl_gsasl.c:339) already auth'd, not offering sasl mechanisms sx (io.c:383) tag 5 event 0 data 0x0 Wed Aug 18 00:16:03 2010 router.c:653 want read Wed Aug 18 00:16:03 2010 router.c:1038 write action on fd 5 sx (io.c:328) 5 ready for writing sx (io.c:286) encoding 66 bytes for writing: <stream:features xmlns:stream='http://etherx.jabber.org/streams'/> sx (chain.c:79) calling io write chain sx (sasl_gsasl.c:218) doing sasl encode sx (sasl_gsasl.c:234) 66 bytes encoded for sasl channel sx (io.c:349) handing app 66 bytes to write sx (io.c:350) tag 5 event 3 data 0x807e390 Wed Aug 18 00:16:03 2010 router.c:728 writing to 5 Wed Aug 18 00:16:03 2010 router.c:732 66 bytes written sx (io.c:383) tag 5 event 0 data 0x0 Wed Aug 18 00:16:03 2010 router.c:653 want read Wed Aug 18 00:16:03 2010 router.c:1024 read action on fd 5 sx (io.c:191) 5 ready for reading sx (io.c:197) tag 5 event 2 data 0x807e390 Wed Aug 18 00:16:03 2010 router.c:663 reading from 5 Wed Aug 18 00:16:03 2010 router.c:721 read 39 bytes sx (io.c:216) passed 39 read bytes sx (chain.c:93) calling io read chain sx (sasl_gsasl.c:246) doing sasl decode sx (sasl_gsasl.c:262) 39 bytes decoded from sasl channel sx (io.c:240) decoded read data (39 bytes): <bind name='some.domain' /> sx (io.c:92) completed nad: <bind name='some.domain'/> sx (chain.c:119) calling nad read chain sx (io.c:156) tag 5 event 6 data 0x807dab0
