XrdHttp crash when dealing with incomplete headers #1176
Assignees
Labels
Comments
|
Huh do you think that checking ib prot->Bridge is nonzero would be
sufficient?
f
Il 12/04/20 10:25, Elvin Sindrilaru ha scritto:
… This crash happened in one of the DOMA tests. Apparently, there an issue
with the "state machine" represented by the CurrentReq.reqstate since
its value is "-1" and no external handler is called for the HTTP request
but also no Bridge object is created. Note there is an external handler
that should deal with such GET requests but since reqstate is non-0 this
never gets invoked. Below you can find a backtrace of the crash and
other relevant information. This happens with XRootD 4.11.3. A full
coredump is available here:
|lxfsre09a02.cern.ch:/var/spool/abrt/ccpp-2020-04-09-20:06:50-3949|
The backtrace:
|(gdb) f 0 #0 0x00007f2cfdae8e8f in XrdHttpReq::ProcessHTTPReq
***@***.***=0x7f2cdd8a9520) at
/usr/src/debug/xrootd-4.11.3/src/XrdHttp/XrdHttpReq.cc:1240 1240 if
(!prot->Bridge->Run((char *) &xrdreq, 0, 0)) { (gdb) bt #0
0x00007f2cfdae8e8f in XrdHttpReq::ProcessHTTPReq
***@***.***=0x7f2cdd8a9520) at
/usr/src/debug/xrootd-4.11.3/src/XrdHttp/XrdHttpReq.cc:1240 #1
0x00007f2cfdae1105 in XrdHttpProtocol::Process (this=0x7f2cdd8a9400,
lp=<optimized out>) at
/usr/src/debug/xrootd-4.11.3/src/XrdHttp/XrdHttpProtocol.cc:988 #2
0x00007f2d00845a59 in XrdLink::DoIt (this=0x7f2ca6385818) at
/usr/src/debug/xrootd-4.11.3/src/Xrd/XrdLink.cc:441 #3
0x00007f2d00848def in XrdScheduler::Run (this=0x610e78
<XrdMain::Config+440>) at
/usr/src/debug/xrootd-4.11.3/src/Xrd/XrdScheduler.cc:357 #4
0x00007f2d00848f39 in XrdStartWorking (carg=<optimized out>) at
/usr/src/debug/xrootd-4.11.3/src/Xrd/XrdScheduler.cc:87 #5
0x00007f2d0080ea67 in XrdSysThread_Xeq (myargs=0x7f2caac5cde0) at
/usr/src/debug/xrootd-4.11.3/src/XrdSys/XrdSysPthread.cc:86 #6
0x00007f2d003c2e65 in start_thread () from /lib64/libpthread.so.0 #7
0x00007f2cff6c488d in clone () from /lib64/libc.so.6 (gdb) p
prot->Bridge $10 = (XrdXrootd::Bridge *) 0x0 (gdb) f 1 #1
0x00007f2cfdae1105 in XrdHttpProtocol::Process (this=0x7f2cdd8a9400,
lp=<optimized out>) at
/usr/src/debug/xrootd-4.11.3/src/XrdHttp/XrdHttpProtocol.cc:988 988 rc =
CurrentReq.ProcessHTTPReq(); (gdb) p CurrentReq.reqstate $11 = -1 (gdb)
p CurrentReq $12 = {<XrdXrootd::Bridge::Result> = {_vptr.Result =
0x7f2cfdcf5ad0 <vtable for XrdHttpReq+16>}, httpStatusCode = 0,
httpStatusText = "", m_transfer_encoding_chunked = false,
m_current_chunk_offset = 0, m_current_chunk_size = -1, prot =
0x7f2cdd8a9400, ralist = 0x0, request = XrdHttpReq::rtGET, requestverb =
"GET", allheaders = std::map with 6 elements = {["Accept-Encoding"] =
"gzip,deflate", ["Authorization"] = "Bearer
MDAxNGxvY2F0aW9uIGVvc3BwcwowMDM0aWRlbnRpZmllciA3ODUxMWY3YS1jOGQ4LTQ2MDAtODFhMS1kZTgxMGRjMzg5NGEKMDAxNmNpZCBuYW1lOnRiZWVybWFuCjAwNTJjaWQgYWN0aXZpdHk6UkVBRF9NRVRBREFUQSxVUExPQUQsRE9XTkxPQUQsREVMR"...,
["Connection"] = "Keep-Alive", ["Host"] = "lxfsre09a02.cern.ch:9001",
["User-Agent"] = "dCache/5.2.16", ["Want-Digest"] = "adler32;q=1,
md5;q=0.8"}, resource = { _vptr.XrdOucString = 0x7f2d00a6dc10 <vtable
for XrdOucString+16>, str = 0x7f2c9dc36150
"/eos/opstest/tpc/https/domatest/file4_cfad65f5-4487-4901-9f0e-af2d20f95c7a",
len = 74, siz = 75, static blksize = -1}, opaque = 0x7f2c8fa3f400,
resourceplusopaque = {_vptr.XrdOucString = 0x7f2d00a6dc10 <vtable for
XrdOucString+16>, str = 0x7f2cdd96b800
"/eos/opstest/tpc/https/domatest/file4_cfad65f5-4487-4901-9f0e-af2d20f95c7a?encURI=%26cap.sym%3Dv%2FTsLkR%2BAYK5TGUAdartlwDahHY%3D%26cap.msg%3DEHPrLOVsWhX%2FV5EHdHgLLXWEibD9RoqwyG9fTh%2BVylyiMajoSE0x7O"...,
len = 947, siz = 964, static blksize = -1}, headerok = true, rwOps =
std::vector of length 0, capacity 0, rwOps_split = std::vector of length
0, capacity 0, keepalive = true, length = 0, depth = 0, sendcontinue =
false, host = "lxfsre09a02.cern.ch:9001", destination = "", m_req_digest
= "adler32;q=1, md5;q=0.8", m_resource_with_digest = {
_vptr.XrdOucString = 0x7f2d00a6dc10 <vtable for XrdOucString+16>, str =
0x7f2cdd80e098 "", len = 0, siz = 1, static blksize = -1},
m_digest_header = "", hdr2cgistr = "", m_appended_hdr2cgistr = false,
rwOpDone = 0, rwOpPartialDone = 0, xrdreq = {header = {streamid =
"\000", requestid = 47883, body = '\000' <repeats 15 times>, dlen = 0},
admin = {streamid = "\000", requestid = 47883, reserved = '\000'
<repeats 15 times>, dlen = 0}, auth = {streamid = "\000", requestid =
47883, reserved = '\000' <repeats 11 times>, credtype = "\000\000\000",
dlen = 0}, bind = {streamid = "\000", requestid = 47883, sessid = '\000'
<repeats 15 times>, dlen = 0}, chmod = {streamid = "\000", requestid =
47883, reserved = '\000' <repeats 13 times>, mode = 0, dlen = 0}, close
= {streamid = "\000", requestid = 47883, fhandle = "\000\000\000", fsize
= 0, reserved = "\000\000\000", dlen = 0}, decrypt = {streamid = "\000",
requestid = 47883, expectrid = 0, version = 0 '\000', flags = 0 '\000',
reserved = '\000' <repeats 11 times>, dlen = 0}, dirlist = {streamid =
"\000", requestid = 47883, reserved = '\000' <repeats 14 times>, options
= "", dlen = 0}, endsess = {streamid = "\000", requestid = 47883, sessid
= '\000' <repeats 15 times>, dlen = 0}, getfile = {streamid = "\000",
requestid = 47883, options = 0, reserved =
"\000\000\000\000\000\000\000", buffsz = 0, dlen = 0}, locate =
{streamid = "\000", requestid = 47883, options = 0, reserved = '\000'
<repeats 13 times>, dlen = 0}, login = { streamid = "\000", requestid =
47883, pid = 0, username = "\000\000\000\000\000\000\000", reserved = 0
'\000', ability = 0 '\000', capver = "", role = "", dlen = 0}, mkdir =
{streamid = "\000", requestid = 47883, options = "", reserved = '\000'
<repeats 12 times>, mode = 0, dlen = 0}, mv = {streamid = "\000",
requestid = 47883, reserved = '\000' <repeats 13 times>, arg1len = 0,
dlen = 0}, open = {streamid = "\000", requestid = 47883, mode = 0,
options = 0, reserved = '\000' <repeats 11 times>, dlen = 0}, ping =
{streamid = "\000", requestid = 47883, reserved = '\000' <repeats 15
times>, dlen = 0}, prepare = {streamid = "\000", requestid = 47883,
options = 0 '\000', prty = 0 '\000', port = 0, optionX = 0, reserved =
"\000\000\000\000\000\000\000\000\000", dlen = 0}, protocol = {streamid
= "\000", requestid = 47883, clientpv = 0, flags = 0 '\000', reserved =
"\000\000\000\000\000\000\000\000\000\000", dlen = 0}, putfile =
{streamid = "\000", requestid = 47883, options = 0, reserved =
"\000\000\000\000\000\000\000", buffsz = 0, dlen = 0}, query = {streamid
= "\000", requestid = 47883, infotype = 0, reserved1 = "\000", fhandle =
"\000\000\000", reserved2 = "\000\000\000\000\000\000\000", dlen = 0},
read = {streamid = "\000", requestid = 47883, fhandle = "\000\000\000",
offset = 0, rlen = 0, dlen = 0}, readv = {streamid = "\000", requestid =
47883, reserved = '\000' <repeats 14 times>, pathid = 0 '\000', dlen =
0}, rm = {streamid = "\000", requestid = 47883, reserved = '\000'
<repeats 15 times>, dlen = 0}, rmdir = {streamid = "\000", requestid =
47883, reserved = '\000' <repeats 15 times>, dlen = 0}, set = { streamid
= "\000", requestid = 47883, reserved = '\000' <repeats 14 times>,
modifier = 0 '\000', dlen = 0}, sigver = {streamid = "\000", requestid =
47883, expectrid = 0, version = 0 '\000', flags = 0 '\000', seqno = 0,
crypto = 0 '\000', rsvd2 = "\000\000", dlen = 0}, stat = {streamid =
"\000", requestid = 47883, options = 0 '\000', reserved =
"\000\000\000\000\000\000\000\000\000\000", fhandle = "\000\000\000",
dlen = 0}, sync = {streamid = "\000", requestid = 47883, fhandle =
"\000\000\000", reserved = '\000' <repeats 11 times>, dlen = 0},
truncate = {streamid = "\000", requestid = 47883, fhandle =
"\000\000\000", offset = 0, reserved = "\000\000\000", dlen = 0}, write
= { streamid = "\000", requestid = 47883, fhandle = "\000\000\000",
offset = 0, pathid = 0 '\000', reserved = "\000\000", dlen = 0}, writev
= {streamid = "\000", requestid = 47883, options = 0 '\000', reserved =
'\000' <repeats 14 times>, dlen = 0, static doSync = 1}}, xrdresp =
kXR_ok, xrderrcode = kXR_noErrorYet, etext = "", redirdest = {
_vptr.XrdOucString = 0x7f2d00a6dc10 <vtable for XrdOucString+16>, str =
0x7f2cdd80e088 "", len = 0, siz = 1, static blksize = -1}, iovP = 0x0,
iovN = 0, iovL = 0, final = false, filesize = 0, fileflags = 0,
filemodtime = 0, fhandle = "\000\000\000", fopened = false, stringresp =
"", reqstate = -1, writtenbytes = 0} (gdb) |
The actual log lines corresponding to this request:
|200409 20:06:49 14876 ***@***.*** sysXrdHttp: received dlen:
16 200409 20:06:49 14876 ***@***.*** sysXrdHttp: received
dump: 71 69 84 32 47 101 111 115 47 111 112 115 116 101 115 00 200409
20:06:49 14876 ***@***.*** sysXrdHttp: Protocol matched.
https: 0 200409 20:06:49 14876 ***@***.*** sysXrdHttp:
Process. lp:0x7f2ca6385818 reqstate: 0 200409 20:06:49 14876
***@***.*** sysXrdHttp: Setting host: [::ffff:192.41.230.26]
200409 20:06:49 14876 sysXrdHttp: getDataOneShot BuffAvailable: 1048576
maxread: 1048576 200409 20:06:49 14876 sysXrdHttp: read 1448 of 1048576
bytes 200409 20:06:49 14876 sysXrdHttp: rc:962 got hdr line: GET
/eos/opstest/tpc/https/domatest/file4_cfad65f5-4487-4901-9f0e-af2d20f95c7a?encURI=%26cap.sym%3Dv%2FTsLkR%2BAYK5TGUAdartlwDahHY%3D%26cap.msg%3DEHPrLOVsWhX%2FV5EHdHgLLXWEibD9RoqwyG9fTh%2BVylyiMajoSE0x7OiUlf630hWmuQQ13VLqh8%2FXxc5VS0VgaxQmDYDaZFYxUMbRvQR135ukoGAsHrrKsxXLo6gmQr2H%2BPHYLEU8xZp9wQXIQnOS8IsE545QWMLXpLnQjHvcJHd24aixCEEj8qPsWRaCGAl%2BxmaLX3IgZGvdNhSeac1tWW17AtPqPv37aE6KlFkvEOmQv42DGEtjckhTgQ4%2BVx9%2BHyDOwYgRpalieGEUqy%2F1Rj5zORWA3E7qbWsHBojBaIAB4pL4BNdNNkkHFvnF5k9ECME%2BkL%2Bhf6K5iXcPN%2F06BWDpRk9YV1jIRzYC0zffHbyQHH04p%2FNLhzUsV6r1%2FaxH00X3lWwEkWrImcl8obM7DzZeDBXHct8KvddyDXvYv95PTsfFxK5OA0icR6y1qSHbtQ%2FPl44Vf9x4lgRBbfaBruo0WMTiY3zFc93Y67Aw0fKygeQ6cM5EzEm2ZjG2PO3tIaNCRbfgya73gS5GWICUkf36OhTzdMBl587OH12l9Us%3D%26mgm.logid%3De2392620-7a8c-11ea-8e3e-fa163ec4aef9%26mgm.blockchecksum%3Dignore%26mgm.replicaindex%3D0%26mgm.replicahead%3D0%26mgm.etag%3D%221275783243513200640:88708a07%22%26mgm.id%3D11b47e19c%26mgm.mtime%3D1586451760
HTTP/1.1 200409 20:06:49 14876 sysXrdHttp: Parsing first line: GET
/eos/opstest/tpc/https/domatest/file4_cfad65f5-4487-4901-9f0e-af2d20f95c7a?encURI=%26cap.sym%3Dv%2FTsLkR%2BAYK5TGUAdartlwDahHY%3D%26cap.msg%3DEHPrLOVsWhX%2FV5EHdHgLLXWEibD9RoqwyG9fTh%2BVylyiMajoSE0x7OiUlf630hWmuQQ13VLqh8%2FXxc5VS0VgaxQmDYDaZFYxUMbRvQR135ukoGAsHrrKsxXLo6gmQr2H%2BPHYLEU8xZp9wQXIQnOS8IsE545QWMLXpLnQjHvcJHd24aixCEEj8qPsWRaCGAl%2BxmaLX3IgZGvdNhSeac1tWW17AtPqPv37aE6KlFkvEOmQv42DGEtjckhTgQ4%2BVx9%2BHyDOwYgRpalieGEUqy%2F1Rj5zORWA3E7qbWsHBojBaIAB4pL4BNdNNkkHFvnF5k9ECME%2BkL%2Bhf6K5iXcPN%2F06BWDpRk9YV1jIRzYC0zffHbyQHH04p%2FNLhzUsV6r1%2FaxH00X3lWwEkWrImcl8obM7DzZeDBXHct8KvddyDXvYv95PTsfFxK5OA0icR6y1qSHbtQ%2FPl44Vf9x4lgRBbfaBruo0WMTiY3zFc93Y67Aw0fKygeQ6cM5EzEm2ZjG2PO3tIaNCRbfgya73gS5GWICUkf36OhTzdMBl587OH12l9Us%3D%26mgm.logid%3De2392620-7a8c-11ea-8e3e-fa163ec4aef9%26mgm.blockchecksum%3Dignore%26mgm.replicaindex%3D0%26mgm.replicahead%3D0%26mgm.etag%3D%221275783243513200640:88708a07%22%26mgm.id%3D11b47e19c%26mgm.mtime%3D1586451760
HTTP/1.1 200409 20:06:49 14876 sysXrdHttp: rc:37 got hdr line:
Want-Digest: adler32;q=1, md5;q=0.8 200409 20:06:49 14876
***@***.*** sysXrdHttp: rc:0Header not yet complete. 200409
20:06:49 3980 sysXrdHttp: Sending 1048576 bytes 200409 20:06:49 14927
***@***.*** sysXrdHttp: Process. lp:0x7f2ca6385818 reqstate:
-1 200409 20:06:49 14927 sysXrdHttp: getDataOneShot BuffAvailable:
1047128 maxread: 1047128 200409 20:06:49 14927 sysXrdHttp: read 195 of
1047128 bytes 200409 20:06:49 14927 sysXrdHttp: rc:528 got hdr line:
Authorization: Bearer
MDAxNGxvY2F0aW9uIGVvc3BwcwowMDM0aWRlbnRpZmllciA3ODUxMWY3YS1jOGQ4LTQ2MDAtODFhMS1kZTgxMGRjMzg5NGEKMDAxNmNpZCBuYW1lOnRiZWVybWFuCjAwNTJjaWQgYWN0aXZpdHk6UkVBRF9NRVRBREFUQSxVUExPQUQsRE9XTkxPQUQsREVMRVRFLE1BTkFHRSxVUERBVEVfTUVUQURBVEEsTElTVAowMDFmY2lkIGFjdGl2aXR5OkRPV05MT0FELExJU1QKMDA1OGNpZCBwYXRoOi9lb3Mvb3BzdGVzdC90cGMvaHR0cHMvZG9tYXRlc3QvZmlsZTRfY2ZhZDY1ZjUtNDQ4Ny00OTAxLTlmMGUtYWYyZDIwZjk1YzdhCjAwMjRjaWQgYmVmb3JlOjIwMjAtMDQtMDlUMjA6NDM6NDZaCjAwMmZzaWduYXR1cmUgA0mewhQwo5ODcWyejOZ05Uo67s7XJdi380Tf53KAFx4K
200409 20:06:49 14927 sysXrdHttp: rc:32 got hdr line: Host:
lxfsre09a02.cern.ch:9001 200409 20:06:49 14927 sysXrdHttp: rc:24 got hdr
line: Connection: Keep-Alive 200409 20:06:49 14927 sysXrdHttp: rc:27 got
hdr line: User-Agent: dCache/5.2.16 200409 20:06:49 14927 sysXrdHttp:
rc:31 got hdr line: Accept-Encoding: gzip,deflate 200409 20:06:49 14927
sysXrdHttp: rc:2 got hdr line: 200409 20:06:49 14927 sysXrdHttp: rc:2
detected header end. 200409 20:07:58 2811 Starting on Linux
3.10.0-1062.9.1.el7.x86_64 Copr. 2004-2012 Stanford University, xrd
version v4.11.3 |
—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub
<#1176>, or unsubscribe
<https://github.com/notifications/unsubscribe-auth/ABJBUTZKZHDQTDSPVLHYIX3RMF3HHANCNFSM4MGKNQOA>.
|
|
Not really, this would just fix the effect not the cause. And there are any many more places where all this should be fixed depending on the type of request. The CurretReq.reqstate should be fixed after this code gets triggered and the rest of the header info is read: |
|
Not really by now, I may find some time on Monday to look at it |
|
Hi, may I know which xrootd you are using? I am on the master, and the line numbers do not match with respect to this issue... |
|
This was using |
|
Another detail that I find scary is that the log line of the master should print the reqstate: TRACEI(DEBUG, " Process. lp:" << lp << " reqstate: " << CurrentReq.reqstate); Instead I see a slightly different printout in your log: #1 0x00007f2cfdae1105 in XrdHttpProtocol::Process (this=0x7f2cdd8a9400, lp=) at /usr/src/debug/xrootd-4.11.3/src/XrdHttp/XrdHttpProtocol.cc:988 That line has been changed a very long time ago, and so many other things. Would you mind to test with the master and your eos plugin? In the meantime, the thing that is ugly to me is that reqstate goes below zero in this very particular case. I will fix that in my next little commit. This will likely avoid the situation at the roots, but will need testing. Please let me know how it goes |
|
The log line from the logs in my first comment does seem to match the TRACEI: Are you referring to something else? It's quite complicated to test as this happens in very particular conditions that I was not yet able to reproduce ... |
This was referenced May 25, 2020
|
right! I pointed the wrong line, sorry. The line numbers still were not matching... as they are two slightly different versions. I have merged into the master two commits, and I am starting the heavy test with DPM, which exercises an ext plugin, like eos does (but not the same plugin) |
|
Running with 4.12.3 which contains this fix in our pre-production instance leads to a segv in a matter of seconds. The output from the XrdHttp logs looks scrambled: The point where this crashes: |
|
OK, I'll have a look at this. So far I have not seen this behaviour in the dpm tests. May I ask you where you pick the xrootd builds? |
|
Hi Fabrizio, This is now running in eospps.cern.ch. The xrootd comes from the eos-depend repo which takes the tarball from the xrootd release (http://storage-ci.web.cern.ch/storage-ci/xrootd/release/cc-7-x86_64/v4.12.3/tarball/) and rebuilds it: |
|
@esindril - in terms of getting together some debug info, anything obviously wrong when run under |
|
I've tried valgrind but this was terribly slow and in the end it crashed itself with a funny message: I tried increasing it but again things are extremely slow and I abandoned after half an hour. On the bright side this seem to be quite reliably reproducible although it does not happen immediately. If I were to guess, I would say this comes more from the SSL part rather then the fixes that Fabrizio did ... but this is just a guess. Below I will post more info from the backtrace which is always the same and some info from the log file once this starts happening. In the log file all http requests seem fine up to this point: Then it seems it can not properly decode the headers: The backtrace looks like this: If anyone wants access to the machine please let me know. |
|
Hi,
I am on this, maybe I found but still don't really know how to test
it... any hint?
f
Il 22/06/20 10:04, Elvin Sindrilaru ha scritto:
… Running with 4.12.3 which contains this fix in our pre-production
instance leads to a segv in a matter of seconds. The output from the
XrdHttp logs looks scrambled:
|200622 09:50:22 29275 ***@***.*** sysXrdHttp: Sending
resp: 403 header len:134 200622 09:50:22 29275 sysXrdHttp: Sending 134
bytes 200622 09:50:22 29275 sysXrdHttp: Sending 3846 bytes 200622
09:50:22 29275 sysXrdHttp: XrdHttpReq request ended. 200622 09:50:22
29275 ***@***.*** sysXrdHttp: Process is exiting rc:1
200622 09:50:22 29266 ***@***.*** sysXrdHttp: Process.
lp:0x7f8721d5a2b8 reqstate: 0 200622 09:50:22 29266 sysXrdHttp:
getDataOneShot BuffAvailable: 1043630 maxread: 1043630 200622 09:50:22
29266 sysXrdHttp: getDataOneShot sslavail: 1043630 200622 09:50:22 29266
sysXrdHttp: read 8192 of 1043630 bytes 200622 09:50:22 29266 sysXrdHttp:
rc:115 got hdr line:
ʰ<9A><E1>4<C6><FD><BF>^?<F3>/<87><U+0379><9E>))<A2>^?h<U+0618>M^Y<9B><A7><8F><CC><F3>3<B9>^XMI<AB>Νy<87>U<E3>7<DD><s<FB><C6>*<E4>^G<C8>Hwj<C6>ESC
|^D<96><B4><B5>\<CF>$<F7>^E`^X_<D9><E5><EF>j<E9>,<A2><FB>TQ<B3>^K<DF>ۥ^O^LHL<EB>5<FB>^\o^R<E2><E1>ױ0N=<82><A4><97>z<F3>\<B2><A9>Z<A1>^^C
200622 09:50:22 29266 sysXrdHttp: Parsing first line:
ʰ<9A><E1>4<C6><FD><BF>^?<F3>/<87><U+0379><9E>))<A2>^?h<U+0618>M^Y<9B><A7><8F><CC><F3>3<B9>^XMI<AB>Νy<87>U<E3>7<DD><s<FB><C6>*<E4>^G<C8>Hwj<C6>ESC
|^D<96><B4><B5>\<CF>$<F7>^E`^X_<D9><E5><EF>j<E9>,<A2><FB>TQ<B3>^K<DF>ۥ^O^LHL<EB>5<FB>^\o^R<E2><E1>ױ0N=<82><A4><97>z<F3>\<B2><A9>Z<A1>^^C
200622 09:50:22 29266 sysXrdHttp: Parsing of first line failed with -1
200622 09:50:22 29266 sysXrdHttp: rc:244 got hdr line:
<C5><C7><C7>J<90><C0>
<F6><A3><E6><E3>BUN{Ѩ<AD><AC><91><AF>%<EC><D9>^W^\r<AA><97><EE>w<97>^Gva<BD>5;l(<C7>m<CF>!^]^F<C6><CC>n/ESC<A1>z<D8>^PW;/<F7>v<AE><95>?<A6>*jwu^?X{Ą<U+99422><9B>^?<9C>^G^M<DE>P<84>5<B4><C1>^U^Q<DB>k^Ceۘ<<85>}<A3>MC̝}2$^GѭG%<89>bi7w<E8><EC>A<BF>^W<A3><D6>f~<F4>-<99><D3>Y<B4>I8'<A1>^X^]d<92><A0>^O<A2><BE>^]r(߆<96><DD>5<85><CD>^]<EC><E9>^H<D8><C1><8A>O<FD>(i<C2>&<F4>$^Yr=<A0><D6><ED><FA>+<EE><A8>^DPXq^F^D<A0>^_^K<8E><B1><C8>-<AB>-<ESC7^EJ<B7>bc;3B<ED><C5>$<B1><C6><F3>=:^Ye6<B9>^H*1J<BD>϶<B7>^?<AE>݆
J <82>^LV<C3>nW<EC><BE>R7<B2>ESC |
The point where this crashes:
|#########################################################################
#
-----------------------------------------------------------------------
# Responsible thread => #
-----------------------------------------------------------------------
# Thread 20 (Thread 0x7f8998bef700 (LWP 29276)):
######################################################################### #5
<signal handler called> #6 0x00007f899cc65691 in __strlen_sse2_pminub ()
from /lib64/libc.so.6 #7 0x00007f8997eda245 in
std::char_traits<char>::length (__s=0x0) at
/usr/include/c++/4.8.2/bits/char_traits.h:259 #8 std::string::assign
(__s=0x0, this=0x7f8720a8e2a8) at
/usr/include/c++/4.8.2/bits/basic_string.h:1131 #9
std::string::operator= (__s=0x0, this=<optimized out>) at
/usr/include/c++/4.8.2/bits/basic_string.h:555 #10
XrdHttpExtReq::XrdHttpExtReq (this=0x7f8998bee7a0, req=0x7f88f3d4b3a0,
pr=<optimized out>) at
/usr/src/debug/xrootd/xrootd/src/XrdHttp/XrdHttpExtHandler.cc:86 #11
0x00007f8997ed3c1f in XrdHttpReq::ProcessHTTPReq (
***@***.***=0x7f88f3d4b3a0) at
/usr/src/debug/xrootd/xrootd/src/XrdHttp/XrdHttpReq.cc:986 #12
0x00007f8997eccc45 in XrdHttpProtocol::Process (this=0x7f88f3d4b280,
lp=<optimized out>) at
/usr/src/debug/xrootd/xrootd/src/XrdHttp/XrdHttpProtocol.cc:1004 #13
0x00007f899dd75d49 in XrdLink::DoIt (this=0x7f8721d5a2b8) at
/usr/src/debug/xrootd/xrootd/src/Xrd/XrdLink.cc:441 #14
0x00007f899dd790df in XrdScheduler::Run ( this=0x610e58
<XrdMain::Config+440>) at
/usr/src/debug/xrootd/xrootd/src/Xrd/XrdScheduler.cc:357 #15
0x00007f899dd79229 in XrdStartWorking (carg=<optimized out>) at
/usr/src/debug/xrootd/xrootd/src/Xrd/XrdScheduler.cc:87 #16
0x00007f899dd3eba7 in XrdSysThread_Xeq (myargs=0x7f899a421700) at
/usr/src/debug/xrootd/xrootd/src/XrdSys/XrdSysPthread.cc:86 #17
0x00007f899d8f2ea5 in start_thread () from /lib64/libpthread.so.0 #18
0x00007f899cbf48dd in clone () from /lib64/libc.so.6 |
—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub
<#1176 (comment)>,
or unsubscribe
<https://github.com/notifications/unsubscribe-auth/AA7NRDW57BRI2VNV7IWYFMLRX4GBLANCNFSM4MGKNQOA>.
------------------------------------------------------------------------
Use REPLY-ALL to reply to list
To unsubscribe from the XROOTD-DEV list, click the following link:
https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-DEV&A=1
|
|
Hi Elvin,
would you be able to try out my xrootd build?
It's here:
/afs/cern.ch/project/gd/dms/www/lcgdm/repos/el7/x86_64
the repofile is here:
https://gitlab.cern.ch/lcgdm/extras-build/-/blob/master/repos/lcgdm-cbuilds-el7.repo
Cheers
Fabrizio
Il 24/06/20 12:01, xrootd-dev ha scritto:
… Hi,
I am on this, maybe I found but still don't really know how to test
it... any hint?
f
Il 22/06/20 10:04, Elvin Sindrilaru ha scritto:
> Running with 4.12.3 which contains this fix in our pre-production
> instance leads to a segv in a matter of seconds. The output from the
> XrdHttp logs looks scrambled:
>
> |200622 09:50:22 29275 ***@***.*** sysXrdHttp: Sending
> resp: 403 header len:134 200622 09:50:22 29275 sysXrdHttp: Sending 134
> bytes 200622 09:50:22 29275 sysXrdHttp: Sending 3846 bytes 200622
> 09:50:22 29275 sysXrdHttp: XrdHttpReq request ended. 200622 09:50:22
> 29275 ***@***.*** sysXrdHttp: Process is exiting rc:1
> 200622 09:50:22 29266 ***@***.*** sysXrdHttp: Process.
> lp:0x7f8721d5a2b8 reqstate: 0 200622 09:50:22 29266 sysXrdHttp:
> getDataOneShot BuffAvailable: 1043630 maxread: 1043630 200622 09:50:22
> 29266 sysXrdHttp: getDataOneShot sslavail: 1043630 200622 09:50:22 29266
> sysXrdHttp: read 8192 of 1043630 bytes 200622 09:50:22 29266 sysXrdHttp:
> rc:115 got hdr line:
>
ʰ<9A><E1>4<C6><FD><BF>^?<F3>/<87><U+0379><9E>))<A2>^?h<U+0618>M^Y<9B><A7><8F><CC><F3>3<B9>^XMI<AB>Νy<87>U<E3>7<DD><s<FB><C6>*<E4>^G<C8>Hwj<C6>ESC
>
|^D<96><B4><B5>\<CF>$<F7>^E`^X_<D9><E5><EF>j<E9>,<A2><FB>TQ<B3>^K<DF>ۥ^O^LHL<EB>5<FB>^\o^R<E2><E1>ױ0N=<82><A4><97>z<F3>\<B2><A9>Z<A1>^^C
> 200622 09:50:22 29266 sysXrdHttp: Parsing first line:
>
ʰ<9A><E1>4<C6><FD><BF>^?<F3>/<87><U+0379><9E>))<A2>^?h<U+0618>M^Y<9B><A7><8F><CC><F3>3<B9>^XMI<AB>Νy<87>U<E3>7<DD><s<FB><C6>*<E4>^G<C8>Hwj<C6>ESC
>
|^D<96><B4><B5>\<CF>$<F7>^E`^X_<D9><E5><EF>j<E9>,<A2><FB>TQ<B3>^K<DF>ۥ^O^LHL<EB>5<FB>^\o^R<E2><E1>ױ0N=<82><A4><97>z<F3>\<B2><A9>Z<A1>^^C
> 200622 09:50:22 29266 sysXrdHttp: Parsing of first line failed with -1
> 200622 09:50:22 29266 sysXrdHttp: rc:244 got hdr line:
> <C5><C7><C7>J<90><C0>
>
<F6><A3><E6><E3>BUN{Ѩ<AD><AC><91><AF>%<EC><D9>^W^\r<AA><97><EE>w<97>^Gva<BD>5;l(<C7>m<CF>!^]^F<C6><CC>n/ESC<A1>z<D8>^PW;/<F7>v<AE><95>?<A6>*jwu^?X{Ą<U+99422><9B>^?<9C>^G^M<DE>P<84>5<B4><C1>^U^Q<DB>k^Ceۘ<<85>}<A3>MC̝}2$^GѭG%<89>bi7w<E8><EC>A<BF>^W<A3><D6>f~<F4>-<99><D3>Y<B4>I8'<A1>^X^]d<92><A0>^O<A2><BE>^]r(߆<96><DD>5<85><CD>^]<EC><E9>^H<D8><C1><8A>O<FD>(i<C2>&<F4>$^Yr=<A0><D6><ED><FA>+<EE><A8>^DPXq^F^D<A0>^_^K<8E><B1><C8>-<AB>-<ESC7^EJ<B7>bc;3B<ED><C5>$<B1><C6><F3>=:^Ye6<B9>^H*1J<BD>϶<B7>^?<AE>݆
> J <82>^LV<C3>nW<EC><BE>R7<B2>ESC |
>
> The point where this crashes:
>
> |#########################################################################
> #
> -----------------------------------------------------------------------
> # Responsible thread => #
> -----------------------------------------------------------------------
> # Thread 20 (Thread 0x7f8998bef700 (LWP 29276)):
>
######################################################################### #5
> <signal handler called> #6 0x00007f899cc65691 in __strlen_sse2_pminub ()
> from /lib64/libc.so.6 #7 0x00007f8997eda245 in
> std::char_traits<char>::length (__s=0x0) at
> /usr/include/c++/4.8.2/bits/char_traits.h:259 #8 std::string::assign
> (__s=0x0, this=0x7f8720a8e2a8) at
> /usr/include/c++/4.8.2/bits/basic_string.h:1131 #9
> std::string::operator= (__s=0x0, this=<optimized out>) at
> /usr/include/c++/4.8.2/bits/basic_string.h:555 #10
> XrdHttpExtReq::XrdHttpExtReq (this=0x7f8998bee7a0, req=0x7f88f3d4b3a0,
> pr=<optimized out>) at
> /usr/src/debug/xrootd/xrootd/src/XrdHttp/XrdHttpExtHandler.cc:86 #11
> 0x00007f8997ed3c1f in XrdHttpReq::ProcessHTTPReq (
> ***@***.***=0x7f88f3d4b3a0) at
> /usr/src/debug/xrootd/xrootd/src/XrdHttp/XrdHttpReq.cc:986 #12
> 0x00007f8997eccc45 in XrdHttpProtocol::Process (this=0x7f88f3d4b280,
> lp=<optimized out>) at
> /usr/src/debug/xrootd/xrootd/src/XrdHttp/XrdHttpProtocol.cc:1004 #13
> 0x00007f899dd75d49 in XrdLink::DoIt (this=0x7f8721d5a2b8) at
> /usr/src/debug/xrootd/xrootd/src/Xrd/XrdLink.cc:441 #14
> 0x00007f899dd790df in XrdScheduler::Run ( this=0x610e58
> <XrdMain::Config+440>) at
> /usr/src/debug/xrootd/xrootd/src/Xrd/XrdScheduler.cc:357 #15
> 0x00007f899dd79229 in XrdStartWorking (carg=<optimized out>) at
> /usr/src/debug/xrootd/xrootd/src/Xrd/XrdScheduler.cc:87 #16
> 0x00007f899dd3eba7 in XrdSysThread_Xeq (myargs=0x7f899a421700) at
> /usr/src/debug/xrootd/xrootd/src/XrdSys/XrdSysPthread.cc:86 #17
> 0x00007f899d8f2ea5 in start_thread () from /lib64/libpthread.so.0 #18
> 0x00007f899cbf48dd in clone () from /lib64/libc.so.6 |
>
> —
> You are receiving this because you are subscribed to this thread.
> Reply to this email directly, view it on GitHub
> <#1176 (comment)>,
> or unsubscribe
>
<https://github.com/notifications/unsubscribe-auth/AA7NRDW57BRI2VNV7IWYFMLRX4GBLANCNFSM4MGKNQOA>.
>
>
> ------------------------------------------------------------------------
>
> Use REPLY-ALL to reply to list
>
> To unsubscribe from the XROOTD-DEV list, click the following link:
> https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-DEV&A=1
>
—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
<#1176 (comment)>,
or unsubscribe
<https://github.com/notifications/unsubscribe-auth/ABJBUTYU66BD4J3Q6OCIGRLRYHFHFANCNFSM4MGKNQOA>.
|
|
Hi Fabrizio, I will deploy it in the after noon. Thanks! Elvin |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
This crash happened in one of the DOMA tests. Apparently, there an issue with the "state machine" represented by the CurrentReq.reqstate since its value is "-1" and no external handler is called for the HTTP request but also no Bridge object is created. Note there is an external handler that should deal with such GET requests but since reqstate is non-0 this never gets invoked. Below you can find a backtrace of the crash and other relevant information. This happens with XRootD 4.11.3. A full coredump is available here:
lxfsre09a02.cern.ch:/var/spool/abrt/ccpp-2020-04-09-20:06:50-3949The backtrace:
The actual log lines corresponding to this request:
The text was updated successfully, but these errors were encountered: