c2s crash in sasl_server_step

[bmuller]

Here is the gdb backtrace:

#0  0xf7d412ae in sasl_server_step () from /usr/lib/libsasl2.so.2
#1  0x08057dd7 in _sx_sasl_client_process (s=0x85b4040, p=0x80855a0, mech=0xffdca284 "",
    in=0x85429f8 "urn:ietf:params:xml:ns:xmpp-saslresponseaturesurn:ietf:params:xml:ns:xmpp-saslmechanismsmechanismDIGEST-MD5mechanismPLAIN<stream:features xmlns:stream='http://etherx.jabber.org/streams'><mechanisms xm"..., inlen=0) at sasl_cyrus.c:764
#2  0x0805835f in _sx_sasl_process (s=0x85b4040, p=0x80855a0, nad=0x84bcf10) at sasl_cyrus.c:904
#3  0x080543ef in _sx_process_read (s=0x85b4040, buf=0x810aa90) at io.c:125
#4  0x0805481a in sx_can_read (s=0x85b4040) at io.c:218
#5  0x0804fc4a in _c2s_client_mio_callback (m=0x8086938, a=action_READ, fd=0x83db438, data=0x0, arg=0x8138c68) at c2s.c:432
#6  0x08059d89 in _mio_run (m=0x8086938, timeout=5) at mio_impl.h:251
#7  0x08051ed1 in main (argc=0, argv=0x0) at main.c:639

[smoku]

Cyrus SASL isn't supported.

Please use GnuSASL.

[sxw]

We use Cyrus SASL extensively here, I'm happy to help with debugging these problems, especially given then issues with GnuSASL.

In this case it would appear that the mechanism attribute is getting set to an empty string, which is causing the SASL library to become upset.

How repeatable is this problem? Is it just when dealing with requests from a particular client, or is it intermittent? Can you get a packet trace from the server that shows the authentication handshake with the client that crashes it?

Simon.

[tofu]

It has only happened once. There are two clients that connect to the server right now. The one that seems to have triggered it is a http binding client called punjab (http://www.butterfat.net/wiki/Projects/PunJab). It handles a good amount of client connections from it though. I can work on that packet trace for you, thanks.

[smoku]

OK Simon. So please take care of it.

[bmuller]

Here's another trace:

Program terminated with signal 11, Segmentation fault.
#0  0xf7a40fdf in DigestCalcResponse () from /usr/lib/sasl2/libdigestmd5.so.2
(gdb) backtrace
#0  0xf7a40fdf in DigestCalcResponse () from /usr/lib/sasl2/libdigestmd5.so.2
#1  0xf7cb42e7 in sasl_server_step () from /usr/lib/libsasl2.so.2
#2  0x0805e316 in _sx_sasl_client_process (s=0x80d8768, p=0x80811a8, mech=0x0,
    in=0x80e69e0 "dXNlcm5hbWU9ImxvYWR0ZXN0ZXIxIixub25jZT0ialltRXJUeVVOS3JDTDhaaWk3RzhLTlJqVXJmQ216bEhGbE41NTVxS00zOD0iLGNoYXJzZXQ9dXRmLTgscmVhbG09InRlc3QuY2hlc3NwYXJrLmNvbSIscW9wPWF1dGgsY25vbmNlPSJhMDI0NjE0N2I4OTZhMzA1"..., inlen=344) at sasl_cyrus.c:656
#3  0x0805eb7c in _sx_sasl_process (s=0x80d8768, p=0x80811a8, nad=0x80d1f88) at sasl_cyrus.c:796
#4  0x08057d50 in _sx_process_read (s=0x80d8768, buf=0x80d2800) at io.c:125
#5  0x08058179 in sx_can_read (s=0x80d8768) at io.c:218
#6  0x08051411 in _c2s_client_mio_callback (m=0x8097878, a=action_READ, fd=0x80d7230, data=0x0, arg=0x80d2830) at c2s.c:427
#7  0x08060d64 in _mio_run (m=0x8097878, timeout=5) at mio_impl.h:239
#8  0x08055c6c in main (argc=3, argv=0xffb7dd04) at main.c:63

