Description
Describe the bug
A clear and concise description of what the bug is.
We have an image from quay.io repo to be cached to private docker regsitry hosted locally. We just encountered an issue where an image is built with a large blob of around ~ 3.6 GB. This image copy from quay.io to localhost:5000/abc/xyx@sha:907392ea41291ab611ddbee96f6e8516d91359c66a180215cdb35a0dbd867ab4 takes more than 15 minutes to upload and finally resulting in an failure exactly at the 15th minutes of the blob copy start
ubuntu@ip-10-xxx-xxx-xxx:~$ [us-cach-new] time crane copy -j 16 --insecure quay.io/abc/xyz@sha256:907392ea41291ab611ddbee96f6e8516d91359c66a180215cdb35a0dbd867ab4 10.200.120.182:5000/abc/xyz@sha256:907392ea41291ab611ddbe
e96f6e8516d91359c66a180215cdb35a0dbd867ab4
2025/04/03 08:30:25 Copying from quay.io/abc/xyz@sha256:907392ea41291ab611ddbee96f6e8516d91359c66a180215cdb35a0dbd867ab4 to 10.200.120.182:5000/abc/xyz@sha256:907392ea41291ab611ddbee96f6e8516d91359c66a180215cdb35a0dbd867ab4
2025/04/03 08:30:28 existing blob: sha256:662189e7fe21f560823e463079fe2dcd76adc63c89a2027bbb48d493e538614c
2025/04/03 08:30:28 existing blob: sha256:945c9aafe91d1655f934fe989671cd8d8e1c2cae80f21204fe4f0f5c33fe71cd
2025/04/03 08:30:28 existing blob: sha256:b0229b2f91f23c5400a4bddc1d2b69c8a1016d84c27cf28058d91f6f54c2221e
2025/04/03 08:30:28 existing blob: sha256:23576ee7eaf9dd762d456422a9ade3eb0d1e4771a2f15b7aedf14a1d0dc1b800
2025/04/03 08:30:28 existing blob: sha256:4f4fb700ef54461cfa02571ae0db9a0dc1e0cdb5577484a6d75e68dc38e8acc1
2025/04/03 08:30:28 existing blob: sha256:426f5576ffbb73aa7676627ddde9f44dba1a7ec79ac791b163261d54e061f883
2025/04/03 08:30:28 existing blob: sha256:e1e7b5edfd43d722034b3d33e5512cd2c4c973e2c02effcd97d895120f931acb
2025/04/03 08:30:28 existing blob: sha256:6991cdeef5ced86f346be9f070f0b5c03aab9768bae91664355adbdad906141e
2025/04/03 08:30:28 existing blob: sha256:468d90e861876e08a6f41ca951e9c65d32433c24e2d0a4dc3eca1b3a38d70855
2025/04/03 08:30:28 existing blob: sha256:49945d46b2cda7e354c37acfabfc49396c90f25424f06838747997d16a50664c
2025/04/03 08:30:28 existing blob: sha256:49e8e931e0c72e79fca424c889b710269f54a255f4f41dff398d3c85c7b3cc96
2025/04/03 08:30:28 existing blob: sha256:45b439e3774e2da6ef81a53f0213fc658b9951bb0de51f645c9d81b58a6224fe
2025/04/03 08:30:28 existing blob: sha256:3e0fdcb9c12323ea6530e0a2b59f4d2753ce05187d3e85a9426e350aa149f8b2
2025/04/03 08:30:28 existing blob: sha256:963ceec6c2ca13b343a25d3157e3e30ffa80fc297ad5e3f78d8f43087427b2d3
2025/04/03 08:30:28 existing blob: sha256:aca13bb8c386c8f10a638328363d158bdb463c6b2af83db9531962a8bbeb40e7
2025/04/03 08:30:28 existing blob: sha256:e77b27b2a67bba9dea348d2c01d79e25e9d935c6f0a5fcb53dced81ea9ee92c9
2025/04/03 08:30:28 existing blob: sha256:1a8913f0a1b26233eeb53cd3e9a36efdcddf47ea7a51fd851c72ee7ad3bf85ef
2025/04/03 08:30:28 existing blob: sha256:aeeb98b1fccfaa62c9b00bb976741ce3b7b7cbc9595ca768f5a0aa15252d2b47
2025/04/03 08:30:28 existing blob: sha256:c560cc11c244a05d95e9c5959eb420af21a2e5229ccb1e0b591619507a688b16
2025/04/03 08:30:28 existing blob: sha256:d9802f032d6798e2086607424bfe88cb8ec1d6f116e11cd99592dcaf261e9cd2
2025/04/03 08:30:28 existing blob: sha256:8b6ac904bbf24881ae2f4a8ed584afcdc2c8b79a590571c5f6034124e3229fdc
2025/04/03 08:30:28 existing blob: sha256:32a0afef0a4eb09fbef4514c369d8ece53e06f1c0a63d86d5cfd2dca1efd8dfc
2025/04/03 08:30:28 existing blob: sha256:b07589e190657a519f0bbc60da9b7bfb7380ec46b806c5ad9e2874893b93af77
2025/04/03 08:30:28 existing blob: sha256:98f6b0e4c137ba3e5a052b6450e3499ba6401cd3fb75f3867df6326d858fde3e
2025/04/03 08:30:28 existing blob: sha256:49d8e62f223f4c1d7e9497baa00db5e5aa63716e71ac9fa98b60abebc8c8c88c
2025/04/03 08:30:28 existing blob: sha256:76c1bfa0c8f66d86f7119e1e24a4e2fa0e4aa1462e5a496543b9a8b12a48b326
2025/04/03 08:30:28 existing blob: sha256:5808ced04684078b8992016a3c6ce7069790a1d3a2c1839e0761dfda8a9501d0
2025/04/03 08:30:28 existing blob: sha256:7cdb99a680fd1148cb35cf5e35ffecd447458e3aee489a590db4aff78bad6107
2025/04/03 08:30:28 existing blob: sha256:4196b5558dedf18efed593e86e36edf9b008af8e6c49c0ad7eb55e09e5dde917
2025/04/03 08:30:28 existing blob: sha256:8f8189cd778431875e47e507da7c016876dc8f8e49a8c79bd14f82ea4fc264ff
2025/04/03 08:30:29 existing blob: sha256:4319eb70c18f3db13c67e8b0a6a3bd911f3a494a82c71a1f4234d238220fe5d8
2025/04/03 08:30:29 existing blob: sha256:e437062fb3c860a650de9d0fd31673004ce7379c886aa000767dce18e24c83e1
2025/04/03 08:30:29 existing blob: sha256:8e3a1585b63838d5eca6c777265667e04b88756850b88e8bf6d3907a04595bf4
2025/04/03 08:30:29 existing blob: sha256:c80623e892165eebb54049512ddc5bb9d66076b8978d7f981b64d7946317c3af
2025/04/03 08:30:29 existing blob: sha256:b4c3efb2108019c0adac1ca568c3625e59459ee3d3d80a2f178d4dcd6e4e4566
2025/04/03 08:30:29 existing blob: sha256:80caa5cda2ceeccae9d4cd4d3c5c4617bf3b6097007e9b04831204aaab0c504e
2025/04/03 08:30:29 existing blob: sha256:28b75d8a50ebd411d980805f03cf31a9f0d852a1d4eab8e7c2473b9a8e3b857c
2025/04/03 08:45:41 retrying Patch "https://10.2xx.1xx.1xx:5000/v2/abc/xyz/blobs/uploads/156f6483-dcd8-4093-84d7-e1f604507788?_state=4RMEcB4vEzTvxMmcv19egwWqqwvKmWwKwHrM5bbseDB7Ik5hbWUiOiJhcnViYWRldm9wcy9haXNlYXJjaCIsIlVVSUQiOiIxNTZmNjQ4My1kY2Q4LTQwOTMtODRkNy1lMWY2MDQ1MDc3ODgiLCJPZmZzZXQiOjAsIlN0YXJ0ZWRBdCI6IjIwMjUtMDQtMDNUMDg6MzA6MjguMTEyODE5Njg4WiJ9": unexpected EOF
2025/04/03 08:45:42 retrying Patch "https://10.2xx.1xx.1xx:5000/v2/abc/xyz/blobs/uploads/1468b5d8-8c49-43a5-8869-0e83b9db4410?_state=T51Nae9QdWHvPiDr_YV_0IGJNd2OCxHAvfz6sMWTmPx7Ik5hbWUiOiJhcnViYWRldm9wcy9haXNlYXJjaCIsIlVVSUQiOiIxNDY4YjVkOC04YzQ5LTQzYTUtODg2OS0wZTgzYjlkYjQ0MTAiLCJPZmZzZXQiOjAsIlN0YXJ0ZWRBdCI6IjIwMjUtMDQtMDNUMDg6MzA6MjkuOTUyNzk5MDI4WiJ9": unexpected EOF
2025/04/03 08:45:43 retrying Patch "https://10.2xx.1xx.1xx:5000/v2/abc/xyz/blobs/uploads/aafe5e10-36d6-4d60-ace4-c60b389e9741?_state=qkQriHJYhd5qMjOhYVRMX5j7kD5-68yvkFVmq8E0u6l7Ik5hbWUiOiJhcnViYWRldm9wcy9haXNlYXJjaCIsIlVVSUQiOiJhYWZlNWUxMC0zNmQ2LTRkNjAtYWNlNC1jNjBiMzg5ZTk3NDEiLCJPZmZzZXQiOjAsIlN0YXJ0ZWRBdCI6IjIwMjUtMDQtMDNUMDg6MzA6MjguMDYxNzA2OTJaIn0%3D": unexpected EOF
if you observe above, the unexpected EOF reported exactly after 15 mins is done during blob upload. This is reproducible everytime the same blob is getting copied. retried 100 times but no luck here.
We have set the Private docker registry times outs as
ubuntu@ip-10-2xx-1xx-1xx:~/caching$ cat /home/ubuntu/caching/config.yml version: 0.1 log: level: debug fields: service: registry storage: cache: blobdescriptor: inmemory s3: region: cn-north-1 bucket: cn-north-1-xx-images http: addr: :5000 timeout: 3600s # add timeout to 1 hour read_timeout: 3600s write_timeout: 3600s readbuffer: 5368709120 writebuffer: 5368709120 maxrequestsize: 0 # Remove chunked transfer limits for large uploads compression: enabled: true headers: X-Content-Type-Options: [nosniff] tls: certificate: /etc/docker/certs/cert.pem key: /etc/docker/certs/key.pem compatibility: schema1: enabled: true delete: enabled: false gc: enabled: true interval: 24h # Run garbage collection every 24 hours ubuntu@ip-10-xx-xx-xx:~/caching$
error from docker private registry while upload failure
time="2025-04-06T08:09:09.016847104Z" level=error msg="client disconnected during blob PATCH" contentLength=3337361377 copied=784334848 error="stream error: stream ID 53; CANCEL" go.version=go1.19.9 http.request.contenttype="application/octet-stream" http.request.host="10.2xx.1xx.1xx:5000" http.request.id=218f99eb-4283-4bf0-bc88-165a9c224632 http.request.method=PATCH http.request.remoteaddr="10.2xx.xx.1xx:63048" http.request.uri="/v2/abc/xyz/blobs/uploads/bc1196fc-df1c-4a11-a0f3-64cb8c65e737?_state=-GUSg06iceCOlRKRo2a2okbY0LwbPe6jpK3f4BThjnJ7Ik5hbWUiOiJhcnViYWRldm9wcy9haXNlYXJjaCIsIlVVSUQiOiJiYzExOTZmYy1kZjFjLTRhMTEtYTBmMy02NGNiOGM2NWU3MzciLCJPZmZzZXQiOjAsIlN0YXJ0ZWRBdCI6IjIwMjUtMDQtMDZUMDc6NTM6NTYuMTE3NTI2ODM5WiJ9" http.request.useragent="crane/0.19.0 go-containerregistry/0.19.0" vars.name="abc/xyz" vars.uuid=bc1196fc-df1c-4a11-a0f3-64cb8c65e737 time="2025-04-06T08:09:09.01823727Z" level=error msg="client disconnected during blob PATCH" contentLength=2622170251 copied=786432000 error="stream error: stream ID 51; CANCEL" go.version=go1.19.9 http.request.contenttype="application/octet-stream" http.request.host="10.2xx.1xx.1xx:5000" http.request.id=6e8d4cd0-8c6d-4d08-9d1b-d02e6440c768 http.request.method=PATCH http.request.remoteaddr="10.211.49.115:63048" http.request.uri="/v2/abc/xyz/blobs/uploads/6e64457b-6b95-4579-9b20-48a2580227c0?_state=QEPXOGdUvcS5Ql7WEKWaxIBYRrusjEYNERyduWoBVcN7Ik5hbWUiOiJhcnViYWRldm9wcy9haXNlYXJjaCIsIlVVSUQiOiI2ZTY0NDU3Yi02Yjk1LTQ1NzktOWIyMC00OGEyNTgwMjI3YzAiLCJPZmZzZXQiOjAsIlN0YXJ0ZWRBdCI6IjIwMjUtMDQtMDZUMDc6NTM6NTUuNjE3MzMwMDI3WiJ9" http.request.useragent="crane/0.19.0 go-containerregistry/0.19.0" vars.name="abc/xyz" vars.uuid=6e64457b-6b95-4579-9b20-48a2580227c0 time="2025-04-06T08:09:09.233401451Z" level=error msg="response completed with error" err.code=unknown err.detail="client disconnected" err.message="unknown error" go.version=go1.19.9 http.request.contenttype="application/octet-stream" http.request.host="10.2xx.1xx.1xx:5000" http.request.id=6e8d4cd0-8c6d-4d08-9d1b-d02e6440c768 http.request.method=PATCH http.request.remoteaddr="10.211.49.115:63048" http.request.uri="/v2/abc/xyz/blobs/uploads/6e64457b-6b95-4579-9b20-48a2580227c0?_state=QEPXOGdUvcS5Ql7WEKWaxIBYRrusjEYNERyduWoBVcN7Ik5hbWUiOiJhcnViYWRldm9wcy9haXNlYXJjaCIsIlVVSUQiOiI2ZTY0NDU3Yi02Yjk1LTQ1NzktOWIyMC00OGEyNTgwMjI3YzAiLCJPZmZzZXQiOjAsIlN0YXJ0ZWRBdCI6IjIwMjUtMDQtMDZUMDc6NTM6NTUuNjE3MzMwMDI3WiJ9" http.request.useragent="crane/0.19.0 go-containerregistry/0.19.0" http.response.contenttype="application/json; charset=utf-8" http.response.duration=15m13.082493548s http.response.status=500 http.response.written=89 vars.name="arubadevops/xyz" vars.uuid=6e64457b-6b95-4579-9b20-48a2580227c0 10.211.49.115 - - [06/Apr/2025:07:53:56 +0000] "PATCH /v2/abc/xyz/blobs/uploads/6e64457b-6b95-4579-9b20-48a2580227c0?_state=QEPXOGdUvcS5Ql7WEKWaxIBYRrusjEYNERyduWoBVcN7Ik5hbWUiOiJhcnViYWRldm9wcy9haXNlYXJjaCIsIlVVSUQiOiI2ZTY0NDU3Yi02Yjk1LTQ1NzktOWIyMC00OGEyNTgwMjI3YzAiLCJPZmZzZXQiOjAsIlN0YXJ0ZWRBdCI6IjIwMjUtMDQtMDZUMDc6NTM6NTUuNjE3MzMwMDI3WiJ9 HTTP/2.0" 500 89 "" "crane/0.19.0 go-containerregistry/0.19.0" time="2025-04-06T08:09:09.427852254Z" level=error msg="response completed with error" err.code=unknown err.detail="client disconnected" err.message="unknown error" go.version=go1.19.9 http.request.contenttype="application/octet-stream" http.request.host="10.2xx.1xx.1xx:5000" http.request.id=218f99eb-4283-4bf0-bc88-165a9c224632 http.request.method=PATCH http.request.remoteaddr="10.2xx.xx.1xx:63048" http.request.uri="/v2/arubadevops/xyz/blobs/uploads/bc1196fc-df1c-4a11-a0f3-64cb8c65e737?_state=-GUSg06iceCOlRKRo2a2okbY0LwbPe6jpK3f4BThjnJ7Ik5hbWUiOiJhcnViYWRldm9wcy9haXNlYXJjaCIsIlVVSUQiOiJiYzExOTZmYy1kZjFjLTRhMTEtYTBmMy02NGNiOGM2NWU3MzciLCJPZmZzZXQiOjAsIlN0YXJ0ZWRBdCI6IjIwMjUtMDQtMDZUMDc6NTM6NTYuMTE3NTI2ODM5WiJ9" http.request.useragent="crane/0.19.0 go-containerregistry/0.19.0" http.response.contenttype="application/json; charset=utf-8" http.response.duration=15m12.07023392s http.response.status=500 http.response.written=89 vars.name="abc/xyz" vars.uuid=bc1196fc-df1c-4a11-a0f3-64cb8c65e737 10.2xx.xx.1xx - - [06/Apr/2025:07:53:57 +0000] "PATCH /v2/abc/xyz/blobs/uploads/bc1196fc-df1c-4a11-a0f3-64cb8c65e737?_state=-GUSg06iceCOlRKRo2a2okbY0LwbPe6jpK3f4BThjnJ7Ik5hbWUiOiJhcnViYWRldm9wcy9haXNlYXJjaCIsIlVVSUQiOiJiYzExOTZmYy1kZjFjLTRhMTEtYTBmMy02NGNiOGM2NWU3MzciLCJPZmZzZXQiOjAsIlN0YXJ0ZWRBdCI6IjIwMjUtMDQtMDZUMDc6NTM6NTYuMTE3NTI2ODM5WiJ9 HTTP/2.0" 500 89 "" "crane/0.19.0 go-containerregistry/0.19.0" 10.211.49.115 - - [06/Apr/2025:08:09:09 +0000] "HEAD /v2/abc/xyz/blobs/sha256:f36e4dcd93eb2302aaddd1a05e8e38f320e72878f8de934ebf9a6327aa90472d HTTP/2.0" 404 157 "" "crane/0.19.0 go-containerregistry/0.19.0" time="2025-04-06T08:09:09.433913043Z" level=error msg="response completed with error" err.code="blob unknown" err.detail=sha256:f36e4dcd93eb2302aaddd1a05e8e38f320e72878f8de934ebf9a6327aa90472d err.message="blob unknown to registry" go.version=go1.19.9 http.request.host="10.200.120.182:5000" http.request.id=f704058f-baf5-4ba0-bd2c-f73a6594e8dd http.request.method=HEAD http.request.remoteaddr="10.2xx.xx.1xx:63048" http.request.uri="/v2/abc/xyz/blobs/sha256:f36e4dcd93eb2302aaddd1a05e8e38f320e72878f8de934ebf9a6327aa90472d" http.request.useragent="crane/0.19.0 go-containerregistry/0.19.0" http.response.contenttype="application/json; charset=utf-8" http.response.duration=27.506031ms http.response.status=404 http.response.written=157 vars.digest="sha256:f36e4dcd93eb2302aaddd1a05e8e38f320e72878f8de934ebf9a6327aa90472d" vars.name="abc/xyz" 10.2xx.xx.1xx - - [06/Apr/2025:08:09:09 +0000] "POST /v2/abc/xyz/blobs/uploads/?from=arubadevops%xyz&mount=sha256%3Af36e4dcd93eb2302aaddd1a05e8e38f320e72878f8de934ebf9a6327aa90472d&origin=quay.io HTTP/2.0" 202 0 "" "crane/0.19.0 go-containerregistry/0.19.0" time="2025-04-06T08:09:09.704639929Z" level=info msg="response completed" go.version=go1.19.9 http.request.contenttype="application/json" http.request.host="10.2xx.1xx.1xx:5000" http.request.id=9e0998ab-e91c-4c5e-9e94-dba8479f271b http.request.method=POST http.request.remoteaddr="10.2xx.xx.1xx:63048" http.request.uri="/v2/abc/xyz/blobs/uploads/?from=arubadevops%xyz&mount=sha256%3Af36e4dcd93eb2302aaddd1a05e8e38f320e72878f8de934ebf9a6327aa90472d&origin=quay.io" http.request.useragent="crane/0.19.0 go-containerregistry/0.19.0" http.response.duration=76.201294ms http.response.status=202 http.response.written=0 10.2xx.xx.1xx - - [06/Apr/2025:08:09:09 +0000] "HEAD /v2/arubadevops/xyz/blobs/sha256:a4626238126a38824d334cc508f7766a2d8e5f7c8bdc04ba4c7a89fa7bde5a4a HTTP/2.0" 404 157 "" "crane/0.19.0 go-containerregistry/0.19.0" time="2025-04-06T08:09:09.716487996Z" level=error msg="response completed with error" err.code="blob unknown" err.detail=sha256:a4626238126a38824d334cc508f7766a2d8e5f7c8bdc04ba4c7a89fa7bde5a4a err.message="blob unknown to registry" go.version=go1.19.9 http.request.host="10.200.120.182:5000" http.request.id=e99fd42b-4de0-4bbc-b12f-36a190713d07 http.request.method=HEAD http.request.remoteaddr="10.2xx.xx.115:63048" http.request.uri="/v2/abc/xyz/blobs/sha256:a4626238126a38824d334cc508f7766a2d8e5f7c8bdc04ba4c7a89fa7bde5a4a" http.request.useragent="crane/0.19.0 go-containerregistry/0.19.0" http.response.contenttype="application/json; charset=utf-8" http.response.duration=26.816772ms http.response.status=404 http.response.written=157 vars.digest="sha256:a4626238126a38824d334cc508f7766a2d8e5f7c8bdc04ba4c7a89fa7bde5a4a" vars.name="abc/xyz" time="2025-04-06T08:09:09.990953914Z" level=info msg="response completed" go.version=go1.19.9 http.request.contenttype="application/json" http.request.host="10.2xx.1xx.1xx:5000" http.request.id=a840414e-1d35-410f-bc1d-25607cf9ce94 http.request.method=POST http.request.remoteaddr="10.2xx.4x.11xx:63048" http.request.uri="/v2/abc/xyz/blobs/uploads/?from=arubadevops%xyz&mount=sha256%3Aa4626238126a38824d334cc508f7766a2d8e5f7c8bdc04ba4c7a89fa7bde5a4a&origin=quay.io" http.request.useragent="crane/0.19.0 go-containerregistry/0.19.0" http.response.duration=77.655911ms http.response.status=202 http.response.written=0 10.211.49.115 - - [06/Apr/2025:08:09:09 +0000] "POST /v2/abc/xyz/blobs/uploads/?from=abc%xyz&mount=sha256%3Aa4626238126a38824d334cc508f7766a2d8e5f7c8bdc04ba4c7a89fa7bde5a4a&origin=quay.io HTTP/2.0" 202 0 "" "crane/0.19.0 go-containerregistry/0.19.0"
We have set the TCP timeouts in kernel
net.ipv4.tcp_keepalive_time = 600 net.ipv4.tcp_keepalive_intvl = 60 net.ipv4.tcp_keepalive_probes = 30
To Reproduce
Expected behavior
A clear and concise description of what you expected to happen.
Additional context
Add any other context about the problem here.
- Output of
crane version - Registry used (e.g., GCR, ECR, Quay)
What could be the issue here?