Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

XrdHttp: error behavior with large Range requests could be improved #2003

Closed
jthiltges opened this issue Apr 27, 2023 · 6 comments · Fixed by #2022
Closed

XrdHttp: error behavior with large Range requests could be improved #2003

jthiltges opened this issue Apr 27, 2023 · 6 comments · Fixed by #2022
Assignees
@ccaffy
Labels
bug (non-critical)
Milestone
5.6.0

Comments

@jthiltges
Copy link
Contributor

In some instances, Uproot may produce HTTP requests with large Range requests: over 1024 items and length beyond 16k chars. XRootD unfortunately doesn't respond with standard HTTP error codes.

  1. For Range requests beyond 1024 items, XRootD HTTP sends two responses: success, followed by failure. This is confusing for HTTP clients:

client request:

GET /store/user/AGC/nanoAOD/TT_TuneCUETP8M1_13TeV-powheg-pythia8/cmsopendata2015_ttbar_19980_PU25nsData2015v1_76X_mcRun2_asymptotic_v12_ext3-v1_00000_0000.root HTTP/1.1
Host: red-xfer13.unl.edu:1094
User-Agent: python-requests/2.28.1
Accept-Encoding: gzip, deflate
Accept: */*
Connection: keep-alive
Range: bytes=0-4, 10-14, ..., 10240-10244

server reply:

HTTP/1.1 206 Partial Content
Connection: Keep-Alive
Server: XrootD/v5.5.4
Content-Length: 105417
Content-Type: multipart/byteranges; boundary=123456

HTTP/1.1 500 Internal Server Error
Connection: Close
Server: XrootD/v5.5.4
Content-Length: 24

Read vector is too long
Backtrace of breakpoint on XrdHttpProtocol::StartSimpleResp for the two replies 
#0  XrdHttpProtocol::StartSimpleResp (this=0x7f634400fee0, code=206, desc=0x0, header_to_add=0x7f6344021f10 "Content-Type: multipart/byteranges; boundary=123456", bodylen=105417, keepalive=true)
    at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdHttp/XrdHttpProtocol.cc:1517
#1  0x00007f635bacfc74 in XrdHttpProtocol::SendSimpleResp (this=0x7f634400fee0, code=<optimized out>, desc=<optimized out>, header_to_add=<optimized out>, body=0x0, bodylen=105417, keepalive=true)
    at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdHttp/XrdHttpProtocol.cc:1616
#2  0x00007f635badbc5c in XrdHttpReq::PostProcessHTTPReq (this=0x7f6344010040, final_=<optimized out>) at /usr/include/c++/8/bits/basic_string.h:2294
#3  0x00007f635badedf2 in XrdHttpReq::Data (this=0x7f6344010040, info=..., iovP_=0x7f634aa7b310, iovN_=2, iovL_=<optimized out>, final_=<optimized out>) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdHttp/XrdHttpReq.cc:511
#4  0x00007f636101e633 in XrdXrootdTransit::Send (this=0x7f63440204d0, rcode=rcode@entry=0, ioV=ioV@entry=0x7f634aa7b310, ioN=ioN@entry=2, ioL=ioL@entry=99) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdXrootd/XrdXrootdTransit.cc:675
#5  0x00007f636101aa56 in XrdXrootdResponse::Send (this=this@entry=0x7f63440208b8, IOResp=IOResp@entry=0x7f634aa7b300, iornum=iornum@entry=3, iolen=iolen@entry=99) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdXrootd/XrdXrootdResponse.cc:222
#6  0x00007f636102895d in XrdXrootdProtocol::do_Open (this=this@entry=0x7f63440204d8) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdXrootd/XrdXrootdXeq.cc:1627
#7  0x00007f63610192ec in XrdXrootdProtocol::Process2 (this=0x7f63440204d8) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdXrootd/XrdXrootdProtocol.cc:572
#8  0x00007f636101d495 in XrdXrootdTransit::Process (this=0x7f63440204d0, lp=0x7f6344008290) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdXrootd/XrdXrootdTransit.cc:397
#9  0x00007f6360d60400 in XrdLinkXeq::DoIt (this=<optimized out>) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/Xrd/XrdLinkXeq.cc:320
#10 XrdLinkXeq::DoIt (this=0x7f6344008290) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/Xrd/XrdLinkXeq.cc:308
#11 0x00007f6360d636a7 in XrdScheduler::Run (this=0x615740 <XrdGlobal::Sched>) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/Xrd/XrdScheduler.cc:406
#12 0x00007f6360d637c9 in XrdStartWorking (carg=<optimized out>) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/Xrd/XrdScheduler.cc:89
#13 0x00007f6360cf35e7 in XrdSysThread_Xeq (myargs=0x7f6354016370) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdSys/XrdSysPthread.cc:86
#14 0x00007f635fd4b1cf in start_thread () from /lib64/libpthread.so.0
#15 0x00007f635f9b6e73 in clone () from /lib64/libc.so.6

#0  XrdHttpProtocol::StartSimpleResp (this=0x7f634400fee0, code=500, desc=0x0, header_to_add=0x0, bodylen=24, keepalive=false) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdHttp/XrdHttpProtocol.cc:1517
#1  0x00007f635bacfc74 in XrdHttpProtocol::SendSimpleResp (this=0x7f634400fee0, code=<optimized out>, desc=<optimized out>, header_to_add=<optimized out>, body=0x7f6344029ff0 "Read vector is too long\n", bodylen=24, keepalive=false)
    at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdHttp/XrdHttpProtocol.cc:1616
#2  0x00007f635badc384 in XrdHttpReq::PostProcessHTTPReq (this=0x7f6344010040, final_=<optimized out>) at /usr/include/c++/8/bits/basic_string.h:2294
#3  0x00007f635badef6a in XrdHttpReq::Error (this=0x7f6344010040, info=..., ecode=3002, etext_=0x7f6361084892 "Read vector is too long") at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdHttp/XrdHttpReq.cc:563
#4  0x00007f636101e520 in XrdXrootdTransit::Send (this=0x7f63440204d0, rcode=rcode@entry=4003, ioV=ioV@entry=0x7f63440208e0, ioN=ioN@entry=2, ioL=<optimized out>) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdXrootd/XrdXrootdTransit.cc:671
#5  0x00007f636101ac0e in XrdXrootdResponse::Send (this=this@entry=0x7f63440208b8, ecode=ecode@entry=kXR_ArgTooLong, msg=msg@entry=0x7f6361084892 "Read vector is too long") at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdXrootd/XrdXrootdResponse.cc:252
#6  0x00007f6361024de0 in XrdXrootdProtocol::do_ReadV (this=this@entry=0x7f63440204d8) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdXrootd/XrdXrootdXeq.cc:2562
#7  0x00007f6361019190 in XrdXrootdProtocol::Process2 (this=0x7f63440204d8) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdXrootd/XrdXrootdProtocol.cc:484
#8  0x00007f636101d495 in XrdXrootdTransit::Process (this=0x7f63440204d0, lp=0x7f6344008290) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdXrootd/XrdXrootdTransit.cc:397
#9  0x00007f6360d60400 in XrdLinkXeq::DoIt (this=<optimized out>) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/Xrd/XrdLinkXeq.cc:320
#10 XrdLinkXeq::DoIt (this=0x7f6344008290) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/Xrd/XrdLinkXeq.cc:308
#11 0x00007f6360d636a7 in XrdScheduler::Run (this=0x615740 <XrdGlobal::Sched>) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/Xrd/XrdScheduler.cc:406
#12 0x00007f6360d637c9 in XrdStartWorking (carg=<optimized out>) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/Xrd/XrdScheduler.cc:89
#13 0x00007f6360cf35e7 in XrdSysThread_Xeq (myargs=0x7f6354016370) at /usr/src/debug/xrootd-5.5.4-1.1.osg36.el8.x86_64/xrootd/src/XrdSys/XrdSysPthread.cc:86
#14 0x00007f635fd4b1cf in start_thread () from /lib64/libpthread.so.0
#15 0x00007f635f9b6e73 in clone () from /lib64/libc.so.6
  1. For exceptionally large Range requests (roughly beyond 16k chars), the TCP connection is closed with a RST, and no HTTP reply. There doesn't seem to be an exact length beyond which a TCP RST is always received. As the header length exceeds 16k, the chances increase.

In both cases, an HTTP 431 Request Header Fields Too Large would probably be the most help for clients.

Sample python3 script 
#!/usr/bin/env python3
import logging
import http.client
http.client.HTTPConnection.debuglevel = 1

logging.basicConfig()
logging.getLogger().setLevel(logging.DEBUG)
requests_log = logging.getLogger("requests.packages.urllib3")
requests_log.setLevel(logging.DEBUG)
requests_log.propagate = True

import requests

url = 'http://red-xfer13.unl.edu:1094/store/user/AGC/nanoAOD/TT_TuneCUETP8M1_13TeV-powheg-pythia8/cmsopendata2015_ttbar_19980_PU25nsData2015v1_76X_mcRun2_asymptotic_v12_ext3-v1_00000_0000.root'

####
ranges = [ f'{10*x}-{10*x+4}' for x in range(0,1025) ]
#ranges = [ f'{10*x}-{10*x+4}' for x in range(0,3000) ]
headers = { 'Range': 'bytes=' + ', '.join(ranges), }

print(f'Count of Range entries: {len(ranges)}')
print(f'Length of Range header: {len(headers["Range"])}')

requests.get(url, headers=headers)
@jthiltges
Copy link
Contributor Author

As requested during the meeting, some further info.

What happens with typical HTTP servers?

Testing with a very large Range header, both Apache/2.4.37 and nginx/1.20.1 return HTTP/1.1 400 Bad Request.

Apache's HTML response includes Size of a request header field exceeds server limit. and nginx is similar.

Server logs with http.trace for a 1025-item range

A single request was submitted for a range of 1025 items. We expect a single 4xx failure response. Logs show two responses, 206 and 500:

230427 19:51:28.848710 2049052 unknown.8:38@hcc-pki-vpn http_Protocol: Sending resp: 206 header len:156
230427 19:51:28.848887 2049052 unknown.8:38@hcc-pki-vpn http_Protocol: Sending resp: 500 header len:100
Full logs 
230427 19:51:28.845968 2049051 anon.0:38@hcc-pki-vpn http_Protocol: received dlen: 16
230427 19:51:28.846025 2049051 anon.0:38@hcc-pki-vpn http_Protocol: received dump: 71 69 84 32 47 115 116 111 114 101 47 117 115 101 114 00 
230427 19:51:28.846034 2049051 anon.0:38@hcc-pki-vpn http_Protocol: Protocol matched. https: False
230427 19:51:28.846055 2049051 anon.0:38@hcc-pki-vpn http_Protocol:  Process. lp:0x1e59bb8 reqstate: 0
230427 19:51:28.846068 2049051 anon.0:38@hcc-pki-vpn http_Protocol:  Setting host: [::ffff:129.93.227.111]
230427 19:51:28.846076 2049051 http_Protocol: getDataOneShot BuffAvailable: 1048576 maxread: 1048576
230427 19:51:28.846092 2049051 http_Protocol: read 5528 of 1048576 bytes
230427 19:51:28.846103 2049051 http_Protocol:  rc:170 got hdr line: GET /store/user/AGC/nanoAOD/TT_TuneCUETP8M1_13TeV-powheg-pythia8/cmsopendata2015_ttbar_19980_PU25nsData2015v1_76X_mcRun2_asymptotic_v12_ext3-v1_00000_0000.root HTTP/1.1

230427 19:51:28.846110 2049051 http_Protocol:  Parsing first line: GET /store/user/AGC/nanoAOD/TT_TuneCUETP8M1_13TeV-powheg-pythia8/cmsopendata2015_ttbar_19980_PU25nsData2015v1_76X_mcRun2_asymptotic_v12_ext3-v1_00000_0000.root HTTP/1.1

230427 19:51:28.846123 2049051 http_Protocol:  rc:31 got hdr line: Host: red-xfer13.unl.edu:1094

230427 19:51:28.846137 2049051 http_Protocol:  rc:36 got hdr line: User-Agent: python-requests/2.28.1

230427 19:51:28.846147 2049051 http_Protocol:  rc:32 got hdr line: Accept-Encoding: gzip, deflate

230427 19:51:28.846156 2049051 http_Protocol:  rc:13 got hdr line: Accept: */*

