LISTSERV 16.5 - XROOTD-DEV Archives

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
> (this=this@entry=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
> (this=this@entry=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 ?:[log in to unmask] sysXrdHttp: received dlen:
> 16 200409 20:06:49 14876 ?:[log in to unmask] sysXrdHttp: received
> dump: 71 69 84 32 47 101 111 115 47 111 112 115 116 101 115 00 200409
> 20:06:49 14876 ?:[log in to unmask] sysXrdHttp: Protocol matched.
> https: 0 200409 20:06:49 14876 ?:[log in to unmask] sysXrdHttp:
> Process. lp:0x7f2ca6385818 reqstate: 0 200409 20:06:49 14876
> ?:[log in to unmask] 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
> ?:[log in to unmask] sysXrdHttp: rc:0Header not yet complete. 200409
> 20:06:49 3980 sysXrdHttp: Sending 1048576 bytes 200409 20:06:49 14927
> ?:[log in to unmask] 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
> <https://github.com/xrootd/xrootd/issues/1176>, or unsubscribe
> <https://github.com/notifications/unsubscribe-auth/ABJBUTZKZHDQTDSPVLHYIX3RMF3HHANCNFSM4MGKNQOA>.
> 


-- 
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/xrootd/xrootd/issues/1176#issuecomment-613406821
########################################################################
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