Page MenuHomePhabricator

Jobrunner timeouts on cross-DC file uploads because of HTTP/2
Closed, ResolvedPublic

Description

This is a followup investigation of T274589: No atomic section is open (got LocalFile::lockingTransaction) to be more focused on the specific "slow PUTs" problem.

The problem: mw times out on a database transaction e.g. on writing stashed files to swift. Turns out that files are being written from eqiad to codfw at about ~2Mbps, thus a ~600MB file can hit the 300s mw timeout (more context at https://phabricator.wikimedia.org/T274589#6850912).

One example of this problem is the following upload from mw1305 (a jobrunner), which takes 6s in eqiad and 300s in codfw:

Feb 23 10:52:40 ms-fe1007 proxy-server: 10.64.16.105 10.64.32.220 23/Feb/2021/10/52/40 PUT /v1/AUTH_mw/wikipedia-commons-local-public.9d/9/9d/TheLostWorld1925.webm HTTP/1.0 201 - wikimedia/multi-http-client%20v1.0 AUTH_tk6fb0dd3ce... 624059195 - 3a6f10dc474ed8113e1498a5751bb075 tx4a56556fd5e44e01bab13-006034de71 - 7.8468 - - 1614077553.124433041 1614077560.971237898 0

Feb 23 10:58:13 ms-fe2007 proxy-server: 10.64.16.105 10.192.32.155 23/Feb/2021/10/58/13 PUT /v1/AUTH_mw/wikipedia-commons-local-public.9d/9/9d/TheLostWorld1925.webm HTTP/1.0 201 - wikimedia/multi-http-client%20v1.0 AUTH_tk5c39f2dc9... 624059195 - 3a6f10dc474ed8113e1498a5751bb075 tx3a392c4173db430aa9e05-006034de82 - 323.8699 - - 1614077570.121001959 1614077893.990885019 0

I've tallied on centrallog hosts the average transfer time in codfw for commons PUTs larger than 300MB, to get a better idea of the time frames involved (note that the day boundaries are not exact, log files are rotated at ~6 UTC)

zcat ms-fe2*/swift.log-2021${date}.gz | awk '$16 > 300000000 && /PUT \/v1\/AUTH_mw\/wikipedia-commons-local-public/ {print $21 }'
jan 01 7.72208
jan 02 8.49384333333333
jan 03 7.75212173913044
...
jan 23 7.75591935483871
jan 24 6.15061379310345
jan 25 9.28589795918367
jan 26 99.3627666666667
jan 27 23.3935756097561
jan 28 9.05734482758621
jan 29 28.5930095238095
jan 30 149.271148
jan 31 70.0038066666667
feb 01 15.1718
feb 02 156.918878571429
feb 03 24.7632038461538
feb 04 52.9359363636364
feb 05 40.7238714285714
feb 06 125.034576923077
feb 07 120.699621428571
feb 08 171.219108333333
feb 09 198.86314
feb 10 320.42824
feb 11 234.13601875
feb 12 349.262411504425
feb 13 384.73485648855
feb 14 390.028958823529
feb 15 409.759209090909
feb 16 346.23785
feb 17 346.446857142857
feb 18 313.29496
feb 19 335.622576190476
feb 20 233.52412
feb 21 355.615288
feb 22 270.534185365854
feb 23 270.328245454545
feb 24 229.021636842105

During the Feb 11th time window we were, among other things, in the process of decom'ing swift codfw hosts (T272837) and thus pushing more weight to existing hosts. The codfw swift cluster is now in steady state, in the sense that there are no planned com/decom.

The timeframe also coincided with Buster upgrades for mw hosts, and indeed the reported slow jobrunners are all the Buster ones. See also https://phabricator.wikimedia.org/T275752#6864889 for futher context.

Related Objects

StatusSubtypeAssignedTask
Stalledtstarling
StalledNone
StalledNone
StalledNone
StalledNone
OpenNone
StalledNone
StalledNone
InvalidNone
StalledNone
StalledNone
OpenNone
OpenPRODUCTION ERRORNone
Resolvedtstarling
OpenNone
ResolvedKrinkle
OpenNone
ResolvedJdforrester-WMF
ResolvedDzahn
OpenNone
ResolvedLegoktm

Event Timeline

There are a very large number of changes, so older changes are hidden. Show Older Changes

I'll also note that the behavior is generally quite rare compared to the number of PUTs from jobrunners, e.g. I haven't been able to reproduce using the swift python client. +1 to re-image a stretch jobrunner

Looking back a few days, e.g. Feb 4-5th, the list of hosts that take > 80s is still eqiad jobrunners, and suspiciously all have been running buster by that date:

AFAICS, T245757 says we're almost fully on buster, so it isn't a surprise that all of them are running buster. mwdebug1003 is stretch, as well as mw1402 (api server) and mw1403 (app server), all of them are special-cases exactly for the purpose of ruling-out/confirming a distro upgrade breaking something.

If it's possible to try it at a given mw server, maybe you can try with those? Or do we need some traffic there (at which point we'd need to reimage a random jobrunner back to stretch)?

Looking back a few days, e.g. Feb 4-5th, the list of hosts that take > 80s is still eqiad jobrunners, and suspiciously all have been running buster by that date:

AFAICS, T245757 says we're almost fully on buster, so it isn't a surprise that all of them are running buster. mwdebug1003 is stretch, as well as mw1402 (api server) and mw1403 (app server), all of them are special-cases exactly for the purpose of ruling-out/confirming a distro upgrade breaking something.

If it's possible to try it at a given mw server, maybe you can try with those? Or do we need some traffic there (at which point we'd need to reimage a random jobrunner back to stretch)?

From my findings in the swift logs the slow uploads happen occasionally only on buster jobrunners, not other mw hosts. It does indeed look like a jobrunner with traffic is needed.

Change 667631 had a related patch set uploaded (by Legoktm; owner: Legoktm):
[operations/puppet@production] install_server: Swtich mw1307 (jobrunner) back to stretch

https://gerrit.wikimedia.org/r/667631

Change 667631 merged by Dzahn:
[operations/puppet@production] install_server: Swtich mw1307 (jobrunner) back to stretch

https://gerrit.wikimedia.org/r/667631

Script wmf-auto-reimage was launched by dzahn on cumin1001.eqiad.wmnet for hosts:

mw1307.eqiad.wmnet

The log can be found in /var/log/wmf-auto-reimage/202103011718_dzahn_13229_mw1307_eqiad_wmnet.log.

Completed auto-reimage of hosts:

['mw1307.eqiad.wmnet']

and were ALL successful.

My suggestion is we re-image one jobrunner to stretch and we check if that changes things dramatically. @Legoktm / @Dzahn can you take care of this?

done! mw1307.eqiad.wmnet is back on stretch and a jobrunner.

@fgiunchedi could you re-run your analysis to see if mw1307 (10.64.0.169) is still exhibiting the issue?

@fgiunchedi could you re-run your analysis to see if mw1307 (10.64.0.169) is still exhibiting the issue?