230427 19:51:28.846165 2049051 http_Protocol:  rc:24 got hdr line: Connection: keep-alive

230427 19:51:28.846179 2049051 anon.0:38@hcc-pki-vpn http_Protocol:  rc:0Header not yet complete.
230427 19:51:28.846443 2049052 anon.0:38@hcc-pki-vpn http_Protocol:  Process. lp:0x1e59bb8 reqstate: 0
230427 19:51:28.846469 2049052 http_Protocol: getDataOneShot BuffAvailable: 1043048 maxread: 1043048
230427 19:51:28.846498 2049052 http_Protocol: read 5896 of 1043048 bytes
230427 19:51:28.846522 2049052 http_Protocol:  rc:11116 got hdr line: Range: bytes=0-4, 10-14, 20-24, 30-34, 40-44, 50-54, 60-64, 70-74, 80-84, 90-94, 100-104, 110-114, 120-124, 130-134, 140-144, 150-154, 160-164, 170-174, 180-184, 190-194, 200-204, 210-214, 220-224, 230-234, 240-244, 250-254, 260-264, 270-274, 280-284, 290-294, 300-304, 310-314, 320-324, 330-334, 340-344, 350-354, 360-364, 370-374, 380-384, 390-394, 400-404, 410-414, 420-424, 430-434, 440-444, 450-454, 460-464, 470-474, 480-484, 490-494, 500-504, 510-514, 520-524, 530-534, 540-544, 550-554, 560-564, 570-574, 580-584, 590-594, 600-604, 610-614, 620-624, 630-634, 640-644, 650-654, 660-664, 670-674, 680-684, 690-694, 700-704, 710-714, 720-724, 730-734, 740-744, 750-754, 760-764, 770-774, 780-784, 790-794, 800-804, 810-814, 820-824, 830-834, 840-844, 850-854, 860-864, 870-874, 880-884, 890-894, 900-904, 910-914, 920-924, 930-934, 940-944, 950-954, 960-964, 970-974, 980-984, 990-994, 1000-1004, 1010-1014, 1020-1024, 1030-1034, 1040-1044, 1050-1054, 1060-1064, 1070-1074, 1080-1084, 1090-1094, 1100-1104, 1110-1114, 1120-1124, 1130-1134, 1140-1144, 1150-1154, 1160-1164, 1170-1174, 1180-1184, 1190-1194, 1200-1204, 1210-1214, 1220-1224, 1230-1234, 1240-1244, 1250-1254, 1260-1264, 1270-1274, 1280-1284, 1290-1294, 1300-1304, 1310-1314, 1320-1324, 1330-1334, 1340-1344, 1350-1354, 1360-1364, 1370-1374, 1380-1384, 1390-1394, 1400-1404, 1410-1414, 1420-1424, 1430-1434, 1440-1444, 1450-1454, 1460-1464, 1470-1474, 1480-1484, 1490-1494, 1500-1504, 1510-1514, 1520-1524, 1530-1534, 1540-1544, 1550-1554, 1560-1564, 1570-1574, 1580-1584, 1590-1594, 1600-1604, 1610-1614, 1620-1624, 1630-1634, 1640-1644, 1650-1654, 1660-1664, 1670-1674, 1680-1684, 1690-1694, 1700-1704, 1710-1714, 1720-1724, 1730-1734, 1740-1744, 1750-1754, 1760-1764, 1770-1774, 1780-1784, 1790-1794, 1800-1804, 1810-1814, 1820-1824, 1830-1834, 1840-1844, 1850-1854, 1860-1864, 1870-1874, 1880-1884, 1890-1894, 1900-1904, 1910-1914, 1920-1924, 1930-1934, 1940-1944, 1950-1954, 1960-1964, 1970-1974, 1980-1984, 1990-1994, 2000-2004, 2010-2014, 2020-2024, 2030-2034, 2040-2044, 2050-2054, 2060-2064, 2070-2074, 2080-2084, 2090-2094, 2100-2104, 2110-2114, 2120-2124, 2130-2134, 2140-2144, 2150-2154, 2160-2164, 2170-2174, 2180-2184, 2190-2194, 2200-2204, 2210-2214, 2220-2224, 2230-2234, 2240-2244, 2250-2254, 2260-2264, 2270-2274, 2280-2284, 2290-2294, 2300-2304, 2310-2314, 2320-2324, 2330-2334, 2340-2344, 2350-2354, 2360-2364, 2370-2374, 2380-2384, 2390-2394, 2400-2404, 2410-2414, 2420-2424, 2430-2434, 2440-2444, 2450-2454, 2460-2464, 2470-2474, 2480-2484, 2490-2494, 2500-2504, 2510-2514, 2520-2524, 2530-2534, 2540-2544, 2550-2554, 2560-2564, 2570-2574, 2580-2584, 2590-2594, 2600-2604, 2610-2614, 2620-2624, 2630-2634, 2640-2644, 2650-2654, 2660-2664, 2670-2674, 2680-2684, 2690-2694, 2700-2704, 2710-2714, 2720-2724, 2730-2734, 2740-2744, 2750-2754, 2760-2764, 2770-2774, 2780-2784, 2790-2794, 2800-2804, 2810-2814, 2820-2824, 2830-2834, 2840-2844, 2850-2854, 2860-2864, 2870-2874, 2880-2884, 2890-2894, 2900-2904, 2910-2914, 2920-2924, 2930-2934, 2940-2944, 2950-2954, 2960-2964, 2970-2974, 2980-2984, 2990-2994, 3000-3004, 3010-3014, 3020-3024, 3030-3034, 3040-3044, 3050-3054, 3060-3064, 3070-3074, 3080-3084, 3090-3094, 3100-3104, 3110-3114, 3120-3124, 3130-3134, 3140-3144, 3150-3154, 3160-3164, 3170-3174, 3180-3184, 3190-3194, 3200-3204, 3210-3214, 3220-3224, 3230-3234, 3240-3244, 3250-3254, 3260-3264, 3270-3274, 3280-3284, 3290-3294, 3300-3304, 3310-3314, 3320-3324, 3330-3334, 3340-3344, 3350-3354, 3360-3364, 3370-3374, 3380-3384, 3390-3394, 3400-3404, 3410-3414, 3420-3424, 3430-3434, 3440-3444, 3450-3454, 3460-3464, 3470-3474, 3480-3484, 3490-3494, 3500-3504, 3510-3514, 3520-3524, 3530-3534, 3540-3544, 3550-3554, 3560-3564, 3570-3574, 3580-3584, 3590-3594, 3600-3604, 3610-3614, 3620-3624, 3630-3634, 3640-3644, 3650-3654, 3660-3664, 3670-3674, 3680-3684, 3690-3694, 3700-3704, 3710-3714, 3720-3724, 3730-3734, 3740-3744, 3750-3754, 3760-3764, 3770-3774, 3780-3784, 3790-3794, 3800-3804, 3810-3814, 3820-3824, 3830-3834, 3840-3844, 3850-3854, 3860-3864, 3870-3874, 3880-3884, 3890-3894, 3900-3904, 3910-3914, 3920-3924, 3930-3934, 3940-3944, 3950-3954, 3960-3964, 3970-3974, 3980-3984, 3990-3994, 4000-4004, 4010-4014, 4020-4024, 4030-4034, 4040-4044, 4050-4054, 4060-4064, 4070-4074, 4080-4084, 4090-4094, 4100-4104, 4110-4114, 4120-4124, 4130-4134, 4140-4144, 4150-4154, 4160-4164, 4170-4174, 4180-4184, 4190-4194, 4200-4204, 4210-4214, 4220-4224, 4230-4234, 4240-4244, 4250-4254, 4260-4264, 4270-4274, 4280-4284, 4290-4294, 4300-4304, 4310-4314, 4320-4324, 4330-4334, 4340-4344, 4350-4354, 4360-4364, 4370-4374, 4380-4384, 4390-4394, 4400-4404, 4410-4414, 4420-4424, 4430-4434, 4440-4444, 4450-4454, 4460-4464, 4470-4474, 4480-4484, 4490-4494, 4500-4504, 4510-4514, 4520-4524, 4530-4534, 4540-4544, 4550-4554, 4560-4564, 4570-4574, 4580-4584, 4590-4594, 4600-4604, 4610-4614, 4620-4624, 4630-4634, 4640-4644, 4650-4654, 4660-4664, 4670-4674, 4680-4684, 4690-4694, 4700-4704, 4710-4714, 4720-4724, 4730-4734, 4740-4744, 4750-4754, 4760-4764, 4770-4774, 4780-4784, 4790-4794, 4800-4804, 4810-4814, 4820-4824, 4830-4834, 4840-4844, 4850-4854, 4860-4864, 4870-4874, 4880-4884, 4890-4894, 4900-4904, 4910-4914, 4920-4924, 4930-4934, 4940-4944, 4950-4954, 4960-4964, 4970-4974, 4980-4984, 4990-4994, 5000-5004, 5010-5014, 5020-5024, 5030-5034, 5040-5044, 5050-5054, 5060-5064, 5070-5074, 5080-5084, 5090-5094, 5100-5104, 5110-5114, 5120-5124, 5130-5134, 5140-5144, 5150-5154, 5160-5164, 5170-5174, 5180-5184, 5190-5194, 5200-5204, 5210-5214, 5220-5224, 5230-5234, 5240-5244, 5250-5254, 5260-5264, 5270-5274, 5280-5284, 5290-5294, 5300-5304, 5310-5314, 5320-5324, 5330-5334, 5340-5344, 5350-5354, 5360-5364, 5370-5374, 5380-5384, 5390-5394, 5400-5404, 5410-5414, 5420-5424, 5430-5434, 5440-5444, 5450-5454, 5460-5464, 5470-5474, 5480-5484, 5490-5494, 5500-5504, 5510-5514, 5520-5524, 5530-5534, 5540-5544, 5550-5554, 5560-5564, 5570-5574, 5580-5584, 5590-5594, 5600-5604, 5610-5614, 5620-5624, 5630-5634, 5640-5644, 5650-5654, 5660-5664, 5670-5674, 5680-5684, 5690-5694, 5700-5704, 5710-5714, 5720-5724, 5730-5734, 5740-5744, 5750-5754, 5760-5764, 5770-5774, 5780-5784, 5790-5794, 5800-5804, 5810-5814, 5820-5824, 5830-5834, 5840-5844, 5850-5854, 5860-5864, 5870-5874, 5880-5884, 5890-5894, 5900-5904, 5910-5914, 5920-5924, 5930-5934, 5940-5944, 5950-5954, 5960-5964, 5970-5974, 5980-5984, 5990-5994, 6000-6004, 6010-6014, 6020-6024, 6030-6034, 6040-6044, 6050-6054, 6060-6064, 6070-6074, 6080-6084, 6090-6094, 6100-6104, 6110-6114, 6120-6124, 6130-6134, 6140-6144, 6150-6154, 6160-6164, 6170-6174, 6180-6184, 6190-6194, 6200-6204, 6210-6214, 6220-6224, 6230-6234, 6240-6244, 6250-6254, 6260-6264, 6270-6274, 6280-6284, 6290-6294, 6300-6304, 6310-6314, 6320-6324, 6330-6334, 6340-6344, 6350-6354, 6360-6364, 6370-6374, 6380-6384, 6390-6394, 6400-6404, 6410-6414, 6420-6424, 6430-6434, 6440-6444, 6450-6454, 6460-6464, 6470-6474, 6480-6484, 6490-6494, 6500-6504, 6510-6514, 6520-6524, 6530-6534, 6540-6544, 6550-6554, 6560-6564, 6570-6574, 6580-6584, 6590-6594, 6600-6604, 6610-6614, 6620-6624, 6630-6634, 6640-6644, 6650-6654, 6660-6664, 6670-6674, 6680-6684, 6690-6694, 6700-6704, 6710-6714, 6720-6724, 6730-6734, 6740-6744, 6750-6754, 6760-6764, 6770-6774, 6780-6784, 6790-6794, 6800-6804, 6810-6814, 6820-6824, 6830-6834, 6840-6844, 6850-6854, 6860-6864, 6870-6874, 6880-6884, 6890-6894, 6900-6904, 6910-6914, 6920-6924, 6930-6934, 6940-6944, 6950-6954, 6960-6964, 6970-6974, 6980-6984, 6990-6994, 7000-7004, 7010-7014, 7020-7024, 7030-7034, 7040-7044, 7050-7054, 7060-7064, 7070-7074, 7080-7084, 7090-7094, 7100-7104, 7110-7114, 7120-7124, 7130-7134, 7140-7144, 7150-7154, 7160-7164, 7170-7174, 7180-7184, 7190-7194, 7200-7204, 7210-7214, 7220-7224, 7230-7234, 7240-7244, 7250-7254, 7260-7264, 7270-7274, 7280-7284, 7290-7294, 7300-7304, 7310-7314, 7320-7324, 7330-7334, 7340-7344, 7350-7354, 7360-7364, 7370-7374, 7380-7384, 7390-7394, 7400-7404, 7410-7414, 7420-7424, 7430-7434, 7440-7444, 7450-7454, 7460-7464, 7470-7474, 7480-7484, 7490-7494, 7500-7504, 7510-7514, 7520-7524, 7530-7534, 7540-7544, 7550-7554, 7560-7564, 7570-7574, 7580-7584, 7590-7594, 7600-7604, 7610-7614, 7620-7624, 7630-7634, 7640-7644, 7650-7654, 7660-7664, 7670-7674, 7680-7684, 7690-7694, 7700-7704, 7710-7714, 7720-7724, 7730-7734, 7740-7744, 7750-7754, 7760-7764, 7770-7774, 7780-7784, 7790-7794, 7800-7804, 7810-7814, 7820-7824, 7830-7834, 7840-7844, 7850-7854, 7860-7864, 7870-7874, 7880-7884, 7890-7894, 7900-7904, 7910-7914, 7920-7924, 7930-7934, 7940-7944, 7950-7954, 7960-7964, 7970-7974, 7980-7984, 7990-7994, 8000-8004, 8010-8014, 8020-8024, 8030-8034, 8040-8044, 8050-8054, 8060-8064, 8070-8074, 8080-8084, 8090-8094, 8100-8104, 8110-8114, 8120-8124, 8130-8134, 8140-8144, 8150-8154, 8160-8164, 8170-8174, 8180-8184, 8190-8194, 8200-8204, 8210-8214, 8220-8224, 8230-8234, 8240-8244, 8250-8254, 8260-8264, 8270-8274, 8280-8284, 8290-8294, 8300-8304, 8310-8314, 8320-8324, 8330-8334, 8340-8344, 8350-8354, 8360-8364, 8370-8374, 8380-8384, 8390-8394, 8400-8404, 8410-8414, 8420-8424, 8430-8434, 8440-8444, 8450-8454, 8460-8464, 8470-8474, 8480-8484, 8490-8494, 8500-8504, 8510-8514, 8520-8524, 8530-8534, 8540-8544, 8550-8554, 8560-8564, 8570-8574, 8580-8584, 8590-8594, 8600-8604, 8610-8614, 8620-8624, 8630-8634, 8640-8644, 8650-8654, 8660-8664, 8670-8674, 8680-8684, 8690-8694, 8700-8704, 8710-8714, 8720-8724, 8730-8734, 8740-8744, 8750-8754, 8760-8764, 8770-8774, 8780-8784, 8790-8794, 8800-8804, 8810-8814, 8820-8824, 8830-8834, 8840-8844, 8850-8854, 8860-8864, 8870-8874, 8880-8884, 8890-8894, 8900-8904, 8910-8914, 8920-8924, 8930-8934, 8940-8944, 8950-8954, 8960-8964, 8970-8974, 8980-8984, 8990-8994, 9000-9004, 9010-9014, 9020-9024, 9030-9034, 9040-9044, 9050-9054, 9060-9064, 9070-9074, 9080-9084, 9090-9094, 9100-9104, 9110-9114, 9120-9124, 9130-9134, 9140-9144, 9150-9154, 9160-9164, 9170-9174, 9180-9184, 9190-9194, 9200-9204, 9210-9214, 9220-9224, 9230-9234, 9240-9244, 9250-9254, 9260-9264, 9270-9274, 9280-9284, 9290-9294, 9300-9304, 9310-9314, 9320-9324, 9330-9334, 9340-9344, 9350-9354, 9360-9364, 9370-9374, 9380-9384, 9390-9394, 9400-9404, 9410-9414, 9420-9424, 9430-9434, 9440-9444, 9450-9454, 9460-9464, 9470-9474, 9480-9484, 9490-9494, 9500-9504, 9510-9514, 9520-9524, 9530-9534, 9540-9544, 9550-9554, 9560-9564, 9570-9574, 9580-9584, 9590-9594, 9600-9604, 9610-9614, 9620-9624, 9630-9634, 9640-9644, 9650-9654, 9660-9664, 9670-9674, 9680-9684, 9690-9694, 9700-9704, 9710-9714, 9720-9724, 9730-9734, 9740-9744, 9750-9754, 9760-9764, 9770-9774, 9780-9784, 9790-9794, 9800-9804, 9810-9814, 9820-9824, 9830-9834, 9840-9844, 9850-9854, 9860-9864, 9870-9874, 9880-9884, 9890-9894, 9900-9904, 9910-9914, 9920-9924, 9930-9934, 9940-9944, 9950-9954, 9960-9964, 9970-9974, 9980-9984, 9990-9994, 10000-10004, 10010-10014, 10020-10024, 10030-10034, 10040-10044, 10050-10054, 10060-10064, 10070-10074, 10080-10084, 10090-10094, 10100-10104, 10110-10114, 10120-10124, 10130-10134, 10140-10144, 10150-10154, 10160-10164, 10170-10174, 10180-10184, 10190-10194, 10200-10204, 10210-10214, 10220-10224, 10230-10234, 10240-10244

