Downloads appear to be requested multiple times after a metalink redirect

[Firstyear]

Recently while checking mirror.fy.id.au logs I noticed odd behaviour of zypper.

Sep 13 13:57:18 b571b137-5f07-4e85-9d3a-97a4e2c1a9db INFO     get_view [ 657µs | 28.82% / 100.00% ]
Sep 13 13:57:18 b571b137-5f07-4e85-9d3a-97a4e2c1a9db INFO     ┝━ ｉ [info]: request_headers -> {"host": "mirror.firstyear.id.au", "range": "bytes=0-928997", "user-agent": "ZYpp 17.35.9 (curl 8.9.1) openSUSE-Tumbleweed-x86_64", "accept": "*/*"}
Sep 13 13:57:18 b571b137-5f07-4e85-9d3a-97a4e2c1a9db INFO     ┝━ ｉ [info]: 🤔  contemplating req -> "/tumbleweed/repo/oss/x86_64/libgnutls30-3.8.7-1.1.x86_64.rpm"
Sep 13 13:57:18 dbd9c216-5b41-4adb-b428-3b32b3da1872 INFO     get_view [ 852µs | 23.50% / 100.00% ]
Sep 13 13:57:18 dbd9c216-5b41-4adb-b428-3b32b3da1872 INFO     ┝━ ｉ [info]: request_headers -> {"host": "mirror.firstyear.id.au", "range": "bytes=0-928997", "user-agent": "ZYpp 17.35.9 (curl 8.9.1) openSUSE-Tumbleweed-x86_64", "accept": "*/*"}
Sep 13 13:57:18 dbd9c216-5b41-4adb-b428-3b32b3da1872 INFO     ┝━ ｉ [info]: 🤔  contemplating req -> "/tumbleweed/repo/oss/x86_64/libgnutls30-3.8.7-1.1.x86_64.rpm"
Sep 13 13:57:18 c966299f-0a20-4499-87b6-248f2fa2c5e9 INFO     get_view [ 425µs | 39.57% / 100.00% ]
Sep 13 13:57:18 c966299f-0a20-4499-87b6-248f2fa2c5e9 INFO     ┝━ ｉ [info]: request_headers -> {"host": "mirror.firstyear.id.au", "range": "bytes=0-928997", "user-agent": "ZYpp 17.35.9 (curl 8.9.1) openSUSE-Tumbleweed-x86_64", "accept": "*/*"}
Sep 13 13:57:18 c966299f-0a20-4499-87b6-248f2fa2c5e9 INFO     ┝━ ｉ [info]: 🤔  contemplating req -> "/tumbleweed/repo/oss/x86_64/libgnutls30-3.8.7-1.1.x86_64.rpm"
Sep 13 13:57:18 94bde68b-adbc-4c94-a677-00f1abda1d0f INFO     get_view [ 490µs | 35.31% / 100.00% ]
Sep 13 13:57:18 94bde68b-adbc-4c94-a677-00f1abda1d0f INFO     ┝━ ｉ [info]: request_headers -> {"host": "mirror.firstyear.id.au", "range": "bytes=0-928997", "user-agent": "ZYpp 17.35.9 (curl 8.9.1) openSUSE-Tumbleweed-x86_64", "accept": "*/*"}
Sep 13 13:57:18 94bde68b-adbc-4c94-a677-00f1abda1d0f INFO     ┝━ ｉ [info]: 🤔  contemplating req -> "/tumbleweed/repo/oss/x86_64/libgnutls30-3.8.7-1.1.x86_64.rpm"

This shows a client rapidly requesting the same file libgnutls30-3.8.7-1.1.x86_64.rpm 4 times in rapid succession. This is confirmed by wireshark traces.

Examining these connections we see that there is a "race" where after establishment, zypper then rapidly sends TCP FIN to 3 of the 4, and only then retrieves the file from the remaining singular connection.

It's unclear why zypper is doing this - however, it causes the server to need to load and start to send the file multiple times needlessly, which also introduces network latency and congestion. What's more, is all requests are of the same range of bytes.

When zypper is directed to a single mirror this does not occur, it only occurs with the multi-curl backend after zypper is redirected by mirrorcache.

-- expected behaviour

zypper opens one connection, and downloads the file once.

[mlandres]

Will have a look at it (after vacation; Sept.30.).
In case you can grab a zypper.log from a client side, please attach it.

[Firstyear]

Sadly I haven't been able to reproduce myself, I have just seen it occuring via the mirrors. If I can reproduce, I'll let you know.

[bzeller]

Only reason for this I could think of is the "stealing" feature. Which is when the MultiCurl backend downloads a file and has more free workers ( e.g. mirrors ) than chunks it will try to steal from a "running" chunk and use the one that is finished the fastest... But it should not download from the same mirror multiple times.