I've tried valgrind but this was terribly slow and in the end it crashed itself with a funny message:
```
valgrind: the 'impossible' happened:
Max number of threads is too low
```
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:
```
stest/tpc/https/domatest/file26_c38ac3a5-2341-4a58-afc8-82d9bcc7d4ad: Unable to stat /eos/opstest/tpc/https/domatest/file26_c38ac3a5-2341-4a58-afc8-82d9bcc7d4ad; No such file or directory"
200624 10:11:27 24523 tbeerman.0:450@fts-devel-10 sysXrdHttp: Sending resp: 404 header len:106
200624 10:11:27 24523 sysXrdHttp: Sending 106 bytes
200624 10:11:27 24523 sysXrdHttp: XrdHttpReq request ended.
200624 10:11:27 24523 tbeerman.0:450@fts-devel-10 sysXrdHttp: Process is exiting rc:1
200624 10:11:27 24521 ?:[log in to unmask] sysXrdHttp: SSL_accept returned :1
200624 10:11:27 24521 ?:[log in to unmask] sysXrdHttp: SSL_get_verify_result returned :0
200624 10:11:27 24521 ?:[log in to unmask] sysXrdHttp: Extracting auth info.
200624 10:11:27 24521 ?:[log in to unmask] sysXrdHttp: SSL_get_peer_certificate returned :0x7f8e4a855d40
200624 10:11:27 24521 ?:[log in to unmask] sysXrdHttp: Issuer name is : '/C=UK/O=eScienceCA/OU=Authority/CN=UK e-Science CA 2B'
200624 10:11:27 24521 ?:[log in to unmask] sysXrdHttp: Mapping name: '/C=UK/O=eScienceCA/OU=Authority/CN=UK e-Science CA 2B' Failed. err: -14
200624 10:11:27 24521 ?:[log in to unmask] sysXrdHttp: Subject name is : '/C=UK/O=eScience/OU=QueenMaryLondon/L=Physics/CN=se03.esc.qmul.ac.uk'
200624 10:11:27 24521 ?:[log in to unmask] sysXrdHttp: Mapping name: /C=UK/O=eScience/OU=QueenMaryLondon/L=Physics/CN=se03.esc.qmul.ac.uk Failed. err: -14
200624 10:11:27 24521 ?:[log in to unmask] SSL_get_peer_certificate returned :0x7f8e4a855d40
200624 10:11:27 24521 ?:[log in to unmask] SSL_get_verify_result returned :0
200624 10:11:27 24521 ?:[log in to unmask] SSL_get_peer_cert_chain :0x7f8dc2cc72c0
200624 10:11:27 24521 ?:[log in to unmask] voms info retrieval failed: VOMS extension not found!
200624 10:11:27 24521 sysXrdHttp: getDataOneShot BuffAvailable: 1048576 maxread: 1048576
200624 10:11:27 24521 sysXrdHttp: getDataOneShot sslavail: 1048576
200624 10:11:27 24521 sysXrdHttp: read 4946 of 1048576 bytes
200624 10:11:27 24521 sysXrdHttp: rc:90 got hdr line: PUT /eos/opstest/tpc/https/domatest/file21_6f1b285c-6ee3-4f1f-946b-ecb10146e8b2 HTTP/1.1
200624 10:11:27 24521 sysXrdHttp: Parsing first line: PUT /eos/opstest/tpc/https/domatest/file21_6f1b285c-6ee3-4f1f-946b-ecb10146e8b2 HTTP/1.1
200624 10:11:27 24521 sysXrdHttp: rc:555 got hdr line: Authorization: Bearer MDAxNGxvY2F0aW9uIGVvc3BwcwowMDM0aWRlbnRpZmllciBmNWJmYzQ3YS0yMzlhLTQyMDEtYTQ1Yy00NGJiNDM0NzY0MzYKMDAxNmNpZCBuYW1lOnRiZWVybWFuCjAwNTJjaWQgYWN0aXZpdHk6UkVBRF9NRVRBREFUQSxVUExPQUQsRE9XTkxPQUQsREVMRVRFLE1BTkFHRSxVUERBVEVfTUVUQURBVEEsTElTVAowMDMyY2lkIGFjdGl2aXR5Ok1BTkFHRSxVUExPQUQsREVMRVRFLExJU1QsTUFOQUdFCjAwNTljaWQgcGF0aDovZW9zL29wc3Rlc3QvdHBjL2h0dHBzL2RvbWF0ZXN0L2ZpbGUyMV82ZjFiMjg1Yy02ZWUzLTRmMWYtOTQ2Yi1lY2IxMDE0NmU4YjIKMDAyNGNpZCBiZWZvcmU6MjAyMC0wNi0yNFQxMDo0ODoyNloKMDAyZnNpZ25hdHVyZSDg7KTdfpKhppYnBI6nfDf2DswIUyYFB6fy-m_xU_bkbAo
200624 10:11:27 24521 sysXrdHttp: rc:28 got hdr line: Content-Length: 1000000000
200624 10:11:27 24521 sysXrdHttp: rc:40 got hdr line: Content-Type: application/octet-stream
200624 10:11:27 24521 sysXrdHttp: rc:26 got hdr line: Host: eospps.cern.ch:443
200624 10:11:27 24521 sysXrdHttp: rc:24 got hdr line: Connection: Keep-Alive
200624 10:11:27 24521 sysXrdHttp: rc:54 got hdr line: User-Agent: Apache-HttpClient/4.5.8 (Java/1.8.0_252)
200624 10:11:27 24521 sysXrdHttp: rc:31 got hdr line: Accept-Encoding: gzip,deflate
200624 10:11:27 24521 sysXrdHttp: rc:2 got hdr line:
200624 10:11:27 24521 sysXrdHttp: rc:2 detected header end.
```
Then it seems it can not properly decode the headers:
```
200624 10:11:27 time=1592986287.197808 func=HttpError level=INFO logid=static.............................. [log in to unmask]:1094 tid=00007f8ef00f0700 source=HttpServer:403 tident= sec=(null) uid=99 gid=99 name=- geo="" errc=1, retcode=403 errmsg="Unable to open file /eos/opstest/tpc/https/domatest/file21_6f1b285c-6ee3-4f1f-946b-ecb10146e8b2; Operation not permitted"
200624 10:11:27 24521 ?:[log in to unmask] sysXrdHttp: Sending resp: 403 header len:134
200624 10:11:27 24521 sysXrdHttp: Sending 134 bytes
200624 10:11:27 24521 sysXrdHttp: Sending 3846 bytes
200624 10:11:27 24521 sysXrdHttp: XrdHttpReq request ended.
200624 10:11:27 24521 ?:[log in to unmask] sysXrdHttp: Process is exiting rc:1
200624 10:11:27 24510 ?:[log in to unmask] sysXrdHttp: Process. lp:0x7f8dd44e12b8 reqstate: 0
200624 10:11:27 24510 sysXrdHttp: getDataOneShot BuffAvailable: 1043630 maxread: 1043630
200624 10:11:27 24510 sysXrdHttp: getDataOneShot sslavail: 1043630
200624 10:11:27 24510 sysXrdHttp: read 8192 of 1043630 bytes
200624 10:11:27 24510 sysXrdHttp: rc:247 got hdr line: <BD>\<AC>^]n<A4><A6>3<BB>ʄb"<86><A3><EC><BC>^^<9E><81><83><F0>}s^^ϋi<E3><C6>2^Q<D0><FF><F0><8A><A3><EB><CF><E8>i2<9D>?<8F><CD><E9>@<B2><F2>^M<AA><B0>@bd{+?<A7>肠|/ESC2<E0>><91><E5><FB>U<E8>Aޮ<U+0372><89>{<EB>9^Gڔ߫8<AE><AA>6<A7>p<FF>
<E5><ED>f<B7>aA<9B>m^O<99><9F>^AESCŭ<82><86>h "<A4>U<9D>^M&O}<E9><F1>KDe<83>^A+\9^]<92>^D<A7>^^<FE><F0><B9>o<9F><96><BA><B4>:ѿ^ZR<C6>*Rh^K<90>~<FD>*<DC>t<F3><DC><DF>ך<FD>^C1Δu<D8><D5>v<D8>aESCY<C6>9<D0><C1><9A><A4><EE><F9>^X>!<F7>q^GD^X<9E>!<B4>CW<A5>^N<9A><9C>^Y<D5>ESC<BD>^G<FA>ޡS
<FA><F3><DD>͝<A8>^K^A<9C>"%%2X]<C8>^CD<C5>6^^p<9E><B6>F<D3>><BA>^H@-<D8>
200624 10:11:27 24510 sysXrdHttp: Parsing first line: <BD>\<AC>^]n<A4><A6>3<BB>ʄb"<86><A3><EC><BC>^^<9E><81><83><F0>}s^^ϋi<E3><C6>2^Q<D0><FF><F0><8A><A3><EB><CF><E8>i2<9D>?<8F><CD><E9>@<B2><F2>^M<AA><B0>@bd{+?<A7>肠|/ESC2<E0>><91><E5><FB>U<E8>Aޮ<U+0372><89>{<EB>9^Gڔ߫8<AE><AA>6<A7>p<FF><E5><ED>f<B7>aA<9B>m^O<99><9F>^AESCŭ<82><86>h "<A4>U<9D>^M&O}<E9><F1>KDe<83>^A+\9^]<92>^D<A7>^^<FE><F0><B9>o<9F><96><BA><B4>:ѿ^ZR<C6>*Rh^K<90>~<FD>*<DC>t<F3><DC><DF>ך<FD>^C1Δu<D8><D5>v<D8>aESCY<C6>9<D0><C1><9A><A4><EE><F9>^X>!<F7>q^GD^X<9E>!<B4>CW<A5>^N<9A><9C>^Y<D5>ESC<BD>^G<FA>ޡS<FA>
<F3><DD>͝<A8>^K^A<9C>"%%2X]<C8>^CD<C5>6^^p<9E><B6>F<D3>><BA>^H@-<D8>
```
The backtrace looks like this:
```
gdb) bt
#0 0x00007f8ef40e4691 in __strlen_sse2_pminub () from /lib64/libc.so.6
#1 0x00007f8eef3db245 in std::char_traits<char>::length (__s=0x0) at /usr/include/c++/4.8.2/bits/char_traits.h:259
#2 std::string::assign (__s=0x0, this=0x7f8e49939b78) at /usr/include/c++/4.8.2/bits/basic_string.h:1131
#3 std::string::operator= (__s=0x0, this=<optimized out>) at /usr/include/c++/4.8.2/bits/basic_string.h:555
#4 XrdHttpExtReq::XrdHttpExtReq (this=0x7f8eeffee7a0, req=0x7f8eaf88ee20, pr=<optimized out>) at /usr/src/debug/xrootd/xrootd/src/XrdHttp/XrdHttpExtHandler.cc:86
#5 0x00007f8eef3d4c1f in XrdHttpReq::ProcessHTTPReq (this=this@entry=0x7f8eaf88ee20) at /usr/src/debug/xrootd/xrootd/src/XrdHttp/XrdHttpReq.cc:986
#6 0x00007f8eef3cdc45 in XrdHttpProtocol::Process (this=0x7f8eaf88ed00, lp=<optimized out>) at /usr/src/debug/xrootd/xrootd/src/XrdHttp/XrdHttpProtocol.cc:1004
#7 0x00007f8ef51f4d49 in XrdLink::DoIt (this=0x7f8dd44e12b8) at /usr/src/debug/xrootd/xrootd/src/Xrd/XrdLink.cc:441
#8 0x00007f8ef51f80df in XrdScheduler::Run (this=0x610e58 <XrdMain::Config+440>) at /usr/src/debug/xrootd/xrootd/src/Xrd/XrdScheduler.cc:357
#9 0x00007f8ef51f8229 in XrdStartWorking (carg=<optimized out>) at /usr/src/debug/xrootd/xrootd/src/Xrd/XrdScheduler.cc:87
#10 0x00007f8ef51bdba7 in XrdSysThread_Xeq (myargs=0x7f8ef1821720) at /usr/src/debug/xrootd/xrootd/src/XrdSys/XrdSysPthread.cc:86
#11 0x00007f8ef4d71ea5 in start_thread () from /lib64/libpthread.so.0
#12 0x00007f8ef40738dd in clone () from /lib64/libc.so.6
(gdb) f 6
#6 0x00007f8eef3cdc45 in XrdHttpProtocol::Process (this=0x7f8eaf88ed00, lp=<optimized out>) at /usr/src/debug/xrootd/xrootd/src/XrdHttp/XrdHttpProtocol.cc:1004
1004 rc = CurrentReq.ProcessHTTPReq();
(gdb) p CurrentReq
$1 = {<XrdXrootd::Bridge::Result> = {_vptr.Result = 0x7f8eef5e2ab0 <vtable for XrdHttpReq+16>}, httpStatusCode = 1114779509, httpStatusText = "", m_transfer_encoding_chunked = false, m_current_chunk_offset = 0, m_current_chunk_size = -1, prot = 0x7f8eaf88ed00, ralist = 0x0,
request = XrdHttpReq::rtMalformed,
requestverb = "\352\361\310E\b\350\313~~\215\214Q\354\351\253\375l\272\070\255Z\201\302l\366_\b\250\030~\211\016c~6\035\252\021\346\067\342\064\vR\035\267+\370\375oW\237\265X\346\336\027\351\337\325\324C\375[\244\302?\255t\206ֿ\243\305\347Y&\376r1n\001|\347\021y-\263\217\316ݹ\"|e\261\250و/M\305W^\302y|R", allheaders = std::map with 9 elements = {["`v"] = "%\r\022\275\002j4\236\232a|\305<\203#I\227d\210\324/y;\226\303\035\t\336\374\245(\fX\213-3\222\004bi(\366\360(",
["bK\237\t\324P\310\302\rO\221N\330\376\327\265-X\256\227\266ϒ(^J\017\004V\274\324a\363\305\373\226\343\070\341\266l\375J\202\231l\177\273EA\221o\276O\246\002\265\327ќ\327\\\301\322\306_\\.\216w\241\360\345\371\026\324\031\223\006\256ζl\205\325㳏\216u\200\271(", <incomplete sequence \360\272>] = "o\257Č/", ["xrd-http-query"] = "",
["\234\321Y\314e\306`\346\026\372\004u5\217\016ŵd\243c\277\224JM\264X\277{P\371\256`\025X\035n\341\352\005\"p9\vX\304\377\021,\244 u\020\"\321\372Ͳ\325/\330\031\270e\020<\201\256\351&\001\353\320\035\032_\340\310\332R\224\254,\b"] = "Vn\341i_\205\364\201\037\242\205@\367\232'%\267\242\336\032\071\260\a\b\021\035`\224\357\347/~\236\302\347ۗ\265\266\004?\343펄h\036\206\020\300\210\351z\374OH\367\anaK\222\263[\331ʐ\t!? \f\321\003\220\066\271|\262\340xMz\200s2\267\243\347}C\337\027\262\267\241\332X",
["\235jA\252\261\003\202\231\365\003\275!\257\377TR\a\005\345\356k\275\b\201\t\020\202QW\201\232\343\210RXƪ\251}\265\254\341\067PKY\003\360O^\340\243\204\276\225_\234\365\215\275D\\\202\\\"k\025\272\003\070\266\340I\255]\355\344l\030\035\214=(\251\342\305SV\325\350\332\006AơH'Ʌ\227\234失8\301Sǘ\353\001\211Z \017贸v\352i\357\252\361Hd\005\233j\257\273\226(S{\250\330\307+\317\005\324A\373\364\027\205h\021\035d"] = "A\327D\033\226\376\071\225\244\017\227)\023\222q\266\375Uvu\316V{=\026n\375\066!\361\372R\034\256^\332P\343\306\314\310\004\233\233\006\317ڲ#k\340\303\346(\316\301\021\005\232\337\035\303g1\351\305T\201\310v\teŮ\364\271Ճ\235\205\263V/\247\256\232\246\352\064H\001\202\341\323~`\215\203\276e,)}&\277\221\246M\227٧5",
["\240*\252b7\366\372\035\307T\216xka{\316b\341\307\067X6q\211\335\002\204G\r `9,^\241\205\a3\217\275l'\343t\273Tv\254\210\370}f\023\253Vko\232Gl\356]\342\221-\216\224\221\363P\001/\340\250\020\214\367\344\261\350\006A'\236O\024}\177\216\211\b>p@\201\004G\300\261!\300\\ޱd\375\210Re\ts1\002v0\257\217\275\247[id\277\224(I\373\021K\264\024b\226\355\257\363mc\275\004\350A\223mQa~%$\371\006\204J\033!\355hCJ\335|龧\215\355P\223"] = "`\365\337\302z\357\260\342J\022\022H\032\211uPi\206\266\355bMWa\323K\336\313\066\361\241\210;\034\344\210\060\002\021hT\222\377\017!Z\232\230f\276\202떯م9`\222\202\002\b\200\305v\216\325.\365\275\020\023\025\066\233\232K+ڭ\200\064Ğ\321pd",
```
If anyone wants access to the machine please let me know.
--
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-648681248
########################################################################
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