230427 19:51:28.846751 2049052 http_Protocol:  rc:2 got hdr line: 

230427 19:51:28.846761 2049052 http_Protocol:  rc:2 detected header end.
230427 19:51:28.846849 2049052 XrootdBridge: unknown.8:38@hcc-pki-vpn login as nobody
230427 19:51:28.846869 2049052 multiuser_UserSentry: Anonymous client; no user set, cannot change FS UIDs
230427 19:51:28.846879 2049052 unknown.8:38@hcc-pki-vpn http_Protocol:  Process. lp:0x1e59bb8 reqstate: 0
230427 19:51:28.846891 2049052 unknown.8:38@hcc-pki-vpn http_Protocol: Process is exiting rc:0
230427 19:51:28.846914 2049052 acc_Audit: unknown.8:38@hcc-pki-vpn grant http *@[::ffff:129.93.227.111] stat /store/user/AGC/nanoAOD/TT_TuneCUETP8M1_13TeV-powheg-pythia8/cmsopendata2015_ttbar_19980_PU25nsData2015v1_76X_mcRun2_asymptotic_v12_ext3-v1_00000_0000.root
230427 19:51:28.846923 2049052 multiuser_UserSentry: Anonymous client; no user set, cannot change FS UIDs
230427 19:51:28.847008 2049052 unknown.8:38@hcc-pki-vpn Xrootd_Protocol: rc=0 stat /store/user/AGC/nanoAOD/TT_TuneCUETP8M1_13TeV-powheg-pythia8/cmsopendata2015_ttbar_19980_PU25nsData2015v1_76X_mcRun2_asymptotic_v12_ext3-v1_00000_0000.root
230427 19:51:28.847032 2049052 http_Req:  XrdHttpReq::Data! final=False
230427 19:51:28.847041 2049052 unknown.8:38@hcc-pki-vpn http_Req: PostProcessHTTPReq req: 2 reqstate: 0
230427 19:51:28.847048 2049052 unknown.8:38@hcc-pki-vpn http_Req: Stat for GET /store/user/AGC/nanoAOD/TT_TuneCUETP8M1_13TeV-powheg-pythia8/cmsopendata2015_ttbar_19980_PU25nsData2015v1_76X_mcRun2_asymptotic_v12_ext3-v1_00000_0000.root stat=252063246826078254 3295266958 16 1673441713 1673441713 1668576304 0644 cmsuser cmsuser
230427 19:51:28.847059 2049052 unknown.8:38@hcc-pki-vpn http_Protocol:  Process. lp:(nil) reqstate: 0
230427 19:51:28.847068 2049052 unknown.8:38@hcc-pki-vpn http_Protocol: Process is exiting rc:0
230427 19:51:28.847076 2049052 unknown.8:38@hcc-pki-vpn Xrootd_Protocol: open rt /store/user/AGC/nanoAOD/TT_TuneCUETP8M1_13TeV-powheg-pythia8/cmsopendata2015_ttbar_19980_PU25nsData2015v1_76X_mcRun2_asymptotic_v12_ext3-v1_00000_0000.root
230427 19:51:28.847094 2049052 acc_Audit: unknown.8:38@hcc-pki-vpn grant http *@[::ffff:129.93.227.111] read /store/user/AGC/nanoAOD/TT_TuneCUETP8M1_13TeV-powheg-pythia8/cmsopendata2015_ttbar_19980_PU25nsData2015v1_76X_mcRun2_asymptotic_v12_ext3-v1_00000_0000.root
230427 19:51:28.847110 2049052 multiuser_UserSentry: Anonymous client; no user set, cannot change FS UIDs
230427 19:51:28.847161 2049052 multiuser_Open: Will not create checksum
230427 19:51:28.847226 2049052 http_Req:  XrdHttpReq::Data! final=True
230427 19:51:28.847238 2049052 unknown.8:38@hcc-pki-vpn http_Req: PostProcessHTTPReq req: 2 reqstate: 1
230427 19:51:28.847246 2049052 unknown.8:38@hcc-pki-vpn http_Req: fhandle:0:0:0:0
230427 19:51:28.848710 2049052 unknown.8:38@hcc-pki-vpn http_Protocol: Sending resp: 206 header len:156
230427 19:51:28.848730 2049052 http_Protocol: Sending 156 bytes
230427 19:51:28.848776 2049052 unknown.8:38@hcc-pki-vpn http_Protocol:  Process. lp:(nil) reqstate: 1
230427 19:51:28.848840 2049052 unknown.8:38@hcc-pki-vpn http_Protocol: Process is exiting rc:0
230427 19:51:28.848851 2049052 unknown.8:38@hcc-pki-vpn Xrootd_Response: sending err 3002: Read vector is too long
230427 19:51:28.848858 2049052 http_Req:  XrdHttpReq::Error
230427 19:51:28.848866 2049052 unknown.8:38@hcc-pki-vpn http_Req: PostProcessHTTPReq req: 2 reqstate: 2
230427 19:51:28.848873 2049052 unknown.8:38@hcc-pki-vpn http_Req: PostProcessHTTPReq mapping Xrd error [3002] to status code [500]
230427 19:51:28.848887 2049052 unknown.8:38@hcc-pki-vpn http_Protocol: Sending resp: 500 header len:100
230427 19:51:28.848895 2049052 http_Protocol: Sending 100 bytes
230427 19:51:28.848907 2049052 http_Protocol: Sending 24 bytes
230427 19:51:28.848917 2049052 http_Req:  XrdHttpReq request ended.
230427 19:51:28.848938 2049052 http_Protocol:  Cleanup
230427 19:51:28.848947 2049052 http_Protocol:  Reset
230427 19:51:28.848953 2049052 http_Req:  XrdHttpReq request ended.
230427 19:51:28.848962 2049052 XrootdXeq: unknown.8:38@hcc-pki-vpn disc 0:00:00 (send failure)
230427 19:51:28.848972 2049052 multiuser_UserSentry: Anonymous client; no user set, cannot change FS UIDs
230427 19:51:28.848982 2049052 unknown.8:38@hcc-pki-vpn Xrootd_File: closing r /store/user/AGC/nanoAOD/TT_TuneCUETP8M1_13TeV-powheg-pythia8/cmsopendata2015_ttbar_19980_PU25nsData2015v1_76X_mcRun2_asymptotic_v12_ext3-v1_00000_0000.root

