Crash when receiving SOAP SLO request and log level is DEBUG
Description
Environment
Debian stable
is duplicated by
Activity
Scott Cantor November 18, 2009 at 3:46 PM
http://svn.middleware.georgetown.edu/view/cpp-log4shib?view=rev&revision=70
Fix will be released in log4shib 1.0.4.
Scott Cantor November 18, 2009 at 3:15 PM
From a little googling, it appears that vararg handling changed on x86_64, perhaps got more strict or something. Seems as though everybody using vsnprintf had to apply patches all over the place to fix crashes. I think the problem shows up when you give it large enough input data, so typical logging doesn't get bit by it, but dumping XML out does.
The fix will certainly be to the logging code, not sure what it actually is yet. I'll check upstream and see if log4cpp has anything for this, but I doubt it.
André Cruz November 18, 2009 at 3:09 PM
As for the XML issue, I checked the log and the XML is fine over there... So either it was the paste or Jira who mangled it...
Scott Cantor November 18, 2009 at 3:04 PM
The crash seems to be 64-bit related, I reproduced on Red Hat x64 but not i386. Not sure how any logging could work if this is crashing, but it's probably a log4cpp bug.
I can't speak to the XML, but I don't think that could be what the IdP is sending. It's corrupted right in the middle of the Issuer/Signature element area, and that's not really code that would be broken. I think you just have a formatting issue in the log or with what you cut/pasted it from.
André Cruz November 18, 2009 at 2:34 PM
The log, minus the IP addresses, is exactly what passed on the wire. So if there's a problem with the XML, it should be a bug.
andre@SS0-PS02:~$ g++ -v
Using built-in specs.
Target: x86_64-linux-gnu
Configured with: ../src/configure -v --with-pkgversion='Debian 4.3.2-1.1' --with-bugurl=file:///usr/share/doc/gcc-4.3/README.Bugs --enable-languages=c,c+,fortran,objc,obj-c+ --prefix=/usr --enable-shared --with-system-zlib --libexecdir=/usr/lib --without-included-gettext --enable-threads=posix --enable-nls --with-gxx-include-dir=/usr/include/c++/4.3 --program-suffix=-4.3 --enable-clocale=gnu --enable-libstdcxx-debug --enable-objc-gc --enable-mpfr --enable-cld --enable-checking=release --build=x86_64-linux-gnu --host=x86_64-linux-gnu --target=x86_64-linux-gnu
Thread model: posix
gcc version 4.3.2 (Debian 4.3.2-1.1)
010.135.035.196.40928-010.135.035.197.00080: POST /Shibboleth.sso/SLO/SOAP HTTP/1.1
Cache-control: no-cache, no-store
Pragma: no-cache
Content-Type: text/xml
SOAPAction: http://www.oasis-open.org/committees/security
User-Agent: Jakarta Commons-HttpClient/3.1
Host: sso2.sso.bk.sapo.pt
Content-Length: 2967
010.135.035.196.40928-010.135.035.197.00080: <?xml version="1.0" encoding="UTF-8"?>
<soap11:Envelope xmlns:soap11="http://schemas.xmlsoap.org/soap/envelope/"><soap11:Body><saml2p:LogoutRequest Destination="http://sso2.sso.bk.sapo.pt/Shibboleth.sso/SLO/SOAP" ID="_71f950d82ded2ecede0fae581b29b29f" IssueInstant="2009-11-18T10:22:29.345Z" Version="2.0" xmlns:saml2p="urn:oasis:names:tc:SAML:2.0:protocol"><saml2:Issuer xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion">https://idp.sapo.pt/shibboleth</saml2:Issuer><ds:Signature xmlns:ds="http://www.w3.org/2000/09/xmldsig#">
<ds:SignedInfo>
<ds:CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/>
<ds:SignatureMethod Algorithm="http://www.w3.org/2000/09/xmldsig#rsa-sha1"/>
<ds:Reference URI="#_71f950d82ded2ecede0fae581b29b29f">
<ds:Transforms>
<ds:Transform Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature"/>
<ds:Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"><ec:InclusiveNamespaces PrefixList="ds saml2 saml2p" xmlns:ec="http://www.w3.org/2001/10/xml-exc-c14n#"/></ds:Transform>
</ds:Transforms>
<ds:DigestMethod Algorithm="http://www.w3.org/2000/09/xmldsig#sha1"/>
<ds:DigestValue>oVN13v1ewhVQHbL3JoUbNHMKo9s=</ds:DigestValue>
</ds:Reference>
</ds:SignedInfo>
<ds:SignatureValue>
n35LbfFQDPFy9fCln4IrhB+dReHCKH+T5zYG3Gxx9zr4MslYWyGUkAiDWz31B+Hk3IGWhx/uVNwg
yuk1m+MFZ/BjnFuLzJ342XDBu/FddiawqyBZf6fowAMdR1aO1p0wvzfOe6zQji1henuEKJxNDvIG
+LAXhvJlkeg7vfa+wDxXYhHOa5nk+fN5krTNAk8iKAc3YIM
010.135.035.196.40928-010.135.035.197.00080: fa7DrB32FEWp/KdsYBj0CDQNEQTwE
JyC0G2mvpWOp3NAGJruVaTUffNWV38WFjTJZ9bakPRFLhX2yyX39wRUT14my9p3AD73rYS1W1fCP
BP9knm8/GNKGJ5p2QCUdA8nXVbvJMGFB823IuQ==
</ds:SignatureValue>
<ds:KeyInfo><ds:X509Data><ds:X509Certificate>MIIC8jCCAlsCAQMwDQYJKoZIhvcNAQEFBQAwbDELMAkGA1UEBhMCUFQxDzANBgNVBAgTBkxpc2Jv
bjEPMA0GA1UEBxMGTGlzYm9uMRQwEgYDVQQKEwtTQVBPIHRlc3RlczEPMA0GA1UECxMGU2VndWxh
MRQwEgYDVQQDEwtTQVBPIHRlc3RlczAeFw0wNzEyMTcxNjU1NDVaFw0xNzEyMTQxNjU1NDVaMIGS
MQswCQYDVQQGEwJQVDEPMA0GA1UECBMGTGlzYm9uMQ8wDQYDVQQHEwZMaXNib24xDTALBgNVBAoT
BFNBUE8xDzANBgNVBAsTBlNlZ3VsYTEcMBoGA1UEAxMTc3NvMS5zc28uYmsuc2Fwby5wdDEjMCEG
CSqGSIb3DQEJARYUYW5kcmUuY3J1ekBzZWd1bGEucHQwggEiMA0GCSqGSIb3DQEBAQUAA4IBDwAw
ggEKAoIBAQC3iVT3FJ3LWEAoCwoIk2WjU15pXBL5BRGjTDTUvEFA4iKPVCa3oKdqG8PESENnyu1p
XFvjWWfRMP2tE7uBunxUttQt7Ji72e4aMJAas5rcIGycze5vS71hHGkpNejZBpbmow781D+K/hqr
O1PR8EIF9OWgeLZRZmvtS1zcx8ut1PZVPY5nBygMQulPr6J2cucnjI1lgJGwT3ssbHiHLP+TmqoH
AjEkA3iN8YhUgvL+IOOeHS6P66I0nasy9WunAzNTVyxh/LnYxdvHI+Ma5IiYLGI3groSA1+qONjO
jyetMtTHYznINo5PoPZTKgzBYSnJmCjK6BcGjPzNoxhhcueRAgMBAAEwDQYJKoZIhvcNAQEFBQAD
gYEAbplbVQRqGVAv/nDIfYyARq2bGqU3emIGLrWDZusBnjz+wwl2yfg8JcRFLZt2EnftKQsYTVvX
qokN5RkCLKWabwO2t0tBAdVv5tWDnsIjxz7UApxFG/LDs46/hfogqcKBKntzyemFZcvrfDs5pbPW
JX4sOeLKedw5wBhyVYwQ/RA=</ds:X509Certificate></ds:X509Data></ds:KeyInfo></ds:Signature><saml2:NameID Format="urn:mace:shibboleth:1.0:nameIdentifier" xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion">_ffabc05d63592e9d07ee2f42aebecec
010.135.035.196.40928-010.135.035.197.00080: d</saml2:NameID></saml2p:LogoutRequest></soap11:Body></soap11:Envelope>
(gdb) bt
#0 0x00002b820c67c030 in strlen () from /lib/libc.so.6
#1 0x00002b820c648cb1 in vfprintf () from /lib/libc.so.6
#2 0x00002b820c66e20a in vsnprintf () from /lib/libc.so.6
#3 0x00002b8207f71be5 in log4shib::StringUtil::vform (format=0x2b82087268d8 "received message:\n%s", args=0x41801110) at StringUtil.cpp:42
#4 0x00002b8207f5e8e8 in log4shib::Category::_logUnconditionally (this=0x9723b0, priority=700, format=0x2b82087268d8 "received message:\n%s", arguments=0x41801110) at Category.cpp:254
#5 0x00002b8207f5e6f8 in log4shib::Category::debug (this=0x9723b0, stringFormat=0x2b82087268d8 "received message:\n%s") at Category.cpp:295
#6 0x00002b82087166b2 in opensaml::saml2p::SAML2SOAPDecoder::decode (this=0x7eeb20, relayState=<value optimized out>, genericRequest=@0x674d80, policy=@0x41801628) at saml2/binding/impl/SAML2SOAPDecoder.cpp:91
#7 0x00002b8207c1a76e in shibsp::SAML2Logout::doRequest (this=0x7ef0e0, application=@0x75cc30, request=@0x674d80, response=@0x940b90) at handler/impl/SAML2Logout.cpp:349
#8 0x00002b8207c1c671 in shibsp::SAML2Logout::receive (this=0x7ef0e0, in=<value optimized out>, out=@0x41801d50) at handler/impl/SAML2Logout.cpp:257
#9 0x00002b8207c72b7f in shibsp::ListenerService::receive (this=0x715608, in=@0x41801f90, out=@0x41801d50) at remoting/impl/ListenerService.cpp:113
#10 0x00002b8207c76e2c in shibsp::ServerThread::job (this=0x83a050) at remoting/impl/SocketListener.cpp:539
#11 0x00002b8207c779bd in shibsp::ServerThread::run (this=0x83a050) at remoting/impl/SocketListener.cpp:479
#12 0x00002b8207c77ab1 in server_thread_fn (arg=0x83a050) at remoting/impl/SocketListener.cpp:413
#13 0x00002b8209c67fc7 in start_thread () from /lib/libpthread.so.0
#14 0x00002b820c6d05ad in clone () from /lib/libc.so.6
#15 0x0000000000000000 in ?? ()