For sure! Just did on centrallog1001 (bar_chart.py is part of https://github.com/bitly/data_hacks and lives in my home). See below, doesn't look like mw1307 is in the list at 80s threshold

centrallog1001:/srv/syslog$ zcat ms-fe2*/swift.log-20210325.gz  | awk '/proxy-server:.*PUT/ && $21 > 80 {print $6}' | ~/bar_chart.py 
# each โˆŽ represents a count of 1. total 54
 10.64.0.170 [     1] โˆŽ
 10.64.0.171 [     2] โˆŽโˆŽ
 10.64.0.172 [     2] โˆŽโˆŽ
 10.64.0.173 [     5] โˆŽโˆŽโˆŽโˆŽโˆŽ
10.64.16.105 [     5] โˆŽโˆŽโˆŽโˆŽโˆŽ
10.64.16.106 [     3] โˆŽโˆŽโˆŽ
10.64.16.199 [     2] โˆŽโˆŽ
 10.64.16.58 [     3] โˆŽโˆŽโˆŽ
 10.64.16.59 [     2] โˆŽโˆŽ
 10.64.16.60 [     1] โˆŽ
 10.64.16.61 [     1] โˆŽ
 10.64.16.63 [     4] โˆŽโˆŽโˆŽโˆŽ
 10.64.16.65 [     3] โˆŽโˆŽโˆŽ
 10.64.16.66 [     2] โˆŽโˆŽ
 10.64.16.67 [     3] โˆŽโˆŽโˆŽ
 10.64.16.68 [     2] โˆŽโˆŽ
 10.64.16.69 [     2] โˆŽโˆŽ
 10.64.32.36 [     1] โˆŽ
 10.64.32.37 [     3] โˆŽโˆŽโˆŽ
 10.64.32.38 [     3] โˆŽโˆŽโˆŽ
 10.64.32.39 [     2] โˆŽโˆŽ
 10.64.32.53 [     1] โˆŽ
10.64.48.222 [     1] โˆŽ

@fgiunchedi could you re-run your analysis to see if mw1307 (10.64.0.169) is still exhibiting the issue?

For sure! Just did on centrallog1001 (bar_chart.py is part of https://github.com/bitly/data_hacks and lives in my home). See below, doesn't look like mw1307 is in the list at 80s threshold

Thanks, I re-ran it just now and can confirm the same. I note that the overall occurrence of this has shot up a lot, 496 on 2021-04-03, 194 on 2021-04-04, and 168 on 2021-04-05. But I think that could easily be explained by the increased usage of video2commons, which normally results in large uploads.

Another data point, as expected post-switchover the high latency uploads from jobrunners moved from codfw to eqiad since codfw is now active.

Also to avoid confusion I'd like to clarify that on the swift side I can't find anything obviously wrong though I don't have the bandwidth to investigate further on the mw/jobrunner/buster side

Joe raised the priority of this task from Medium to High.Oct 12 2021, 5:28 AM

So, this problem clearly hasn't been solved. We need to isolate where the problem is; the easiest way to test is imho as follows:

  • Temporarily reimage one debug server to stretch; if this is in any way problematic, keep it depooled
  • test cross-dc uploads of a large file from a buster and a stretch server using a simple script in php that makes no use of mediawiki things. Example: https://gist.github.com/etudor/e85689aa88b8436f2803e11ff8b99251
  • If that doesn't show any difference, try uploading the same file using MediaWiki's own code (we'd probably be better off just calling it by hand from shell.php), but skipping all the database parts of it. Just upload the file
  • Finally, if nothing changes there either, the problem must be in php code and we should extract profiling info from test requests.

Raising priority to "high" as this seems like a possible, if unlikely, reason why people can't upload large files anymore.

One thing I think most of us missed is that MediaWiki AFAICT isn't actually uploading any data, it's just sending a X-Copy-From to Swift.

Looking at https://commons.wikimedia.org/wiki/File:A_bibliography_of_North_Carolina,_1589-1956_-_1958.djvu (51MB)

eqiad -> eqiad took 0.6s

2021-10-27 14:58:50 [5b424ea4-cc9e-48d4-be23-f30497ad135f] mw1308 commonswiki 1.38.0-wmf.5 FileOperation DEBUG: HTTP start: PUT https://ms-fe.svc.eqiad.wmnet/v1/AUTH_mw/wikipedia-commons-local-public.ef/e/ef/A_bibliography_of_North_Carolina%2C_1589-1956_-_1958.djvu {"method":"PUT","url":"https://ms-fe.svc.eqiad.wmnet/v1/AUTH_mw/wikipedia-commons-local-public.ef/e/ef/A_bibliography_of_North_Carolina%2C_1589-1956_-_1958.djvu"} 
2021-10-27 14:58:51 [5b424ea4-cc9e-48d4-be23-f30497ad135f] mw1308 commonswiki 1.38.0-wmf.5 FileOperation DEBUG: HTTP complete: PUT https://ms-fe.svc.eqiad.wmnet/v1/AUTH_mw/wikipedia-commons-local-public.ef/e/ef/A_bibliography_of_North_Carolina%2C_1589-1956_-_1958.djvu code=201 size=0 total=0.600838 connect=3.9E-5 {"method":"PUT","url":"https://ms-fe.svc.eqiad.wmnet/v1/AUTH_mw/wikipedia-commons-local-public.ef/e/ef/A_bibliography_of_North_Carolina%2C_1589-1956_-_1958.djvu","response_code":201,"size":0.0,"total_time":"0.600838","connect_time":"3.9E-5"}

eqiad -> codfw took 25s

2021-10-27 14:58:52 [5b424ea4-cc9e-48d4-be23-f30497ad135f] mw1308 commonswiki 1.38.0-wmf.5 FileOperation DEBUG: HTTP start: PUT https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-commons-local-public.ef/e/ef/A_bibliography_of_North_Carolina%2C_1589-1956_-_1958.djvu {"method":"PUT","url":"https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-commons-local-public.ef/e/ef/A_bibliography_of_North_Carolina%2C_1589-1956_-_1958.djvu"} 
2021-10-27 14:59:17 [5b424ea4-cc9e-48d4-be23-f30497ad135f] mw1308 commonswiki 1.38.0-wmf.5 FileOperation DEBUG: HTTP complete: PUT https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-commons-local-public.ef/e/ef/A_bibliography_of_North_Carolina%2C_1589-1956_-_1958.djvu code=201 size=0 total=25.100911 connect=4.0E-5 {"method":"PUT","url":"https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-commons-local-public.ef/e/ef/A_bibliography_of_North_Carolina%2C_1589-1956_-_1958.djvu","response_code":201,"size":0.0,"total_time":"25.100911","connect_time":"4.0E-5"}

(note: we should probably log headers here)

Scratch that, the requests that are slow are not using X-Copy-From:

2021-10-28 20:45:41 [fc3a0714-35c2-4cbc-8999-ad4c24bc17b4] mw1439 testwiki 1.38.0-wmf.6 FileOperation DEBUG: HTTP start: PUT https://ms-fe.svc.eqiad.wmnet/v1/AUTH_mw/wikipedia-test-local-public/3/36/Legoktm_test_1.djvu {"method":"PUT","url":"https://ms-fe.svc.eqiad.wmnet/v1/AUTH_mw/wikipedia-test-local-public/3/36/Legoktm_test_1.djvu","headers":{"x-content-dimensions":"","content-type":"image/vnd.djvu","content-length":53798301,"etag":"069fc83e88bc112f309f2548c386853c","x-object-meta-sha1base36":"56e0liu04c2u9avcrvlz7m5k4nh6gxf"}} 
2021-10-28 20:45:42 [fc3a0714-35c2-4cbc-8999-ad4c24bc17b4] mw1439 testwiki 1.38.0-wmf.6 FileOperation DEBUG: HTTP complete: PUT https://ms-fe.svc.eqiad.wmnet/v1/AUTH_mw/wikipedia-test-local-public/3/36/Legoktm_test_1.djvu code=201 size=0 total=0.613292 connect=6.7E-5 {"method":"PUT","url":"https://ms-fe.svc.eqiad.wmnet/v1/AUTH_mw/wikipedia-test-local-public/3/36/Legoktm_test_1.djvu","response_code":201,"size":0.0,"total_time":"0.613292","connect_time":"6.7E-5"} 
...
2021-10-28 20:45:42 [fc3a0714-35c2-4cbc-8999-ad4c24bc17b4] mw1439 testwiki 1.38.0-wmf.6 FileOperation DEBUG: HTTP start: PUT https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-test-local-public/3/36/Legoktm_test_1.djvu {"method":"PUT","url":"https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-test-local-public/3/36/Legoktm_test_1.djvu","headers":{"x-content-dimensions":"","content-type":"image/vnd.djvu","content-length":53798301,"etag":"069fc83e88bc112f309f2548c386853c","x-object-meta-sha1base36":"56e0liu04c2u9avcrvlz7m5k4nh6gxf"}} 
2021-10-28 20:46:10 [fc3a0714-35c2-4cbc-8999-ad4c24bc17b4] mw1439 testwiki 1.38.0-wmf.6 FileOperation DEBUG: HTTP complete: PUT https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-test-local-public/3/36/Legoktm_test_1.djvu code=201 size=0 total=27.750302 connect=4.0E-5 {"method":"PUT","url":"https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-test-local-public/3/36/Legoktm_test_1.djvu","response_code":201,"size":0.0,"total_time":"27.750302","connect_time":"4.0E-5"}

I think I narrowed it down. If I upload using plain CLI curl, it finishes instantaneously:

1legoktm@mw1305:~$ time curl -v -X PUT --data-binary @legoktm_test_T275752.djvu -H 'x-content-dimensions:' -H 'content-type: image/vnd.djvu' -H 'x-auth-token: [redacted]' -H 'etag: 069fc83e88bc112f309f2548c386853c' -H 'x-object-meta-sha1base36: 56e0liu04c2u9avcrvlz7m5k4nh6gxf' --http1.0 https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-test-local-temp/legoktm_test_T275752_2.djvu
2* Expire in 0 ms for 6 (transfer 0x5650c5041fb0)
3* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
4* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
5* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
6* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
7* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
8* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
9* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
10* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
11* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
12* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
13* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
14* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
15* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
16* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
17* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
18* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
19* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
20* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
21* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
22* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
23* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
24* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
25* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
26* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
27* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
28* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
29* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
30* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
31* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
32* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
33* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
34* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
35* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
36* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
37* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
38* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
39* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
40* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
41* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
42* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
43* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
44* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
45* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
46* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
47* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
48* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
49* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
50* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
51* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
52* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
53* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
54* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
55* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
56* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
57* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
58* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
59* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
60* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
61* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
62* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
63* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
64* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
65* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
66* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
67* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
68* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
69* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
70* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
71* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
72* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
73* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
74* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
75* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
76* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
77* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
78* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
79* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
80* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
81* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
82* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
83* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
84* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
85* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
86* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
87* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
88* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
89* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
90* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
91* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
92* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
93* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
94* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
95* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
96* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
97* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
98* Expire in 1 ms for 1 (transfer 0x5650c5041fb0)
99* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
100* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
101* Expire in 2 ms for 1 (transfer 0x5650c5041fb0)
102* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
103* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
104* Expire in 2 ms for 1 (transfer 0x5650c5041fb0)
105* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
106* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
107* Expire in 2 ms for 1 (transfer 0x5650c5041fb0)
108* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
109* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
110* Expire in 2 ms for 1 (transfer 0x5650c5041fb0)
111* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
112* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
113* Expire in 2 ms for 1 (transfer 0x5650c5041fb0)
114* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
115* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
116* Expire in 2 ms for 1 (transfer 0x5650c5041fb0)
117* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
118* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
119* Expire in 2 ms for 1 (transfer 0x5650c5041fb0)
120* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
121* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
122* Expire in 2 ms for 1 (transfer 0x5650c5041fb0)
123* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
124* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
125* Expire in 0 ms for 1 (transfer 0x5650c5041fb0)
126* Trying 10.2.1.27...
127* TCP_NODELAY set
128* Expire in 200 ms for 4 (transfer 0x5650c5041fb0)
129* Connected to ms-fe.svc.codfw.wmnet (10.2.1.27) port 443 (#0)
130* ALPN, offering http/1.1
131* successfully set certificate verify locations:
132* CAfile: none
133 CApath: /etc/ssl/certs
134* TLSv1.3 (OUT), TLS handshake, Client hello (1):
135* TLSv1.3 (IN), TLS handshake, Server hello (2):
136* TLSv1.2 (IN), TLS handshake, Certificate (11):
137* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
138* TLSv1.2 (IN), TLS handshake, Server finished (14):
139* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
140* TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
141* TLSv1.2 (OUT), TLS handshake, Finished (20):
142* TLSv1.2 (IN), TLS handshake, Finished (20):
143* SSL connection using TLSv1.2 / ECDHE-ECDSA-CHACHA20-POLY1305
144* ALPN, server accepted to use http/1.1
145* Server certificate:
146* subject: CN=swift_codfw
147* start date: Apr 15 13:31:23 2019 GMT
148* expire date: Apr 14 13:31:23 2024 GMT
149* subjectAltName: host "ms-fe.svc.codfw.wmnet" matched cert's "ms-fe.svc.codfw.wmnet"
150* issuer: CN=Puppet CA: palladium.eqiad.wmnet
151* SSL certificate verify ok.
152> PUT /v1/AUTH_mw/wikipedia-test-local-temp/legoktm_test_T275752_2.djvu HTTP/1.0
153> Host: ms-fe.svc.codfw.wmnet
154> User-Agent: curl/7.64.0
155> Accept: */*
156> content-type: image/vnd.djvu
157> x-auth-token: [redacted]
158> etag: 069fc83e88bc112f309f2548c386853c
159> x-object-meta-sha1base36: 56e0liu04c2u9avcrvlz7m5k4nh6gxf
160> Content-Length: 53798301
161>
162* We are completely uploaded and fine
163< HTTP/1.1 201 Created
164< Date: Fri, 29 Oct 2021 04:55:35 GMT
165< Content-Type: text/html; charset=UTF-8
166< Content-Length: 0
167< Connection: close
168< Last-Modified: Fri, 29 Oct 2021 04:55:35 GMT
169< Etag: 069fc83e88bc112f309f2548c386853c
170< X-Trans-Id: txd7ee81b7e16c4fb79cc03-00617b7ec6
171<
172* Closing connection 0
173
174real 0m0.933s
175user 0m0.119s
176sys 0m0.087s
.

Now when I use a stripped down version of SwiftFileBackend/MultiHttpClient, I get:

1legoktm@mw1305:~$ time php test.php legoktm_test_T275752.djvu
2array(2) {
3 [0]=>
4 string(8) "test.php"
5 [1]=>
6 string(25) "legoktm_test_T275752.djvu"
7}
8Uploading to https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-test-local-temp/legoktm_test_T275752.djvu
9array(7) {
10 [0]=>
11 string(28) "content-type: image/vnd.djvu"
12 [1]=>
13 string(24) "content-length: 53798301"
14 [2]=>
15 string(38) "etag: 069fc83e88bc112f309f2548c386853c"
16 [3]=>
17 string(53) "x-auth-token: [redacted]"
18 [4]=>
19 string(57) "x-object-meta-sha1base36: 56e0liu04c2u9avcrvlz7m5k4nh6gxf"
20 [5]=>
21 string(22) "x-content-dimensions: "
22 [6]=>
23 string(19) "user-agent: legoktm"
24}
251635483013 curl_exec()
26* Expire in 0 ms for 6 (transfer 0x55a49aa773c0)
27* Expire in 30000 ms for 8 (transfer 0x55a49aa773c0)
28* Expire in 10000 ms for 2 (transfer 0x55a49aa773c0)
29* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
30* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
31* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
32* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
33* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
34* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
35* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
36* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
37* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
38* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
39* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
40* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
41* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
42* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
43* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
44* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
45* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
46* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
47* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
48* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
49* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
50* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
51* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
52* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
53* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
54* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
55* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
56* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
57* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
58* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
59* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
60* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
61* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
62* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
63* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
64* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
65* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
66* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
67* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
68* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
69* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
70* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
71* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
72* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
73* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
74* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
75* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
76* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
77* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
78* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
79* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
80* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
81* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
82* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
83* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
84* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
85* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
86* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
87* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
88* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
89* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
90* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
91* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
92* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
93* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
94* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
95* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
96* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
97* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
98* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
99* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
100* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
101* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
102* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
103* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
104* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
105* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
106* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
107* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
108* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
109* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
110* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
111* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
112* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
113* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
114* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
115* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
116* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
117* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
118* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
119* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
120* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
121* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
122* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
123* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
124* Expire in 1 ms for 1 (transfer 0x55a49aa773c0)
125* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
126* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
127* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
128* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
129* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
130* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
131* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
132* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
133* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
134* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
135* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
136* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
137* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
138* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
139* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
140* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
141* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
142* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
143* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
144* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
145* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
146* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
147* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
148* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
149* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
150* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
151* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
152* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
153* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
154* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
155* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
156* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
157* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
158* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
159* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
160* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
161* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
162* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
163* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
164* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
165* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
166* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
167* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
168* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
169* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
170* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
171* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
172* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
173* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
174* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
175* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
176* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
177* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
178* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
179* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
180* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
181* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
182* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
183* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
184* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
185* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
186* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
187* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
188* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
189* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
190* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
191* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
192* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
193* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
194* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
195* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
196* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
197* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
198* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
199* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
200* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
201* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
202* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
203* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
204* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
205* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
206* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
207* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
208* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
209* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
210* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
211* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
212* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
213* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
214* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
215* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
216* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
217* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
218* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
219* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
220* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
221* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
222* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
223* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
224* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
225* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
226* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
227* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
228* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
229* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
230* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
231* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
232* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
233* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
234* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
235* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
236* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
237* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
238* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
239* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
240* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
241* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
242* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
243* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
244* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
245* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
246* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
247* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
248* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
249* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
250* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
251* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
252* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
253* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
254* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
255* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
256* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
257* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
258* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
259* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
260* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
261* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
262* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
263* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
264* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
265* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
266* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
267* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
268* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
269* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
270* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
271* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
272* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
273* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
274* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
275* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
276* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
277* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
278* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
279* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
280* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
281* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
282* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
283* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
284* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
285* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
286* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
287* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
288* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
289* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
290* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
291* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
292* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
293* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
294* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
295* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
296* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
297* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
298* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
299* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
300* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
301* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
302* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
303* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
304* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
305* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
306* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
307* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
308* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
309* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
310* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
311* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
312* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
313* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
314* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
315* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
316* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
317* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
318* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
319* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
320* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
321* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
322* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
323* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
324* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
325* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
326* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
327* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
328* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
329* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
330* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
331* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
332* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
333* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
334* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
335* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
336* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
337* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
338* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
339* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
340* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
341* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
342* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
343* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
344* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
345* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
346* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
347* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
348* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
349* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
350* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
351* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
352* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
353* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
354* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
355* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
356* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
357* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
358* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
359* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
360* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
361* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
362* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
363* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
364* Expire in 2 ms for 1 (transfer 0x55a49aa773c0)
365* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
366* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
367* Expire in 0 ms for 1 (transfer 0x55a49aa773c0)
368* Trying 10.2.1.27...
369* TCP_NODELAY set
370* Expire in 200 ms for 4 (transfer 0x55a49aa773c0)
371* Connected to ms-fe.svc.codfw.wmnet (10.2.1.27) port 443 (#0)
372* ALPN, offering h2
373* ALPN, offering http/1.1
374* successfully set certificate verify locations:
375* CAfile: none
376 CApath: /etc/ssl/certs
377* SSL connection using TLSv1.2 / ECDHE-ECDSA-CHACHA20-POLY1305
378* ALPN, server accepted to use h2
379* Server certificate:
380* subject: CN=swift_codfw
381* start date: Apr 15 13:31:23 2019 GMT
382* expire date: Apr 14 13:31:23 2024 GMT
383* subjectAltName: host "ms-fe.svc.codfw.wmnet" matched cert's "ms-fe.svc.codfw.wmnet"
384* issuer: CN=Puppet CA: palladium.eqiad.wmnet
385* SSL certificate verify ok.
386* Using HTTP2, server supports multi-use
387* Connection state changed (HTTP/2 confirmed)
388* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
389* Using Stream ID: 1 (easy handle 0x55a49aa773c0)
390> PUT /v1/AUTH_mw/wikipedia-test-local-temp/legoktm_test_T275752.djvu HTTP/2
391Host: ms-fe.svc.codfw.wmnet
392Accept: */*
393content-type: image/vnd.djvu
394content-length: 53798301
395etag: 069fc83e88bc112f309f2548c386853c
396x-auth-token: [redacted]
397x-object-meta-sha1base36: 56e0liu04c2u9avcrvlz7m5k4nh6gxf
398user-agent: legoktm
399
400* Connection state changed (MAX_CONCURRENT_STREAMS == 128)!
4011635483013 fread(...65536)
4021635483014 fread(...65536)
4031635483014 fread(...65536)
4041635483014 fread(...65536)
4051635483014 fread(...65536)
4061635483014 fread(...65536)
4071635483014 fread(...65536)
4081635483014 fread(...65536)
4091635483014 fread(...65536)
4101635483014 fread(...65536)
4111635483014 fread(...65536)
4121635483014 fread(...65536)
4131635483014 fread(...65536)
4141635483014 fread(...65536)
4151635483014 fread(...65536)
4161635483014 fread(...65536)
4171635483014 fread(...65536)
4181635483014 fread(...65536)
4191635483014 fread(...65536)
4201635483014 fread(...65536)
4211635483014 fread(...65536)
4221635483014 fread(...65536)
4231635483014 fread(...65536)
4241635483014 fread(...65536)
4251635483014 fread(...65536)
4261635483014 fread(...65536)
4271635483014 fread(...65536)
4281635483014 fread(...65536)
4291635483014 fread(...65536)
4301635483014 fread(...65536)
4311635483014 fread(...65536)
4321635483015 fread(...65536)
4331635483015 fread(...65536)
4341635483015 fread(...65536)
4351635483015 fread(...65536)
4361635483015 fread(...65536)
4371635483015 fread(...65536)
4381635483015 fread(...65536)
4391635483015 fread(...65536)
4401635483015 fread(...65536)
4411635483015 fread(...65536)
4421635483015 fread(...65536)
4431635483015 fread(...65536)
4441635483015 fread(...65536)
4451635483015 fread(...65536)
4461635483015 fread(...65536)
4471635483015 fread(...65536)
4481635483015 fread(...65536)
4491635483015 fread(...65536)
4501635483015 fread(...65536)
4511635483015 fread(...65536)
4521635483015 fread(...65536)
4531635483015 fread(...65536)
4541635483015 fread(...65536)
4551635483015 fread(...65536)
4561635483015 fread(...65536)
4571635483015 fread(...65536)
4581635483015 fread(...65536)
4591635483015 fread(...65536)
4601635483015 fread(...65536)
4611635483015 fread(...65536)
4621635483015 fread(...65536)
4631635483016 fread(...65536)
4641635483016 fread(...65536)
4651635483016 fread(...65536)
4661635483016 fread(...65536)
4671635483016 fread(...65536)
4681635483016 fread(...65536)
4691635483016 fread(...65536)
4701635483016 fread(...65536)
4711635483016 fread(...65536)
4721635483016 fread(...65536)
4731635483016 fread(...65536)
4741635483016 fread(...65536)
4751635483016 fread(...65536)
4761635483016 fread(...65536)
4771635483016 fread(...65536)
4781635483016 fread(...65536)
4791635483016 fread(...65536)
4801635483016 fread(...65536)
4811635483016 fread(...65536)
4821635483016 fread(...65536)
4831635483016 fread(...65536)
4841635483016 fread(...65536)
4851635483016 fread(...65536)
4861635483016 fread(...65536)
4871635483016 fread(...65536)
4881635483016 fread(...65536)
4891635483016 fread(...65536)
4901635483016 fread(...65536)
4911635483016 fread(...65536)
4921635483016 fread(...65536)
4931635483016 fread(...65536)
4941635483017 fread(...65536)
4951635483017 fread(...65536)
4961635483017 fread(...65536)
4971635483017 fread(...65536)
4981635483017 fread(...65536)
4991635483017 fread(...65536)
5001635483017 fread(...65536)
5011635483017 fread(...65536)
5021635483017 fread(...65536)
5031635483017 fread(...65536)
5041635483017 fread(...65536)
5051635483017 fread(...65536)
5061635483017 fread(...65536)
5071635483017 fread(...65536)
5081635483017 fread(...65536)
5091635483017 fread(...65536)
5101635483017 fread(...65536)
5111635483017 fread(...65536)
5121635483017 fread(...65536)
5131635483017 fread(...65536)
5141635483017 fread(...65536)
5151635483017 fread(...65536)
5161635483017 fread(...65536)
5171635483017 fread(...65536)
5181635483017 fread(...65536)
5191635483017 fread(...65536)
5201635483017 fread(...65536)
5211635483017 fread(...65536)
5221635483017 fread(...65536)
5231635483017 fread(...65536)
5241635483017 fread(...65536)
5251635483017 fread(...65536)
5261635483018 fread(...65536)
5271635483018 fread(...65536)
5281635483018 fread(...65536)
5291635483018 fread(...65536)
5301635483018 fread(...65536)
5311635483018 fread(...65536)
5321635483018 fread(...65536)
5331635483018 fread(...65536)
5341635483018 fread(...65536)
5351635483018 fread(...65536)
5361635483018 fread(...65536)
5371635483018 fread(...65536)
5381635483018 fread(...65536)
5391635483018 fread(...65536)
5401635483018 fread(...65536)
5411635483018 fread(...65536)
5421635483018 fread(...65536)
5431635483018 fread(...65536)
5441635483018 fread(...65536)
5451635483018 fread(...65536)
5461635483018 fread(...65536)
5471635483018 fread(...65536)
5481635483018 fread(...65536)
5491635483018 fread(...65536)
5501635483018 fread(...65536)
5511635483018 fread(...65536)
5521635483018 fread(...65536)
5531635483018 fread(...65536)
5541635483018 fread(...65536)
5551635483018 fread(...65536)
5561635483018 fread(...65536)
5571635483019 fread(...65536)
5581635483019 fread(...65536)
5591635483019 fread(...65536)
5601635483019 fread(...65536)
5611635483019 fread(...65536)
5621635483019 fread(...65536)
5631635483019 fread(...65536)
5641635483019 fread(...65536)
5651635483019 fread(...65536)
5661635483019 fread(...65536)
5671635483019 fread(...65536)
5681635483019 fread(...65536)
5691635483019 fread(...65536)
5701635483019 fread(...65536)
5711635483019 fread(...65536)
5721635483019 fread(...65536)
5731635483019 fread(...65536)
5741635483019 fread(...65536)
5751635483019 fread(...65536)
5761635483019 fread(...65536)
5771635483019 fread(...65536)
5781635483019 fread(...65536)
5791635483019 fread(...65536)
5801635483019 fread(...65536)
5811635483019 fread(...65536)
5821635483019 fread(...65536)
5831635483019 fread(...65536)
5841635483019 fread(...65536)
5851635483019 fread(...65536)
5861635483019 fread(...65536)
5871635483019 fread(...65536)
5881635483020 fread(...65536)
5891635483020 fread(...65536)
5901635483020 fread(...65536)
5911635483020 fread(...65536)
5921635483020 fread(...65536)
5931635483020 fread(...65536)
5941635483020 fread(...65536)
5951635483020 fread(...65536)
5961635483020 fread(...65536)
5971635483020 fread(...65536)
5981635483020 fread(...65536)
5991635483020 fread(...65536)
6001635483020 fread(...65536)
6011635483020 fread(...65536)
6021635483020 fread(...65536)
6031635483020 fread(...65536)
6041635483020 fread(...65536)
6051635483020 fread(...65536)
6061635483020 fread(...65536)
6071635483020 fread(...65536)
6081635483020 fread(...65536)
6091635483020 fread(...65536)
6101635483020 fread(...65536)
6111635483020 fread(...65536)
6121635483020 fread(...65536)
6131635483020 fread(...65536)
6141635483020 fread(...65536)
6151635483020 fread(...65536)
6161635483020 fread(...65536)
6171635483020 fread(...65536)
6181635483020 fread(...65536)
6191635483020 fread(...65536)
6201635483021 fread(...65536)
6211635483021 fread(...65536)
6221635483021 fread(...65536)
6231635483021 fread(...65536)
6241635483021 fread(...65536)
6251635483021 fread(...65536)
6261635483021 fread(...65536)
6271635483021 fread(...65536)
6281635483021 fread(...65536)
6291635483021 fread(...65536)
6301635483021 fread(...65536)
6311635483021 fread(...65536)
6321635483021 fread(...65536)
6331635483021 fread(...65536)
6341635483021 fread(...65536)
6351635483021 fread(...65536)
6361635483021 fread(...65536)
6371635483021 fread(...65536)
6381635483021 fread(...65536)
6391635483021 fread(...65536)
6401635483021 fread(...65536)
6411635483021 fread(...65536)
6421635483021 fread(...65536)
6431635483021 fread(...65536)
6441635483021 fread(...65536)
6451635483021 fread(...65536)
6461635483021 fread(...65536)
6471635483021 fread(...65536)
6481635483021 fread(...65536)
6491635483021 fread(...65536)
6501635483021 fread(...65536)
6511635483022 fread(...65536)
6521635483022 fread(...65536)
6531635483022 fread(...65536)
6541635483022 fread(...65536)
6551635483022 fread(...65536)
6561635483022 fread(...65536)
6571635483022 fread(...65536)
6581635483022 fread(...65536)
6591635483022 fread(...65536)
6601635483022 fread(...65536)
6611635483022 fread(...65536)
6621635483022 fread(...65536)
6631635483022 fread(...65536)
6641635483022 fread(...65536)
6651635483022 fread(...65536)
6661635483022 fread(...65536)
6671635483022 fread(...65536)
6681635483022 fread(...65536)
6691635483022 fread(...65536)
6701635483022 fread(...65536)
6711635483022 fread(...65536)
6721635483022 fread(...65536)
6731635483022 fread(...65536)
6741635483022 fread(...65536)
6751635483022 fread(...65536)
6761635483022 fread(...65536)
6771635483022 fread(...65536)
6781635483022 fread(...65536)
6791635483022 fread(...65536)
6801635483022 fread(...65536)
6811635483022 fread(...65536)
6821635483023 fread(...65536)
6831635483023 fread(...65536)
6841635483023 fread(...65536)
6851635483023 fread(...65536)
6861635483023 fread(...65536)
6871635483023 fread(...65536)
6881635483023 fread(...65536)
6891635483023 fread(...65536)
6901635483023 fread(...65536)
6911635483023 fread(...65536)
6921635483023 fread(...65536)
6931635483023 fread(...65536)
6941635483023 fread(...65536)
6951635483023 fread(...65536)
6961635483023 fread(...65536)
6971635483023 fread(...65536)
6981635483023 fread(...65536)
6991635483023 fread(...65536)
7001635483023 fread(...65536)
7011635483023 fread(...65536)
7021635483023 fread(...65536)
7031635483023 fread(...65536)
7041635483023 fread(...65536)
7051635483023 fread(...65536)
7061635483023 fread(...65536)
7071635483023 fread(...65536)
7081635483023 fread(...65536)
7091635483023 fread(...65536)
7101635483023 fread(...65536)
7111635483023 fread(...65536)
7121635483023 fread(...65536)
7131635483024 fread(...65536)
7141635483024 fread(...65536)
7151635483024 fread(...65536)
7161635483024 fread(...65536)
7171635483024 fread(...65536)
7181635483024 fread(...65536)
7191635483024 fread(...65536)
7201635483024 fread(...65536)
7211635483024 fread(...65536)
7221635483024 fread(...65536)
7231635483024 fread(...65536)
7241635483024 fread(...65536)
7251635483024 fread(...65536)
7261635483024 fread(...65536)
7271635483024 fread(...65536)
7281635483024 fread(...65536)
7291635483024 fread(...65536)
7301635483024 fread(...65536)
7311635483024 fread(...65536)
7321635483024 fread(...65536)
7331635483024 fread(...65536)
7341635483024 fread(...65536)
7351635483024 fread(...65536)
7361635483024 fread(...65536)
7371635483024 fread(...65536)
7381635483024 fread(...65536)
7391635483024 fread(...65536)
7401635483024 fread(...65536)
7411635483024 fread(...65536)
7421635483024 fread(...65536)
7431635483024 fread(...65536)
7441635483024 fread(...65536)
7451635483025 fread(...65536)
7461635483025 fread(...65536)
7471635483025 fread(...65536)
7481635483025 fread(...65536)
7491635483025 fread(...65536)
7501635483025 fread(...65536)
7511635483025 fread(...65536)
7521635483025 fread(...65536)
7531635483025 fread(...65536)
7541635483025 fread(...65536)
7551635483025 fread(...65536)
7561635483025 fread(...65536)
7571635483025 fread(...65536)
7581635483025 fread(...65536)
7591635483025 fread(...65536)
7601635483025 fread(...65536)
7611635483025 fread(...65536)
7621635483025 fread(...65536)
7631635483025 fread(...65536)
7641635483025 fread(...65536)
7651635483025 fread(...65536)
7661635483025 fread(...65536)
7671635483025 fread(...65536)
7681635483025 fread(...65536)
7691635483025 fread(...65536)
7701635483025 fread(...65536)
7711635483025 fread(...65536)
7721635483025 fread(...65536)
7731635483025 fread(...65536)
7741635483025 fread(...65536)
7751635483025 fread(...65536)
7761635483026 fread(...65536)
7771635483026 fread(...65536)
7781635483026 fread(...65536)
7791635483026 fread(...65536)
7801635483026 fread(...65536)
7811635483026 fread(...65536)
7821635483026 fread(...65536)
7831635483026 fread(...65536)
7841635483026 fread(...65536)
7851635483026 fread(...65536)
7861635483026 fread(...65536)
7871635483026 fread(...65536)
7881635483026 fread(...65536)
7891635483026 fread(...65536)
7901635483026 fread(...65536)
7911635483026 fread(...65536)
7921635483026 fread(...65536)
7931635483026 fread(...65536)
7941635483026 fread(...65536)
7951635483026 fread(...65536)
7961635483026 fread(...65536)
7971635483026 fread(...65536)
7981635483026 fread(...65536)
7991635483026 fread(...65536)
8001635483026 fread(...65536)
8011635483026 fread(...65536)
8021635483026 fread(...65536)
8031635483026 fread(...65536)
8041635483026 fread(...65536)
8051635483026 fread(...65536)
8061635483026 fread(...65536)
8071635483027 fread(...65536)
8081635483027 fread(...65536)
8091635483027 fread(...65536)
8101635483027 fread(...65536)
8111635483027 fread(...65536)
8121635483027 fread(...65536)
8131635483027 fread(...65536)
8141635483027 fread(...65536)
8151635483027 fread(...65536)
8161635483027 fread(...65536)
8171635483027 fread(...65536)
8181635483027 fread(...65536)
8191635483027 fread(...65536)
8201635483027 fread(...65536)
8211635483027 fread(...65536)
8221635483027 fread(...65536)
8231635483027 fread(...65536)
8241635483027 fread(...65536)
8251635483027 fread(...65536)
8261635483027 fread(...65536)
8271635483027 fread(...65536)
8281635483027 fread(...65536)
8291635483027 fread(...65536)
8301635483027 fread(...65536)
8311635483027 fread(...65536)
8321635483027 fread(...65536)
8331635483027 fread(...65536)
8341635483027 fread(...65536)
8351635483027 fread(...65536)
8361635483027 fread(...65536)
8371635483027 fread(...65536)
8381635483027 fread(...65536)
8391635483028 fread(...65536)
8401635483028 fread(...65536)
8411635483028 fread(...65536)
8421635483028 fread(...65536)
8431635483028 fread(...65536)
8441635483028 fread(...65536)
8451635483028 fread(...65536)
8461635483028 fread(...65536)
8471635483028 fread(...65536)
8481635483028 fread(...65536)
8491635483028 fread(...65536)
8501635483028 fread(...65536)
8511635483028 fread(...65536)
8521635483028 fread(...65536)
8531635483028 fread(...65536)
8541635483028 fread(...65536)
8551635483028 fread(...65536)
8561635483028 fread(...65536)
8571635483028 fread(...65536)
8581635483028 fread(...65536)
8591635483028 fread(...65536)
8601635483028 fread(...65536)
8611635483028 fread(...65536)
8621635483028 fread(...65536)
8631635483028 fread(...65536)
8641635483028 fread(...65536)
8651635483028 fread(...65536)
8661635483028 fread(...65536)
8671635483028 fread(...65536)
8681635483028 fread(...65536)
8691635483028 fread(...65536)
8701635483029 fread(...65536)
8711635483029 fread(...65536)
8721635483029 fread(...65536)
8731635483029 fread(...65536)
8741635483029 fread(...65536)
8751635483029 fread(...65536)
8761635483029 fread(...65536)
8771635483029 fread(...65536)
8781635483029 fread(...65536)
8791635483029 fread(...65536)
8801635483029 fread(...65536)
8811635483029 fread(...65536)
8821635483029 fread(...65536)
8831635483029 fread(...65536)
8841635483029 fread(...65536)
8851635483029 fread(...65536)
8861635483029 fread(...65536)
8871635483029 fread(...65536)
8881635483029 fread(...65536)
8891635483029 fread(...65536)
8901635483029 fread(...65536)
8911635483029 fread(...65536)
8921635483029 fread(...65536)
8931635483029 fread(...65536)
8941635483029 fread(...65536)
8951635483029 fread(...65536)
8961635483029 fread(...65536)
8971635483029 fread(...65536)
8981635483029 fread(...65536)
8991635483029 fread(...65536)
9001635483029 fread(...65536)
9011635483030 fread(...65536)
9021635483030 fread(...65536)
9031635483030 fread(...65536)
9041635483030 fread(...65536)
9051635483030 fread(...65536)
9061635483030 fread(...65536)
9071635483030 fread(...65536)
9081635483030 fread(...65536)
9091635483030 fread(...65536)
9101635483030 fread(...65536)
9111635483030 fread(...65536)
9121635483030 fread(...65536)
9131635483030 fread(...65536)
9141635483030 fread(...65536)
9151635483030 fread(...65536)
9161635483030 fread(...65536)
9171635483030 fread(...65536)
9181635483030 fread(...65536)
9191635483030 fread(...65536)
9201635483030 fread(...65536)
9211635483030 fread(...65536)
9221635483030 fread(...65536)
9231635483030 fread(...65536)
9241635483030 fread(...65536)
9251635483030 fread(...65536)
9261635483030 fread(...65536)
9271635483030 fread(...65536)
9281635483030 fread(...65536)
9291635483030 fread(...65536)
9301635483030 fread(...65536)
9311635483030 fread(...65536)
9321635483031 fread(...65536)
9331635483031 fread(...65536)
9341635483031 fread(...65536)
9351635483031 fread(...65536)
9361635483031 fread(...65536)
9371635483031 fread(...65536)
9381635483031 fread(...65536)
9391635483031 fread(...65536)
9401635483031 fread(...65536)
9411635483031 fread(...65536)
9421635483031 fread(...65536)
9431635483031 fread(...65536)
9441635483031 fread(...65536)
9451635483031 fread(...65536)
9461635483031 fread(...65536)
9471635483031 fread(...65536)
9481635483031 fread(...65536)
9491635483031 fread(...65536)
9501635483031 fread(...65536)
9511635483031 fread(...65536)
9521635483031 fread(...65536)
9531635483031 fread(...65536)
9541635483031 fread(...65536)
9551635483031 fread(...65536)
9561635483031 fread(...65536)
9571635483031 fread(...65536)
9581635483031 fread(...65536)
9591635483031 fread(...65536)
9601635483031 fread(...65536)
9611635483031 fread(...65536)
9621635483031 fread(...65536)
9631635483031 fread(...65536)
9641635483032 fread(...65536)
9651635483032 fread(...65536)
9661635483032 fread(...65536)
9671635483032 fread(...65536)
9681635483032 fread(...65536)
9691635483032 fread(...65536)
9701635483032 fread(...65536)
9711635483032 fread(...65536)
9721635483032 fread(...65536)
9731635483032 fread(...65536)
9741635483032 fread(...65536)
9751635483032 fread(...65536)
9761635483032 fread(...65536)
9771635483032 fread(...65536)
9781635483032 fread(...65536)
9791635483032 fread(...65536)
9801635483032 fread(...65536)
9811635483032 fread(...65536)
9821635483032 fread(...65536)
9831635483032 fread(...65536)
9841635483032 fread(...65536)
9851635483032 fread(...65536)
9861635483032 fread(...65536)
9871635483032 fread(...65536)
9881635483032 fread(...65536)
9891635483032 fread(...65536)
9901635483032 fread(...65536)
9911635483032 fread(...65536)
9921635483032 fread(...65536)
9931635483032 fread(...65536)
9941635483032 fread(...65536)
9951635483033 fread(...65536)
9961635483033 fread(...65536)
9971635483033 fread(...65536)
9981635483033 fread(...65536)
9991635483033 fread(...65536)
10001635483033 fread(...65536)
10011635483033 fread(...65536)
10021635483033 fread(...65536)
10031635483033 fread(...65536)
10041635483033 fread(...65536)
10051635483033 fread(...65536)
10061635483033 fread(...65536)
10071635483033 fread(...65536)
10081635483033 fread(...65536)
10091635483033 fread(...65536)
10101635483033 fread(...65536)
10111635483033 fread(...65536)
10121635483033 fread(...65536)
10131635483033 fread(...65536)
10141635483033 fread(...65536)
10151635483033 fread(...65536)
10161635483033 fread(...65536)
10171635483033 fread(...65536)
10181635483033 fread(...65536)
10191635483033 fread(...65536)
10201635483033 fread(...65536)
10211635483033 fread(...65536)
10221635483033 fread(...65536)
10231635483033 fread(...65536)
10241635483033 fread(...65536)
10251635483033 fread(...65536)
10261635483034 fread(...65536)
10271635483034 fread(...65536)
10281635483034 fread(...65536)
10291635483034 fread(...65536)
10301635483034 fread(...65536)
10311635483034 fread(...65536)
10321635483034 fread(...65536)
10331635483034 fread(...65536)
10341635483034 fread(...65536)
10351635483034 fread(...65536)
10361635483034 fread(...65536)
10371635483034 fread(...65536)
10381635483034 fread(...65536)
10391635483034 fread(...65536)
10401635483034 fread(...65536)
10411635483034 fread(...65536)
10421635483034 fread(...65536)
10431635483034 fread(...65536)
10441635483034 fread(...65536)
10451635483034 fread(...65536)
10461635483034 fread(...65536)
10471635483034 fread(...65536)
10481635483034 fread(...65536)
10491635483034 fread(...65536)
10501635483034 fread(...65536)
10511635483034 fread(...65536)
10521635483034 fread(...65536)
10531635483034 fread(...65536)
10541635483034 fread(...65536)
10551635483034 fread(...65536)
10561635483034 fread(...65536)
10571635483034 fread(...65536)
10581635483035 fread(...65536)
10591635483035 fread(...65536)
10601635483035 fread(...65536)
10611635483035 fread(...65536)
10621635483035 fread(...65536)
10631635483035 fread(...65536)
10641635483035 fread(...65536)
10651635483035 fread(...65536)
10661635483035 fread(...65536)
10671635483035 fread(...65536)
10681635483035 fread(...65536)
10691635483035 fread(...65536)
10701635483035 fread(...65536)
10711635483035 fread(...65536)
10721635483035 fread(...65536)
10731635483035 fread(...65536)
10741635483035 fread(...65536)
10751635483035 fread(...65536)
10761635483035 fread(...65536)
10771635483035 fread(...65536)
10781635483035 fread(...65536)
10791635483035 fread(...65536)
10801635483035 fread(...65536)
10811635483035 fread(...65536)
10821635483035 fread(...65536)
10831635483035 fread(...65536)
10841635483035 fread(...65536)
10851635483035 fread(...65536)
10861635483035 fread(...65536)
10871635483035 fread(...65536)
10881635483035 fread(...65536)
10891635483036 fread(...65536)
10901635483036 fread(...65536)
10911635483036 fread(...65536)
10921635483036 fread(...65536)
10931635483036 fread(...65536)
10941635483036 fread(...65536)
10951635483036 fread(...65536)
10961635483036 fread(...65536)
10971635483036 fread(...65536)
10981635483036 fread(...65536)
10991635483036 fread(...65536)
11001635483036 fread(...65536)
11011635483036 fread(...65536)
11021635483036 fread(...65536)
11031635483036 fread(...65536)
11041635483036 fread(...65536)
11051635483036 fread(...65536)
11061635483036 fread(...65536)
11071635483036 fread(...65536)
11081635483036 fread(...65536)
11091635483036 fread(...65536)
11101635483036 fread(...65536)
11111635483036 fread(...65536)
11121635483036 fread(...65536)
11131635483036 fread(...65536)
11141635483036 fread(...65536)
11151635483036 fread(...65536)
11161635483036 fread(...65536)
11171635483036 fread(...65536)
11181635483036 fread(...65536)
11191635483036 fread(...65536)
11201635483037 fread(...65536)
11211635483037 fread(...65536)
11221635483037 fread(...65536)
11231635483037 fread(...65536)
11241635483037 fread(...65536)
11251635483037 fread(...65536)
11261635483037 fread(...65536)
11271635483037 fread(...65536)
11281635483037 fread(...65536)
11291635483037 fread(...65536)
11301635483037 fread(...65536)
11311635483037 fread(...65536)
11321635483037 fread(...65536)
11331635483037 fread(...65536)
11341635483037 fread(...65536)
11351635483037 fread(...65536)
11361635483037 fread(...65536)
11371635483037 fread(...65536)
11381635483037 fread(...65536)
11391635483037 fread(...65536)
11401635483037 fread(...65536)
11411635483037 fread(...65536)
11421635483037 fread(...65536)
11431635483037 fread(...65536)
11441635483037 fread(...65536)
11451635483037 fread(...65536)
11461635483037 fread(...65536)
11471635483037 fread(...65536)
11481635483037 fread(...65536)
11491635483037 fread(...65536)
11501635483037 fread(...65536)
11511635483038 fread(...65536)
11521635483038 fread(...65536)
11531635483038 fread(...65536)
11541635483038 fread(...65536)
11551635483038 fread(...65536)
11561635483038 fread(...65536)
11571635483038 fread(...65536)
11581635483038 fread(...65536)
11591635483038 fread(...65536)
11601635483038 fread(...65536)
11611635483038 fread(...65536)
11621635483038 fread(...65536)
11631635483038 fread(...65536)
11641635483038 fread(...65536)
11651635483038 fread(...65536)
11661635483038 fread(...65536)
11671635483038 fread(...65536)
11681635483038 fread(...65536)
11691635483038 fread(...65536)
11701635483038 fread(...65536)
11711635483038 fread(...65536)
11721635483038 fread(...65536)
11731635483038 fread(...65536)
11741635483038 fread(...65536)
11751635483038 fread(...65536)
11761635483038 fread(...65536)
11771635483038 fread(...65536)
11781635483038 fread(...65536)
11791635483038 fread(...65536)
11801635483038 fread(...65536)
11811635483038 fread(...65536)
11821635483038 fread(...65536)
11831635483039 fread(...65536)
11841635483039 fread(...65536)
11851635483039 fread(...65536)
11861635483039 fread(...65536)
11871635483039 fread(...65536)
11881635483039 fread(...65536)
11891635483039 fread(...65536)
11901635483039 fread(...65536)
11911635483039 fread(...65536)
11921635483039 fread(...65536)
11931635483039 fread(...65536)
11941635483039 fread(...65536)
11951635483039 fread(...65536)
11961635483039 fread(...65536)
11971635483039 fread(...65536)
11981635483039 fread(...65536)
11991635483039 fread(...65536)
12001635483039 fread(...65536)
12011635483039 fread(...65536)
12021635483039 fread(...65536)
12031635483039 fread(...65536)
12041635483039 fread(...65536)
12051635483039 fread(...65536)
12061635483039 fread(...65536)
12071635483039 fread(...65536)
12081635483039 fread(...65536)
12091635483039 fread(...65536)
12101635483039 fread(...65536)
12111635483039 fread(...65536)
12121635483039 fread(...65536)
12131635483039 fread(...65536)
12141635483040 fread(...65536)
12151635483040 fread(...65536)
12161635483040 fread(...65536)
12171635483040 fread(...65536)
12181635483040 fread(...65536)
12191635483040 fread(...65536)
12201635483040 fread(...65536)
12211635483040 fread(...65536)
1222* We are completely uploaded and fine
1223< HTTP/2 201
1224< date: Fri, 29 Oct 2021 04:50:40 GMT
1225< content-type: text/html; charset=UTF-8
1226< content-length: 0
1227< last-modified: Fri, 29 Oct 2021 04:50:15 GMT
1228< etag: 069fc83e88bc112f309f2548c386853c
1229< x-trans-id: tx7133aca8ca844d46a8931-00617b7d86
1230<
1231* Connection #0 to host ms-fe.svc.codfw.wmnet left intact
1232bool(true)
12331635483040 finished
1234array(8) {
1235 [0]=>
1236 string(13) "HTTP/2 201
1237"
1238 [1]=>
1239 string(37) "date: Fri, 29 Oct 2021 04:50:40 GMT
1240"
1241 [2]=>
1242 string(40) "content-type: text/html; charset=UTF-8
1243"
1244 [3]=>
1245 string(19) "content-length: 0
1246"
1247 [4]=>
1248 string(46) "last-modified: Fri, 29 Oct 2021 04:50:15 GMT
1249"
1250 [5]=>
1251 string(40) "etag: 069fc83e88bc112f309f2548c386853c
1252"
1253 [6]=>
1254 string(48) "x-trans-id: tx7133aca8ca844d46a8931-00617b7d86
1255"
1256 [7]=>
1257 string(2) "
1258"
1259}
1260string(0) ""
1261
1262real 0m26.815s
1263user 0m16.464s
1264sys 0m10.132s
1265legoktm@mw1305:~$
1266

note that it's doing fread's with a chunk size of 65536 or 65kb...which again points to syscalls just overall being slower on buster. strace shows CLI curl using like five read() syscalls to read the whole file while PHP took so many it scrolled off my terminal.

If I use PHP's stream wrappers, literally:

$opts = [ 'http' => [
	'method' => 'PUT',
	'header' => $realHeaders,
	'content' => $contents,
] ];

$ctx = stream_context_create($opts);
$fh = fopen( $url, "r", false, $ctx );
$result = stream_get_meta_data( $fh );

Where $contents is the file read into memory, then the same exact upload to codfw takes ~1s.

Also note that during the buster upgrade we did move from curl 7.52.1 to 7.64.0, so it could also be a regression from that. I haven't looked at the libcurl changelog yet.

I tried a few different variations on the PHP curl script, none of which made a difference:

  • Using curl_setopt( $ch, CURLOPT_POSTFIELDS, $contents ); instead of CURLOPT_INFILE/CURLOPT_READFUNCTION
  • Writing the file to php://memory which is supposed to be a in-memory stream

The stream_context_create solution only works for files that fit under the memory limit, which is currently ~600MB.

The stream_context_create solution only works for files that fit under the memory limit, which is currently ~600MB.

@Inductiveload mentioned to me that the practical limit to not hit a timeout is ~90-100MB, so this still would be a decent improvement. We could also have a temporary higher memory limit for job runners like we already do for Parsoid.

Just to clarify from a previous comment from @Legoktm, the "fread" reported in his output is produced by curl when it sends the data to the client. So I'm not sure at all it has to do with too many syscalls.

So, we can go deeper in what's wrong here, but for now I just tested switching the URL we call in @Legoktm's test.php to funnel the request via envoy, and that reduced the upload time to ~ 1 second, which is what we were seeing with the curl cli tool as well. We need to do a few more tests - like try to change the swift url on mwdebug and see if that's enough to fix the issue without breaking the world, but it seems indeed the problem is with the transfer chunk size and the amount of back and forth chatter needed as a consequence.

While I think this route should be only followed with care (we know that introducing a proxy between systems often causes failures of its own) it is still a way out and confirmed my basic suspect.

So, what I think we know at this point is:

  • The problem is completely within php / curl; curl from the command line or pretty much any other client behaves correctly.
  • PHP's curl usage will write/read responses in 65k chunks, so there seems to be a back-forth of request/response partial data across the wire
  • for the test file, I see 820 such req/resp partial stages (the fread in lego's paste)
  • If we multiply 820 by 31.5 ms (the rtt between mw1305 and ms-fe.svc.codfw.wmnet) we get 25.8 seconds... which is more or less the overhead we're seeing

Now I would just need to get a full dump of the tcp communications between client and server to confirm what exactly is happening - I suppose it's waiting for "100-contiunue" messages from the server.

So @Legoktm hypothesis seems overall correct - but it's not the syscalls that cause the slowness, it's the 820 round trips between datacenters because we're sending such small chunks.

2021-10-29_12-55.png (1ร—870 px, 80 KB)

Adding a statistical analysis of packet lengths in wireshark from 2 captures. Upper one, with 3323 packets in total is standard curl call, lower one, with 13326 packets is test.php.

I don't think curl sends Expect: 100-continue for chunked transfers to begin with, and I don't think chunks need to be ack'ed before sending the next in HTTP/1.1.

But then, as Lego's output above shows, cmdline curl is using HTTP/1.0 and libcurl from PHP is using HTTP/2. And in HTTP/2 chunked transfer encoding isn't supported, replaced with some new streaming and multiplexing stuff that I've never looked into but which sounds suspiciously like reimplementing TCP on top of HTTP. In particular, I wouldn't be at all surprised to find that HTTP/2 has what amounts to a TCP ACK but without SACK.

Can we force cmdline curl to HTTP/2, or PHP libcurl to HTTP/1.1, to test that?

In any case, with ~15ms latency any synchronous ack is going to kill performance with small chunks (http level "packets"), and upping the size of the chunks massively the best bet for improving throughput.

Can we force cmdline curl to HTTP/2, or PHP libcurl to HTTP/1.1, to test that?

Right on target! Thanks for noticing that, that's the issue. HTTP2 shouldn't really be used in internal scenarios, it was never meant for that.

setting curl_setopt( $ch, CURLOPT_HTTP_VERSION, CURL_HTTP_VERSION_1_1); in the code fixes it and conversely passing --http2 to the curl call reproduces it.

Yes, thanks for noticing @Xover; a posteriori, it's pretty obvious what is going on and it's interesting how much more inefficient using http2 is in this case (not surprising, once you think about it, but still unexpected, at least for me).

#2709 landed in libcurl 7.62.0 and enabled HTTP/2 multiplexing by default when available, so Buster would indeed have changed the behaviour here as Lego suggested in T275752#7467345.

setting curl_setopt( $ch, CURLOPT_HTTP_VERSION, CURL_HTTP_VERSION_1_1); in the code fixes it

Hmm. Is HTTP/2 actually used for anything in core? Just setting the above in the global settings in MultiHttpClient.php:getCurlHandle() might be all that's needed.

setting curl_setopt( $ch, CURLOPT_HTTP_VERSION, CURL_HTTP_VERSION_1_1); in the code fixes it

Hmm. Is HTTP/2 actually used for anything in core? Just setting the above in the global settings in MultiHttpClient.php:getCurlHandle() might be all that's needed.

I would rather add an option to the constructor of MultiHttpClient conditionally or - let me put my SRE hat on - get the ability to define domains for which we do not want to use http/2 so that we can effectively ban the use of http/2 internally.

While reading the code of MultiHttpClient, I found that is tries to support pipelining, which was removed from curl completely (and was already disabled in curl 7.62):

https://daniel.haxx.se/blog/2019/04/06/curl-says-bye-bye-to-pipelining/

I'm now thinking we should offer an opt-in useMultiplexing instead, and only explicitly use http 2 when that is set to true maybe.

While reading the code of MultiHttpClient, I found that is tries to support pipelining, which was removed from curl completely (and was already disabled in curl 7.62):

https://daniel.haxx.se/blog/2019/04/06/curl-says-bye-bye-to-pipelining/

I'm now thinking we should offer an opt-in useMultiplexing instead, and only explicitly use http 2 when that is set to true maybe.

T264735: MultiHttpClient has hard-coded deprecated cURL option used by CdnCacheUpdate

Change 735646 had a related patch set uploaded (by Alexandros Kosiaris; author: Alexandros Kosiaris):

[mediawiki/core@master] MultiHttpClient: Allow setting HTTP protocol version in curl

https://gerrit.wikimedia.org/r/735646

Change 735647 had a related patch set uploaded (by Alexandros Kosiaris; author: Alexandros Kosiaris):

[mediawiki/core@master] WIP: Force HTTP version for SwiftFileBackend

https://gerrit.wikimedia.org/r/735647

"Delivering HTTP/2 upload speed improvements" from Cloudflare may be of use for Swift people looking into this or similar issues. I haven't mapped the lab numbers they use to the scenario here, but high-bandwidth+high-latency usually means you run into the Long Fat Pipe problem where TCP window scaling comes into play. And since HTTTP/2 is essentially reinventing TCP at the application layer (just with "frames" instead of "packets") it seems likely that what we're seeing here is essentially broken "HTTP window scaling" (cf. RFC7540 6.9.2): the receiver (in this case Swift) sets the window size, and is here using the 64k default size which libcurl faithfully obeys (curl itself, for downloads, switched its default to ~32MB in 7.52.0). In other words, it looks like this can't actually be tuned on the MW (libcurl) side but must happen on the Swift side if it's to be supported.

I'm now thinking we should offer an opt-in useMultiplexing instead, and only explicitly use http 2 when that is set to true maybe.

Opt-in sounds sensible to me in this scenario (FWIW). Front end stuff (anything talking directly to a web browser) might benefit from HTTP/2, but I don't see the use cases elsewhere.

Change 735670 had a related patch set uploaded (by Legoktm; author: Legoktm):

[mediawiki/core@master] MultiHttpClient: Force HTTP/1.0 to avoid HTTP/2 multiplexing

https://gerrit.wikimedia.org/r/735670

Change 735670 abandoned by Legoktm:

[mediawiki/core@master] MultiHttpClient: Force HTTP/1.0 to avoid HTTP/2 multiplexing

Reason:

Per Joe

https://gerrit.wikimedia.org/r/735670

Change 735646 merged by jenkins-bot:

[mediawiki/core@master] MultiHttpClient: Allow setting HTTP protocol version in curl

https://gerrit.wikimedia.org/r/735646

Change 735647 merged by jenkins-bot:

[mediawiki/core@master] Force using HTTP 1.1 for SwiftFileBackend

https://gerrit.wikimedia.org/r/735647

Change 735637 had a related patch set uploaded (by Legoktm; author: Alexandros Kosiaris):

[mediawiki/core@wmf/1.38.0-wmf.6] MultiHttpClient: Allow setting HTTP protocol version in curl

https://gerrit.wikimedia.org/r/735637

Change 735638 had a related patch set uploaded (by Legoktm; author: Alexandros Kosiaris):

[mediawiki/core@wmf/1.38.0-wmf.6] Force using HTTP 1.1 for SwiftFileBackend

https://gerrit.wikimedia.org/r/735638

But then, as Lego's output above shows, cmdline curl is using HTTP/1.0 and libcurl from PHP is using HTTP/2. And in HTTP/2 chunked transfer encoding isn't supported, replaced with some new streaming and multiplexing stuff that I've never looked into but which sounds suspiciously like reimplementing TCP on top of HTTP. In particular, I wouldn't be at all surprised to find that HTTP/2 has what amounts to a TCP ACK but without SACK.

I totally missed that PHP was using HTTP/2, nice catch. I was forcing CLI curl to use HTTP/1.0 because in the Swift logs, the requests appeared as being HTTP/1.0. But now I realize that we were talking HTTP/2 to nginx, which terminated TLS for Swift, and the nginx<-->Swift is HTTP/1.0, which ends up in the logs.

Change 735637 merged by jenkins-bot:

[mediawiki/core@wmf/1.38.0-wmf.6] MultiHttpClient: Allow setting HTTP protocol version in curl

https://gerrit.wikimedia.org/r/735637

Change 735638 merged by jenkins-bot:

[mediawiki/core@wmf/1.38.0-wmf.6] Force using HTTP 1.1 for SwiftFileBackend

https://gerrit.wikimedia.org/r/735638

Mentioned in SAL (#wikimedia-operations) [2021-10-29T21:17:35Z] <legoktm@deploy1002> Synchronized php-1.38.0-wmf.6/includes/libs/http/MultiHttpClient.php: MultiHttpClient: Allow setting HTTP protocol version in curl (T275752) (duration: 00m 57s)

Mentioned in SAL (#wikimedia-operations) [2021-10-29T21:20:00Z] <legoktm@deploy1002> Synchronized php-1.38.0-wmf.6/includes/libs/filebackend/SwiftFileBackend.php: Force using HTTP 1.1 for SwiftFileBackend (T275752) (duration: 00m 55s)

2021-10-29 21:21:39 [296d3ab0-158d-47d4-b10b-25ae741838c7] mw1308 testwiki 1.38.0-wmf.6 FileOperation DEBUG: HTTP start: PUT https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-test-local-temp/5/57/20211029212138%21chunkedupload_ac568d8608f7.djvu {"method":"PUT","url":"https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-test-local-temp/5/57/20211029212138%21chunkedupload_ac568d8608f7.djvu","headers":{"content-type":"image/vnd.djvu","content-length":53798301,"etag":"069fc83e88bc112f309f2548c386853c","x-object-meta-sha1base36":"56e0liu04c2u9avcrvlz7m5k4nh6gxf"}} 
2021-10-29 21:21:40 [296d3ab0-158d-47d4-b10b-25ae741838c7] mw1308 testwiki 1.38.0-wmf.6 FileOperation DEBUG: HTTP complete: PUT https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-test-local-temp/5/57/20211029212138%21chunkedupload_ac568d8608f7.djvu code=201 size=0 total=0.816901 connect=6.3E-5 {"method":"PUT","url":"https://ms-fe.svc.codfw.wmnet/v1/AUTH_mw/wikipedia-test-local-temp/5/57/20211029212138%21chunkedupload_ac568d8608f7.djvu","response_code":201,"size":0.0,"total_time":"0.816901","connect_time":"6.3E-5"}

Took only .8s to upload the same ~50MB file from earlier. Looks like this is it, but I'll wait till we have a few days of data before declaring it solved.

I watched the uploads for T292769: Server side upload to commons (2 DJVUs ~800MB each) and they took 7s and 9s for 714MB and 864 MB files, respectively. \o/

Change 735944 had a related patch set uploaded (by Alexandros Kosiaris; author: Alexandros Kosiaris):

[operations/puppet@production] tlsproxy::localssl: Allow disabling http2

https://gerrit.wikimedia.org/r/735944

Change 735945 had a related patch set uploaded (by Alexandros Kosiaris; author: Alexandros Kosiaris):

[operations/puppet@production] maps: Disable http2 in tlsproxy

https://gerrit.wikimedia.org/r/735945

Change 735946 had a related patch set uploaded (by Alexandros Kosiaris; author: Alexandros Kosiaris):

[operations/puppet@production] elasticsearch::cirrus: Disable http2 in tlsproxy

https://gerrit.wikimedia.org/r/735946

Change 735947 had a related patch set uploaded (by Alexandros Kosiaris; author: Alexandros Kosiaris):

[operations/puppet@production] cloudelastic: Disable http2 in tlsproxy

https://gerrit.wikimedia.org/r/735947

But now I realize that we were talking HTTP/2 to nginx, which terminated TLS for Swift

Which should not have happened but unfortunately code re-use bit us here. Anyway, patches uploaded to disable http2 in that module and users of it. Service Owners can definitely make the case for having HTTP2 enabled, but it should a conscious choice.

Change 735973 had a related patch set uploaded (by Alexandros Kosiaris; author: Alexandros Kosiaris):

[operations/puppet@production] relforge: Disable http2 in tlsproxy

https://gerrit.wikimedia.org/r/735973

Legoktm renamed this task from Jobrunner on Buster occasional timeout on codfw file upload to Jobrunner timeouts on cross-DC file uploads because of HTTP/2.Nov 1 2021, 9:18 PM

Change 735944 merged by Alexandros Kosiaris:

[operations/puppet@production] tlsproxy::localssl: Allow disabling http2

https://gerrit.wikimedia.org/r/735944

Change 735945 merged by Alexandros Kosiaris:

[operations/puppet@production] maps: Disable http2 in tlsproxy

https://gerrit.wikimedia.org/r/735945

Change 735946 merged by Alexandros Kosiaris:

[operations/puppet@production] elasticsearch::cirrus: Disable http2 in tlsproxy

https://gerrit.wikimedia.org/r/735946

Change 735947 merged by Alexandros Kosiaris:

[operations/puppet@production] cloudelastic: Disable http2 in tlsproxy

https://gerrit.wikimedia.org/r/735947

Change 735973 merged by Alexandros Kosiaris:

[operations/puppet@production] relforge: Disable http2 in tlsproxy

https://gerrit.wikimedia.org/r/735973