Server logs with http.trace for a 2500-item range, 30282 bytes

For a very large Range header, XRootD closes the connection without an HTTP reply. Testing with Apache and nginx, we receive a 400 error.

230427 20:00:51.134577 2049174 anon.0:38@hcc-pki-vpn http_Protocol: Corrupted header detected, or line too long. Disconnecting client.
Full logs 
230427 20:00:51.131862 2049051 anon.0:38@hcc-pki-vpn http_Protocol: received dlen: 16
230427 20:00:51.131944 2049051 anon.0:38@hcc-pki-vpn http_Protocol: received dump: 71 69 84 32 47 115 116 111 114 101 47 117 115 101 114 00 
230427 20:00:51.132033 2049051 anon.0:38@hcc-pki-vpn http_Protocol: Protocol matched. https: False
230427 20:00:51.132087 2049051 anon.0:38@hcc-pki-vpn http_Protocol:  Process. lp:0x1e59bb8 reqstate: 0
230427 20:00:51.132132 2049051 anon.0:38@hcc-pki-vpn http_Protocol:  Setting host: [::ffff:129.93.227.111]
230427 20:00:51.132144 2049051 http_Protocol: getDataOneShot BuffAvailable: 1048576 maxread: 1048576
230427 20:00:51.132164 2049051 http_Protocol: read 13820 of 1048576 bytes
230427 20:00:51.132175 2049051 http_Protocol:  rc:170 got hdr line: GET /store/user/AGC/nanoAOD/TT_TuneCUETP8M1_13TeV-powheg-pythia8/cmsopendata2015_ttbar_19980_PU25nsData2015v1_76X_mcRun2_asymptotic_v12_ext3-v1_00000_0000.root HTTP/1.1