I'll attach code for a client that logs in and out repeatedly. When it logs in, it sends a message to another user that is not logged in. After a few seconds, c2s crashes.

[bmuller]

python twisted script to crash c2s

[tofu]

Just adding another crash for reference.

Program terminated with signal 11, Segmentation fault.
#0  0xf7977fdf in DigestCalcResponse () from /usr/lib/sasl2/libdigestmd5.so.2
(gdb) backtrace
#0  0xf7977fdf in DigestCalcResponse () from /usr/lib/sasl2/libdigestmd5.so.2
#1  0xf7cb42e7 in sasl_server_step () from /usr/lib/libsasl2.so.2
#2  0x08057dd7 in _sx_sasl_client_process (s=0x81321f8, p=0x80855a0, mech=0xf797b320 "\026�\227�\200", 
    in=0x821c5f0 "dXNlcm5hbWU9IjEyYXJzcyIscmVhbG09ImNoZXNzcGFyay5jb20iLG5vbmNlPSJSNTBWZlNkalFtTFB4WEt2Qm8xc3czMnB0dnYzeTRrU2ZuRWxEbmVCSlFVPSIsY25vbmNlPSJkNDFkOGNkOThmMDBiMjA0ZTk4MDA5OThlY2Y4NDI3ZSIsbmM9IjAwMDAwMDAxIixx"..., inlen=336) at sasl_cyrus.c:764
#3  0x0805835f in _sx_sasl_process (s=0x81321f8, p=0x80855a0, nad=0x81cd5c0) at sasl_cyrus.c:904
#4  0x080543ef in _sx_process_read (s=0x81321f8, buf=0x8ae6dd0) at io.c:125
#5  0x0805481a in sx_can_read (s=0x81321f8) at io.c:218
#6  0x0804fc4a in _c2s_client_mio_callback (m=0x8086938, a=action_READ, fd=0x80aa798, data=0x0, arg=0x8276270) at c2s.c:432
#7  0x08059d89 in _mio_run (m=0x8086938, timeout=5) at mio_impl.h:251
#8  0x08051ed1 in main (argc=1919251317, argv=0x656d616e) at main.c:639

[bmuller]

Here's the output from valgrind:

==14039== Invalid read of size 4
==14039==    at 0x647FFDF: (within /usr/lib/sasl2/libdigestmd5.so.2.0.22)
==14039==    by 0x45D42E6: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22)
==14039==    by 0x805E103: _sx_sasl_client_process (sasl_cyrus.c:764)
==14039==    by 0x805E969: _sx_sasl_process (sasl_cyrus.c:904)
==14039==    by 0x805786F: _sx_process_read (io.c:125)
==14039==    by 0x8057C98: sx_can_read (io.c:218)
==14039==    by 0x8050F19: _c2s_client_mio_callback (c2s.c:432)
==14039==    by 0x8060B4F: _mio_run (mio_impl.h:251)
==14039==    by 0x805578E: main (main.c:639)
==14039==  Address 0x0 is not stack'd, malloc'd or (recently) free'd
==14039==
==14039== Process terminating with default action of signal 11 (SIGSEGV): dumping core
==14039==  Access not within mapped region at address 0x0
==14039==    at 0x647FFDF: (within /usr/lib/sasl2/libdigestmd5.so.2.0.22)
==14039==    by 0x45D42E6: sasl_server_step (in /usr/lib/libsasl2.so.2.0.22)
==14039==    by 0x805E103: _sx_sasl_client_process (sasl_cyrus.c:764)
==14039==    by 0x805E969: _sx_sasl_process (sasl_cyrus.c:904)
==14039==    by 0x805786F: _sx_process_read (io.c:125)
==14039==    by 0x8057C98: sx_can_read (io.c:218)
==14039==    by 0x8050F19: _c2s_client_mio_callback (c2s.c:432)
==14039==    by 0x8060B4F: _mio_run (mio_impl.h:251)
==14039==    by 0x805578E: main (main.c:639)

[smoku]

Not touched in 6 months. Cyrus is not supported. Closing. Please reopen is anything new is going on the case.