230427 20:00:51.132182 2049051 http_Protocol:  Parsing first line: GET /store/user/AGC/nanoAOD/TT_TuneCUETP8M1_13TeV-powheg-pythia8/cmsopendata2015_ttbar_19980_PU25nsData2015v1_76X_mcRun2_asymptotic_v12_ext3-v1_00000_0000.root HTTP/1.1

230427 20:00:51.132195 2049051 http_Protocol:  rc:31 got hdr line: Host: red-xfer13.unl.edu:1094

230427 20:00:51.132209 2049051 http_Protocol:  rc:36 got hdr line: User-Agent: python-requests/2.28.1

230427 20:00:51.132220 2049051 http_Protocol:  rc:32 got hdr line: Accept-Encoding: gzip, deflate

230427 20:00:51.132228 2049051 http_Protocol:  rc:13 got hdr line: Accept: */*

230427 20:00:51.132237 2049051 http_Protocol:  rc:24 got hdr line: Connection: keep-alive

230427 20:00:51.132289 2049051 anon.0:38@hcc-pki-vpn http_Protocol:  rc:0Header not yet complete.
230427 20:00:51.134332 2049174 anon.0:38@hcc-pki-vpn http_Protocol:  Process. lp:0x1e59bb8 reqstate: 0
230427 20:00:51.134428 2049174 http_Protocol: getDataOneShot BuffAvailable: 1034756 maxread: 1034756
230427 20:00:51.134525 2049174 http_Protocol: read 8292 of 1034756 bytes
230427 20:00:51.134569 2049174 anon.0:38@hcc-pki-vpn http_Protocol:  rc:0Header not yet complete.
230427 20:00:51.134577 2049174 anon.0:38@hcc-pki-vpn http_Protocol: Corrupted header detected, or line too long. Disconnecting client.
230427 20:00:51.134586 2049174 http_Protocol:  Cleanup
230427 20:00:51.134612 2049174 http_Protocol:  Reset
230427 20:00:51.134622 2049174 http_Req:  XrdHttpReq request ended.

@xrootd-dev
Copy link

xrootd-dev commented Apr 27, 2023 via email

@masonproffitt
Copy link

Just chiming in to say that this is closely related to #1976, although there my problem isn't with the number of ranges or the length of the request header, but the total number of bytes requested by a Range.

@alexander-held alexander-held mentioned this issue May 1, 2023
Open
@masonproffitt masonproffitt mentioned this issue May 1, 2023
Closed
@jthiltges
Copy link
Contributor Author

Hmmm, I don't see the case where you get two responses: first is a continuation, the second is an error. The one here sent an error only. I will admit that the error code and message could be better.

My apologies. This issue is challenging to describe. For the request, there's two responses, but no payload. After the large (>1024) range request, this is the complete response:

HTTP/1.1 206 Partial Content
Connection: Keep-Alive
Server: XrootD/v5.5.4
Content-Length: 105417
Content-Type: multipart/byteranges; boundary=123456

HTTP/1.1 500 Internal Server Error
Connection: Close
Server: XrootD/v5.5.4
Content-Length: 24

Read vector is too long

I'd have expected the 206 reply to include a payload. And I suspect this behavior is confusing HTTP clients.

Since a picture pcap is worth a thousand words, I've attempted to attach a wireshark capture of the conversation.
red-xfer13-range-1025.pcapng.gz

And thank you for linking the related issues, Mason. I should have done a better search before opening this one. Please close this one if appropriate.

@bbockelm
Copy link
Contributor

bbockelm commented May 1, 2023

@jthiltges - I think this is a separate item from #1976.

@ccaffy ccaffy mentioned this issue Jun 1, 2023
Merged
@ccaffy
Copy link
Contributor

ccaffy commented Jun 8, 2023

Done and merged here: #2022

@ccaffy ccaffy closed this as completed Jun 8, 2023
@amadio amadio added this to the 5.6 milestone Jun 8, 2023
@amadio amadio linked a pull request Jun 8, 2023 that will close this issue
[XrdHttp] A bad request error is returned in the case a client provides too many range requests #2022
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@ccaffy ccaffy

Labels
bug (non-critical)
Projects
None yet
Milestone
5.6.0
7 participants
@amadio @bbockelm @jthiltges @abh3 @xrootd-dev @masonproffitt @ccaffy