Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Container registry - layer drops #19586

Closed
PavelMXFox opened this issue May 2, 2022 · 26 comments · May be fixed by #21063
Closed

Container registry - layer drops #19586

PavelMXFox opened this issue May 2, 2022 · 26 comments · May be fixed by #21063

Comments

@PavelMXFox
Copy link

PavelMXFox commented May 2, 2022

Description

Hi!
The layer 4f4fb700ef54461cfa02571ae0db9a0dc1e0cdb5577484a6d75e68dc38e8acc1 is constantly disappearing, it contains 1024 zero-bytes. The 'gitea/packages/4f/4f' folder remains empty. If I upload an archived version of a layer, everything works until any image containing this layer is deleted, and after that the layer disappears. At this time in the gitea logs

2022/05/02 21:50:41 [62702801] router: completed GET /v2/mxfox/fox-web-basic/blobs/sha256:4f4fb700ef54461cfa02571ae0db9a0dc1e0cdb5577484a6d75e68dc38e8acc1 for 217.107.125.158:0, 500 Internal Server Error in 255.8ms @ container/container.go:359(container.GetBlob)

2022/05/02 21:50:42 ...ntainer/container.go:84:api Error() [E] [62702802] open /data/gitea/packages/4f/4f/4f4fb700ef54461cfa02571ae0db9a0dc1e0cdb5577484a6d75e68dc38e8acc1: no such file or directory

I attach a copy of the layer.

Gitea Version

1.17.0+dev-511-g71bafa026

Can you reproduce the bug on the Gitea demo site?

No

Log Gist

No response

Screenshots

No response

Git Version

No response

Operating System

No response

How are you running Gitea?

in docker

Database

MySQL

@PavelMXFox
Copy link
Author

Update - this repeated with other blobs, when pushing other image, contains this blob. Blob's file was removed from FS, but in DB table package_blob row with it presents, and because it blob cant'be re-uploaded with docker push

@PavelMXFox
Copy link
Author

Can't reproduce on [1.17.0+dev-568-gcbd45471b] it seems to be fixed.

@PavelMXFox
Copy link
Author

PavelMXFox commented May 18, 2022

Gitea [1.17.0+dev-587-g9ea920640]
Image layer has been dropeed by registry.

Directory packages/2f/f2 is empty.

if i restore 2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd file from backup - all work fine.

It was when i build && push image with docker buildx
Docker's log

#13 exporting to image
#13 exporting manifest list sha256:42c0b4a9357d56f15b69abfc9e8cc7b3488a62a1f9cb6444d3817afdd75efcb9 0.0s done
#13 pushing layers
#13 3.635 error: failed commit on ref "layer-sha256:fabe278fb707a6ec1d19f0a2eb628261cde71a98b6f00c89cb437a561a5097ac": unexpected status: 500 Internal Server Error
#13 3.635 retrying in 1s
#13 3.668 error: failed commit on ref "layer-sha256:2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd": unexpected status: 500 Internal Server Error

Gitea log

2022/05/18 17:21:27 ...ntainer/container.go:84:apiError() [E] [628500e7-7] open /data/gitea/packages/2f/f2/2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd: no such file or directory
2022/05/18 17:21:27 [628500e7-7] router: completed GET /v2/mxfox/fox-web-basic/blobs/sha256:2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd for __:0, 500 Internal Server Error in 40.0ms @ container/container.go:358(container.GetBlob)
2022/05/18 17:22:58 ...ntainer/container.go:84:apiError() [E] [62850142-4] open /data/gitea/packages/2f/f2/2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd: no such file or directory
2022/05/18 17:22:58 [62850142-4] router: completed GET /v2/mxfox/fox-web-basic/blobs/sha256:2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd for __:0, 500 Internal Server Error in 64.1ms @ container/container.go:358(container.GetBlob)
2022/05/18 17:26:41 ...ntainer/container.go:84:apiError() [E] [62850221-7] open /data/gitea/packages/2f/f2/2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd: no such file or directory
2022/05/18 17:26:41 [62850221-7] router: completed GET /v2/mxfox/fox-web-basic/blobs/sha256:2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd for __:0, 500 Internal Server Error in 76.0ms @ container/container.go:358(container.GetBlob)
2022/05/18 17:26:41 ...ntainer/container.go:84:apiError() [E] [62850221-9] open /data/gitea/packages/2f/f2/2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd: no such file or directory
2022/05/18 17:26:41 [62850221-9] router: completed GET /v2/mxfox/fox-web-basic/blobs/sha256:2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd for __:0, 500 Internal Server Error in 32.3ms @ container/container.go:358(container.GetBlob)
2022/05/18 17:26:46 ...ntainer/container.go:84:apiError() [E] [62850226] open /data/gitea/packages/2f/f2/2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd: no such file or directory
2022/05/18 17:26:46 [62850226] router: completed GET /v2/mxfox/fox-web-basic/blobs/sha256:2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd for __:0, 500 Internal Server Error in 34.1ms @ container/container.go:358(container.GetBlob)
2022/05/18 17:26:46 ...ntainer/container.go:84:apiError() [E] [62850226-2] open /data/gitea/packages/2f/f2/2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd: no such file or directory
2022/05/18 17:26:46 [62850226-2] router: completed GET /v2/mxfox/fox-web-basic/blobs/sha256:2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd for __:0, 500 Internal Server Error in 33.6ms @ container/container.go:358(container.GetBlob)

@PavelMXFox
Copy link
Author

I see series of HTTP500, usually after some layers drop. Now I can't find if something layers are missing, maybe it's a new bug. Just in case, I attach a full push log.

#13 3.925 error: failed commit on ref "layer-sha256:fe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac": unexpected status: 500 Internal Server Error

2022/05/18 20:49:55 [628531c3] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:d4ba87bb7858f0dd4a60003f011338f3a58b87d0add985652856007fe5ca5034 for ____:0, 401 Unauthorized in 0.3ms @ container/container.go:113(container.ReqContainerAccess)
2022/05/18 20:49:55 [628531c3-2] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:fe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac for ____:0, 401 Unauthorized in 0.4ms @ container/container.go:113(container.ReqContainerAccess)
2022/05/18 20:49:55 [628531c3-3] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:659bbfc26a5a93b8010ea6b575f7f0a60cdfe6a80e5e154fde755479d301f0ce for ____:0, 401 Unauthorized in 1.2ms @ container/container.go:113(container.ReqContainerAccess)
2022/05/18 20:49:55 [628531c3-4] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:06ecd50008383f7aac0acd7bb5c8c19dcd0d29df93b12871218dd5cec426d6bd for ____:0, 401 Unauthorized in 0.3ms @ container/container.go:113(container.ReqContainerAccess)
2022/05/18 20:49:55 [628531c3-5] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:39e7b07e7410ac8be4d4d7e7de8a2cf0a214278d15410d6eac5828595ab02085 for ____:0, 401 Unauthorized in 0.4ms @ container/container.go:113(container.ReqContainerAccess)
2022/05/18 20:49:55 [628531c3-6] router: completed POST /v2/token for ____:0, 405 Method Not Allowed in 0.2ms @ packages/api.go:254(packages.ContainerRoutes)
2022/05/18 20:49:55 [628531c3-7] router: completed GET /v2/token?scope=repository%3Amxfox%2Fchimera-mk2-core%3Apull%2Cpush for ____:0, 200 OK in 263.2ms @ container/container.go:137(container.Authenticate)
2022/05/18 20:49:56 [628531c4-4] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:39e7b07e7410ac8be4d4d7e7de8a2cf0a214278d15410d6eac5828595ab02085 for ____:0, 200 OK in 51.0ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-2] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:06ecd50008383f7aac0acd7bb5c8c19dcd0d29df93b12871218dd5cec426d6bd for ____:0, 404 Not Found in 56.6ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:fe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac for ____:0, 404 Not Found in 62.9ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-3] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:d4ba87bb7858f0dd4a60003f011338f3a58b87d0add985652856007fe5ca5034 for ____:0, 200 OK in 75.0ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-6] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:09d6f9eaf28ac33c6e44a860dbefbcbe157ff4a793effb9a7824f6b453a009cd for ____:0, 404 Not Found in 48.2ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-5] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:659bbfc26a5a93b8010ea6b575f7f0a60cdfe6a80e5e154fde755479d301f0ce for ____:0, 200 OK in 58.6ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-8] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ____:0, 202 Accepted in 140.3ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/18 20:49:56 [628531c4-7] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ____:0, 202 Accepted in 249.2ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/18 20:49:56 [628531c4-9] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:02909e51564bd118b45605cf034515fbad616eeb4547d32e8e43c30ce73a507d for ____:0, 200 OK in 258.0ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-10] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ____:0, 202 Accepted in 305.9ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/18 20:49:56 [628531c4-11] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:4f4fb700ef54461cfa02571ae0db9a0dc1e0cdb5577484a6d75e68dc38e8acc1 for ____:0, 200 OK in 434.9ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-16] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd for ____:0, 200 OK in 23.1ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-14] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:82a003d50dff92ab1725d548b14447af15583ee2f475dfb83cb7582b0026f416 for ____:0, 404 Not Found in 401.7ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:57 [628531c4-17] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:70dfc71c1e12e4d8a617313a286212d2b3cd0751c3df8c57e9408048d060d956 for ____:0, 200 OK in 360.5ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:57 [628531c5] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ____:0, 202 Accepted in 285.3ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/18 20:49:57 [628531c5-2] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:d5fd17ec1767521cf97f61568096bfc9a7cd9c2d149576a7b43930c5a97062b0 for ____:0, 200 OK in 23.5ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:57 [628531c4-13] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/k9h6area7tbavls4fewkuetvy?digest=sha256%3A06ecd50008383f7aac0acd7bb5c8c19dcd0d29df93b12871218dd5cec426d6bd for ____:0, 201 Created in 1081.7ms @ container/container.go:264(container.EndUploadBlob)
2022/05/18 20:49:57 ...es/container/blob.go:56:func1() [E] [628531c4-12] Error inserting package: Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s'
2022/05/18 20:49:57 ...es/container/blob.go:56:func1() [E] [628531c4-15] Error inserting package: Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s'
2022/05/18 20:49:57 [628531c4-15] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/ro1rkcdp1ib4awzbummsl24oc?digest=sha256%3A09d6f9eaf28ac33c6e44a860dbefbcbe157ff4a793effb9a7824f6b453a009cd for ____:0, 500 Internal Server Error in 1077.3ms @ container/container.go:264(container.EndUploadBlob)
2022/05/18 20:49:57 [628531c4-12] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/dl0e8ctrfrwh1jiu7i6a403y1?digest=sha256%3Afe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac for ____:0, 500 Internal Server Error in 1256.4ms @ container/container.go:264(container.EndUploadBlob)
2022/05/18 20:49:57 ...ntainer/container.go:84:apiError() [E] [628531c4-15] Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s'
2022/05/18 20:49:57 ...ntainer/container.go:84:apiError() [E] [628531c4-12] Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s'
2022/05/18 20:49:58 [628531c6] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:09d6f9eaf28ac33c6e44a860dbefbcbe157ff4a793effb9a7824f6b453a009cd for ____:0, 404 Not Found in 57.5ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:58 [628531c6-2] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:fe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac for ____:0, 404 Not Found in 88.8ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:59 [628531c6-3] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ____:0, 202 Accepted in 66.6ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/18 20:49:59 [628531c6-4] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ____:0, 202 Accepted in 51.5ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/18 20:49:59 [628531c7] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/95o8db7u0w9snfrt7itn8h5vh?digest=sha256%3A09d6f9eaf28ac33c6e44a860dbefbcbe157ff4a793effb9a7824f6b453a009cd for ____:0, 201 Created in 332.7ms @ container/container.go:264(container.EndUploadBlob)
2022/05/18 20:49:59 [628531c7-2] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/acdmgf4ph173eyp5jcqrgllqk?digest=sha256%3Afe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac for ____:0, 201 Created in 390.7ms @ container/container.go:264(container.EndUploadBlob)
2022/05/18 20:49:59 [628531c5-3] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/ab3ohnddvqlltk8ddwffmxgd4?digest=sha256%3A82a003d50dff92ab1725d548b14447af15583ee2f475dfb83cb7582b0026f416 for ____:0, 201 Created in 2063.3ms @ container/container.go:264(container.EndUploadBlob)
2022/05/18 20:50:00 [628531c8] router: completed HEAD /v2/mxfox/chimera-mk2-core/manifests/sha256:6c8411bdc95928eb58cceca5a543cd0c9137383f48b0d3fa03b41afee57548a6 for ____:0, 404 Not Found in 21.5ms @ container/container.go:477(container.HeadManifest)
2022/05/18 20:50:00 [628531c8-2] router: completed PUT /v2/mxfox/chimera-mk2-core/manifests/sha256:6c8411bdc95928eb58cceca5a543cd0c9137383f48b0d3fa03b41afee57548a6 for ____:0, 201 Created in 380.9ms @ container/container.go:407(container.UploadManifest)
2022/05/18 20:50:00 [628531c8-3] router: completed HEAD /v2/mxfox/chimera-mk2-core/manifests/sha256:d9ef2c79f420f4b83129d006441d00286e3f1a696266b4ef6e97c2017c898662 for ____:0, 404 Not Found in 20.9ms @ container/container.go:477(container.HeadManifest)
2022/05/18 20:50:01 [628531c8-4] router: completed PUT /v2/mxfox/chimera-mk2-core/manifests/sha256:d9ef2c79f420f4b83129d006441d00286e3f1a696266b4ef6e97c2017c898662 for ____:0, 201 Created in 364.4ms @ container/container.go:407(container.UploadManifest)
2022/05/18 20:50:01 [628531c9] router: completed HEAD /v2/mxfox/chimera-mk2-core/manifests/testing-2-c69e9a8f0a for ____:0, 404 Not Found in 19.7ms @ container/container.go:477(container.HeadManifest)
2022/05/18 20:50:01 [628531c9-2] router: completed PUT /v2/mxfox/chimera-mk2-core/manifests/testing-2-c69e9a8f0a for ____:0, 201 Created in 111.9ms @ container/container.go:407(container.UploadManifest)
2022/05/18 20:50:01 [628531c9-4] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:82a003d50dff92ab1725d548b14447af15583ee2f475dfb83cb7582b0026f416 for ____:0, 200 OK in 77.3ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-5] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:d4ba87bb7858f0dd4a60003f011338f3a58b87d0add985652856007fe5ca5034 for ____:0, 200 OK in 86.0ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-3] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:02909e51564bd118b45605cf034515fbad616eeb4547d32e8e43c30ce73a507d for ____:0, 200 OK in 100.8ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-6] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:06ecd50008383f7aac0acd7bb5c8c19dcd0d29df93b12871218dd5cec426d6bd for ____:0, 200 OK in 101.7ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-7] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:70dfc71c1e12e4d8a617313a286212d2b3cd0751c3df8c57e9408048d060d956 for ____:0, 200 OK in 96.9ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-8] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:09d6f9eaf28ac33c6e44a860dbefbcbe157ff4a793effb9a7824f6b453a009cd for ____:0, 200 OK in 77.2ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-10] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:fe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac for ____:0, 200 OK in 66.7ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-9] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:659bbfc26a5a93b8010ea6b575f7f0a60cdfe6a80e5e154fde755479d301f0ce for ____:0, 200 OK in 81.1ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-12] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd for ____:0, 200 OK in 40.2ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-11] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:4f4fb700ef54461cfa02571ae0db9a0dc1e0cdb5577484a6d75e68dc38e8acc1 for ____:0, 200 OK in 91.5ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-13] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:d5fd17ec1767521cf97f61568096bfc9a7cd9c2d149576a7b43930c5a97062b0 for ____:0, 200 OK in 34.7ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-14] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:39e7b07e7410ac8be4d4d7e7de8a2cf0a214278d15410d6eac5828595ab02085 for ____:0, 200 OK in 36.8ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-15] router: completed HEAD /v2/mxfox/chimera-mk2-core/manifests/sha256:d9ef2c79f420f4b83129d006441d00286e3f1a696266b4ef6e97c2017c898662 for ____:0, 200 OK in 28.4ms @ container/container.go:477(container.HeadManifest)
2022/05/18 20:50:01 [628531c9-16] router: completed HEAD /v2/mxfox/chimera-mk2-core/manifests/sha256:6c8411bdc95928eb58cceca5a543cd0c9137383f48b0d3fa03b41afee57548a6 for ____:0, 200 OK in 22.7ms @ container/container.go:477(container.HeadManifest)
2022/05/18 20:50:02 [628531ca] router: completed HEAD /v2/mxfox/chimera-mk2-core/manifests/testing for ____:0, 200 OK in 21.8ms @ container/container.go:477(container.HeadManifest)
2022/05/18 20:50:02 [628531ca-2] router: completed PUT /v2/mxfox/chimera-mk2-core/manifests/testing for ____:0, 201 Created in 295.6ms @ container/container.go:407(container.UploadManifest)
2022/05/18 20:50:06 [628531ce] router: completed POST /api/v1/repos/Chimera.Mark2/core/statuses/c69e9a8f0a5e35a40d292466236c12740c9db5e2 for ____:0, 201 Created in 345.8ms @ repo/status.go:21(repo.NewCommitStatus)

@lunny
Copy link
Member

lunny commented May 19, 2022

I see series of HTTP500, usually after some layers drop. Now I can't find if something layers are missing, maybe it's a new bug. Just in case, I attach a full push log.

#13 3.925 error: failed commit on ref "layer-sha256:fe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac": unexpected status: 500 Internal Server Error

2022/05/18 20:49:55 [628531c3] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:d4ba87bb7858f0dd4a60003f011338f3a58b87d0add985652856007fe5ca5034 for ____:0, 401 Unauthorized in 0.3ms @ container/container.go:113(container.ReqContainerAccess)
2022/05/18 20:49:55 [628531c3-2] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:fe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac for ____:0, 401 Unauthorized in 0.4ms @ container/container.go:113(container.ReqContainerAccess)
2022/05/18 20:49:55 [628531c3-3] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:659bbfc26a5a93b8010ea6b575f7f0a60cdfe6a80e5e154fde755479d301f0ce for ____:0, 401 Unauthorized in 1.2ms @ container/container.go:113(container.ReqContainerAccess)
2022/05/18 20:49:55 [628531c3-4] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:06ecd50008383f7aac0acd7bb5c8c19dcd0d29df93b12871218dd5cec426d6bd for ____:0, 401 Unauthorized in 0.3ms @ container/container.go:113(container.ReqContainerAccess)
2022/05/18 20:49:55 [628531c3-5] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:39e7b07e7410ac8be4d4d7e7de8a2cf0a214278d15410d6eac5828595ab02085 for ____:0, 401 Unauthorized in 0.4ms @ container/container.go:113(container.ReqContainerAccess)
2022/05/18 20:49:55 [628531c3-6] router: completed POST /v2/token for ____:0, 405 Method Not Allowed in 0.2ms @ packages/api.go:254(packages.ContainerRoutes)
2022/05/18 20:49:55 [628531c3-7] router: completed GET /v2/token?scope=repository%3Amxfox%2Fchimera-mk2-core%3Apull%2Cpush for ____:0, 200 OK in 263.2ms @ container/container.go:137(container.Authenticate)
2022/05/18 20:49:56 [628531c4-4] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:39e7b07e7410ac8be4d4d7e7de8a2cf0a214278d15410d6eac5828595ab02085 for ____:0, 200 OK in 51.0ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-2] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:06ecd50008383f7aac0acd7bb5c8c19dcd0d29df93b12871218dd5cec426d6bd for ____:0, 404 Not Found in 56.6ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:fe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac for ____:0, 404 Not Found in 62.9ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-3] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:d4ba87bb7858f0dd4a60003f011338f3a58b87d0add985652856007fe5ca5034 for ____:0, 200 OK in 75.0ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-6] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:09d6f9eaf28ac33c6e44a860dbefbcbe157ff4a793effb9a7824f6b453a009cd for ____:0, 404 Not Found in 48.2ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-5] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:659bbfc26a5a93b8010ea6b575f7f0a60cdfe6a80e5e154fde755479d301f0ce for ____:0, 200 OK in 58.6ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-8] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ____:0, 202 Accepted in 140.3ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/18 20:49:56 [628531c4-7] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ____:0, 202 Accepted in 249.2ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/18 20:49:56 [628531c4-9] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:02909e51564bd118b45605cf034515fbad616eeb4547d32e8e43c30ce73a507d for ____:0, 200 OK in 258.0ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-10] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ____:0, 202 Accepted in 305.9ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/18 20:49:56 [628531c4-11] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:4f4fb700ef54461cfa02571ae0db9a0dc1e0cdb5577484a6d75e68dc38e8acc1 for ____:0, 200 OK in 434.9ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-16] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd for ____:0, 200 OK in 23.1ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:56 [628531c4-14] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:82a003d50dff92ab1725d548b14447af15583ee2f475dfb83cb7582b0026f416 for ____:0, 404 Not Found in 401.7ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:57 [628531c4-17] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:70dfc71c1e12e4d8a617313a286212d2b3cd0751c3df8c57e9408048d060d956 for ____:0, 200 OK in 360.5ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:57 [628531c5] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ____:0, 202 Accepted in 285.3ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/18 20:49:57 [628531c5-2] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:d5fd17ec1767521cf97f61568096bfc9a7cd9c2d149576a7b43930c5a97062b0 for ____:0, 200 OK in 23.5ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:57 [628531c4-13] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/k9h6area7tbavls4fewkuetvy?digest=sha256%3A06ecd50008383f7aac0acd7bb5c8c19dcd0d29df93b12871218dd5cec426d6bd for ____:0, 201 Created in 1081.7ms @ container/container.go:264(container.EndUploadBlob)
2022/05/18 20:49:57 ...es/container/blob.go:56:func1() [E] [628531c4-12] Error inserting package: Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s'
2022/05/18 20:49:57 ...es/container/blob.go:56:func1() [E] [628531c4-15] Error inserting package: Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s'
2022/05/18 20:49:57 [628531c4-15] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/ro1rkcdp1ib4awzbummsl24oc?digest=sha256%3A09d6f9eaf28ac33c6e44a860dbefbcbe157ff4a793effb9a7824f6b453a009cd for ____:0, 500 Internal Server Error in 1077.3ms @ container/container.go:264(container.EndUploadBlob)
2022/05/18 20:49:57 [628531c4-12] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/dl0e8ctrfrwh1jiu7i6a403y1?digest=sha256%3Afe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac for ____:0, 500 Internal Server Error in 1256.4ms @ container/container.go:264(container.EndUploadBlob)
2022/05/18 20:49:57 ...ntainer/container.go:84:apiError() [E] [628531c4-15] Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s'
2022/05/18 20:49:57 ...ntainer/container.go:84:apiError() [E] [628531c4-12] Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s'
2022/05/18 20:49:58 [628531c6] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:09d6f9eaf28ac33c6e44a860dbefbcbe157ff4a793effb9a7824f6b453a009cd for ____:0, 404 Not Found in 57.5ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:58 [628531c6-2] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:fe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac for ____:0, 404 Not Found in 88.8ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:49:59 [628531c6-3] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ____:0, 202 Accepted in 66.6ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/18 20:49:59 [628531c6-4] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ____:0, 202 Accepted in 51.5ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/18 20:49:59 [628531c7] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/95o8db7u0w9snfrt7itn8h5vh?digest=sha256%3A09d6f9eaf28ac33c6e44a860dbefbcbe157ff4a793effb9a7824f6b453a009cd for ____:0, 201 Created in 332.7ms @ container/container.go:264(container.EndUploadBlob)
2022/05/18 20:49:59 [628531c7-2] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/acdmgf4ph173eyp5jcqrgllqk?digest=sha256%3Afe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac for ____:0, 201 Created in 390.7ms @ container/container.go:264(container.EndUploadBlob)
2022/05/18 20:49:59 [628531c5-3] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/ab3ohnddvqlltk8ddwffmxgd4?digest=sha256%3A82a003d50dff92ab1725d548b14447af15583ee2f475dfb83cb7582b0026f416 for ____:0, 201 Created in 2063.3ms @ container/container.go:264(container.EndUploadBlob)
2022/05/18 20:50:00 [628531c8] router: completed HEAD /v2/mxfox/chimera-mk2-core/manifests/sha256:6c8411bdc95928eb58cceca5a543cd0c9137383f48b0d3fa03b41afee57548a6 for ____:0, 404 Not Found in 21.5ms @ container/container.go:477(container.HeadManifest)
2022/05/18 20:50:00 [628531c8-2] router: completed PUT /v2/mxfox/chimera-mk2-core/manifests/sha256:6c8411bdc95928eb58cceca5a543cd0c9137383f48b0d3fa03b41afee57548a6 for ____:0, 201 Created in 380.9ms @ container/container.go:407(container.UploadManifest)
2022/05/18 20:50:00 [628531c8-3] router: completed HEAD /v2/mxfox/chimera-mk2-core/manifests/sha256:d9ef2c79f420f4b83129d006441d00286e3f1a696266b4ef6e97c2017c898662 for ____:0, 404 Not Found in 20.9ms @ container/container.go:477(container.HeadManifest)
2022/05/18 20:50:01 [628531c8-4] router: completed PUT /v2/mxfox/chimera-mk2-core/manifests/sha256:d9ef2c79f420f4b83129d006441d00286e3f1a696266b4ef6e97c2017c898662 for ____:0, 201 Created in 364.4ms @ container/container.go:407(container.UploadManifest)
2022/05/18 20:50:01 [628531c9] router: completed HEAD /v2/mxfox/chimera-mk2-core/manifests/testing-2-c69e9a8f0a for ____:0, 404 Not Found in 19.7ms @ container/container.go:477(container.HeadManifest)
2022/05/18 20:50:01 [628531c9-2] router: completed PUT /v2/mxfox/chimera-mk2-core/manifests/testing-2-c69e9a8f0a for ____:0, 201 Created in 111.9ms @ container/container.go:407(container.UploadManifest)
2022/05/18 20:50:01 [628531c9-4] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:82a003d50dff92ab1725d548b14447af15583ee2f475dfb83cb7582b0026f416 for ____:0, 200 OK in 77.3ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-5] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:d4ba87bb7858f0dd4a60003f011338f3a58b87d0add985652856007fe5ca5034 for ____:0, 200 OK in 86.0ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-3] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:02909e51564bd118b45605cf034515fbad616eeb4547d32e8e43c30ce73a507d for ____:0, 200 OK in 100.8ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-6] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:06ecd50008383f7aac0acd7bb5c8c19dcd0d29df93b12871218dd5cec426d6bd for ____:0, 200 OK in 101.7ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-7] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:70dfc71c1e12e4d8a617313a286212d2b3cd0751c3df8c57e9408048d060d956 for ____:0, 200 OK in 96.9ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-8] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:09d6f9eaf28ac33c6e44a860dbefbcbe157ff4a793effb9a7824f6b453a009cd for ____:0, 200 OK in 77.2ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-10] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:fe18631e174dd7b4a8a9da2f7a7f1f3fb8f40a658bda2c3934612b08d01a1aac for ____:0, 200 OK in 66.7ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-9] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:659bbfc26a5a93b8010ea6b575f7f0a60cdfe6a80e5e154fde755479d301f0ce for ____:0, 200 OK in 81.1ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-12] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd for ____:0, 200 OK in 40.2ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-11] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:4f4fb700ef54461cfa02571ae0db9a0dc1e0cdb5577484a6d75e68dc38e8acc1 for ____:0, 200 OK in 91.5ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-13] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:d5fd17ec1767521cf97f61568096bfc9a7cd9c2d149576a7b43930c5a97062b0 for ____:0, 200 OK in 34.7ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-14] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:39e7b07e7410ac8be4d4d7e7de8a2cf0a214278d15410d6eac5828595ab02085 for ____:0, 200 OK in 36.8ms @ container/container.go:339(container.HeadBlob)
2022/05/18 20:50:01 [628531c9-15] router: completed HEAD /v2/mxfox/chimera-mk2-core/manifests/sha256:d9ef2c79f420f4b83129d006441d00286e3f1a696266b4ef6e97c2017c898662 for ____:0, 200 OK in 28.4ms @ container/container.go:477(container.HeadManifest)
2022/05/18 20:50:01 [628531c9-16] router: completed HEAD /v2/mxfox/chimera-mk2-core/manifests/sha256:6c8411bdc95928eb58cceca5a543cd0c9137383f48b0d3fa03b41afee57548a6 for ____:0, 200 OK in 22.7ms @ container/container.go:477(container.HeadManifest)
2022/05/18 20:50:02 [628531ca] router: completed HEAD /v2/mxfox/chimera-mk2-core/manifests/testing for ____:0, 200 OK in 21.8ms @ container/container.go:477(container.HeadManifest)
2022/05/18 20:50:02 [628531ca-2] router: completed PUT /v2/mxfox/chimera-mk2-core/manifests/testing for ____:0, 201 Created in 295.6ms @ container/container.go:407(container.UploadManifest)
2022/05/18 20:50:06 [628531ce] router: completed POST /api/v1/repos/Chimera.Mark2/core/statuses/c69e9a8f0a5e35a40d292466236c12740c9db5e2 for ____:0, 201 Created in 345.8ms @ repo/status.go:21(repo.NewCommitStatus)

Could you enable dev mode in app.ini so that more detail could be displayed.

@wxiaoguang
Copy link
Contributor

The problem is caused by concurrency requests to database.

In TryInsertPackage/GetOrInsertVersion: Get -> Insert.

Then insert can trigger Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s' error.

@PavelMXFox
Copy link
Author

Could you enable dev mode in app.ini so that more detail could be displayed.

Ok

@PavelMXFox
Copy link
Author

Hi! With mode=dev.

This appears every time while building cross-platform images with docker buildx. In this build i can't find if any layes drop yet.

Builder log:

#13 4.946 error: failed commit on ref "config-sha256:cf6b0ada9237ffe1fc7a102a6bb21b71034125cb7b2b8d1eeaad8401b8f235ce": unexpected status: 500 Internal Server Error
#13 4.946 retrying in 1s
#13 4.981 error: failed commit on ref "layer-sha256:df4525ed1afc13237ff175f81e53b89e96bbc171bc69940015055e8950362733": unexpected status: 500 Internal Server Error
#13 4.981 retrying in 1s
#13 pushing layers 6.1s done
#13 pushing manifest for mxfox.ru/mxfox/chimera-mk2-core:testing-13-c163e1fa67@sha256:6eda7fb374665a5af6e0420cfa00b017eed96e90a16b17a6aa229abceb137a18
#13 pushing manifest for mxfox.ru/mxfox/chimera-mk2-core:testing-13-c163e1fa67@sha256:6eda7fb374665a5af6e0420cfa00b017eed96e90a16b17a6aa229abceb137a18 1.5s done

Gitea log:

2022/05/21 19:30:48 [628913b7-9] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:2ff2e940e73e30a29749f6cdec49203aa1d1a94b30b59988ce6288e14b836fcd for ******:0, 200 OK in 322.6ms @ container/container.go:339(container.HeadBlob)
2022/05/21 19:30:48 [628913b7-6] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ******:0, 202 Accepted in 533.4ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/21 19:30:48 [628913b8] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:d5fd17ec1767521cf97f61568096bfc9a7cd9c2d149576a7b43930c5a97062b0 for ******:0, 200 OK in 22.7ms @ container/container.go:339(container.HeadBlob)
2022/05/21 19:30:48 [628913b8-3] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:c48a9434d528936656b47c42a842d7f02e61faad1b171854f6d039e8b75fac58 for ******:0, 404 Not Found in 19.8ms @ container/container.go:339(container.HeadBlob)
2022/05/21 19:30:48 [628913b8-4] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ******:0, 202 Accepted in 134.6ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/21 19:30:49 [628913b7-10] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/zetdy8kdtulde2thozhbrr8bj?digest=sha256%3A08cf0fa824af0bf647cefc1557e94b9d375a5c8afc6d14e30e6b813d0d2249fe for ******:0, 201 Created in 1302.0ms @ container/container.go:264(container.EndUploadBlob)
2022/05/21 19:30:49 ...es/container/blob.go:56:func1() [E] [628913b7-11] Error inserting package: Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s'
2022/05/21 19:30:49 ...es/container/blob.go:56:func1() [E] [628913b8-2] Error inserting package: Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s'
2022/05/21 19:30:49 ...ntainer/container.go:84:apiError() [E] [628913b7-11] Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s'
2022/05/21 19:30:49 [628913b7-11] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/sp450bclryqfnguivtgcdkja9?digest=sha256%3Acf6b0ada9237ffe1fc7a102a6bb21b71034125cb7b2b8d1eeaad8401b8f235ce for ******:0, 500 Internal Server Error in 1407.4ms @ container/container.go:264(container.EndUploadBlob)
2022/05/21 19:30:49 [628913b9-2] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:39e7b07e7410ac8be4d4d7e7de8a2cf0a214278d15410d6eac5828595ab02085 for ******:0, 200 OK in 75.5ms @ container/container.go:339(container.HeadBlob)
2022/05/21 19:30:49 ...ntainer/container.go:84:apiError() [E] [628913b8-2] Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s'
2022/05/21 19:30:49 [628913b8-2] router: completed PUT /v2/mxfox/chimera-mk2-core/blobs/uploads/8lmlkch8ui3qjqobu7j188i6f?digest=sha256%3Adf4525ed1afc13237ff175f81e53b89e96bbc171bc69940015055e8950362733 for ******:0, 500 Internal Server Error in 1080.2ms @ container/container.go:264(container.EndUploadBlob)
2022/05/21 19:30:50 [628913ba] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:cf6b0ada9237ffe1fc7a102a6bb21b71034125cb7b2b8d1eeaad8401b8f235ce for ******:0, 404 Not Found in 43.8ms @ container/container.go:339(container.HeadBlob)
2022/05/21 19:30:50 [628913ba-2] router: completed HEAD /v2/mxfox/chimera-mk2-core/blobs/sha256:df4525ed1afc13237ff175f81e53b89e96bbc171bc69940015055e8950362733 for ******:0, 404 Not Found in 39.6ms @ container/container.go:339(container.HeadBlob)
2022/05/21 19:30:50 [628913ba-4] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ******:0, 202 Accepted in 67.0ms @ container/container.go:157(container.InitiateUploadBlob)
2022/05/21 19:30:50 [628913ba-3] router: completed POST /v2/mxfox/chimera-mk2-core/blobs/uploads/ for ******:0, 202 Accepted in 122.4ms @ container/container.go:157(container.InitiateUploadBlob)

@ChromoX
Copy link

ChromoX commented Jul 12, 2022

I'm experiencing this problem on v1.17.0-rc1, running on Kubernetes.

I have this symptom: #19586 (comment)

@markrexwinkel
Copy link

I also experienced this issue with v1.17.0-rc1. When configuring Docker or Podman to use just one thread it works fine, as soon as you configure more parallel threads to push the container layers, error 500 appears. So it seems like a concurrency issue.

@lunny lunny added this to the 1.17.1 milestone Jul 31, 2022
@zeripath zeripath modified the milestones: 1.17.1, 1.17.2 Aug 17, 2022
@Taha-Firoz
Copy link

I also experienced this issue with v1.17.0-rc1. When configuring Docker or Podman to use just one thread it works fine, as soon as you configure more parallel threads to push the container layers, error 500 appears. So it seems like a concurrency issue.

nope not a concurrency issue, just tried this, max_concurrent_uploads: 1 still leads to 500 error

@zeripath
Copy link
Contributor

zeripath commented Sep 4, 2022

The problem is caused by concurrency requests to database.

In TryInsertPackage/GetOrInsertVersion: Get -> Insert.

Then insert can trigger Error 1062: Duplicate entry '10-_upload' for key 'UQE_package_version_s' error.

I think this might solve the issue but I'm not sure if it's gonna cause the whole transaction to fail instead.

diff --git a/models/packages/package.go b/models/packages/package.go
index e39a7c4e4..f9bd6c765 100644
--- a/models/packages/package.go
+++ b/models/packages/package.go
@@ -128,14 +128,11 @@ func TryInsertPackage(ctx context.Context, p *Package) (*Package, error) {
 		LowerName: p.LowerName,
 	}
 
-	has, err := e.Get(key)
-	if err != nil {
-		return nil, err
-	}
-	if has {
-		return key, ErrDuplicatePackage
-	}
-	if _, err = e.Insert(p); err != nil {
+	if _, err := e.Insert(p); err != nil {
+		// Try to get the key again
+		if has, _ := e.Get(key); has {
+			return key, ErrDuplicatePackage
+		}
 		return nil, err
 	}
 	return p, nil

Another option is to parse the error returned back.

@zeripath
Copy link
Contributor

zeripath commented Sep 4, 2022

nope not a concurrency issue, just tried this, max_concurrent_uploads: 1 still leads to 500 error

It IS a concurrency issue - just an internal concurrency issue to do with transactional isolation etc.

The TryInsert* functions are incorrect depending on the transactional isolation level within the database.

zeripath added a commit to zeripath/gitea that referenced this issue Sep 4, 2022
The TryInsert* functions within the packages models make incorrect assumptions
about transactional isolation within most databases. It is perfectly possible for
a SELECT to return nothing but an INSERT fail with a duplicate in most DBs as it
is only INSERT that the locking occurs.

This PR changes the code to simply try to insert first and if there is an error
then attempt to SELECT from the table. If the SELECT works then the INSERT error
is assumed to have been related to the unique constraint failure.

This technique avoids us having to parse the error returned from the DBs as
these are varied and different.

If the SELECT fails then the INSERT error is returned to the user.

Fix go-gitea#19586

Signed-off-by: Andrew Thornton <art27@cantab.net>
@lunny lunny modified the milestones: 1.17.2, 1.17.3 Sep 5, 2022
@Taha-Firoz
Copy link

nope not a concurrency issue, just tried this, max_concurrent_uploads: 1 still leads to 500 error

It IS a concurrency issue - just an internal concurrency issue to do with transactional isolation etc.

The TryInsert* functions are incorrect depending on the transactional isolation level within the database.

But why won't any subsequent pushes work? I've tried many times and basically every second or third image pushed has a dropped layer in it. The database reports the layer exists but the layer doesn't exist in the FS, shouldn't there be some amount of validation.

@davidhiendl
Copy link

I've experienced this problem when testing a new Gitea instance in different configurations:

  • with local FS storage
  • with S3 storage
  • with Postgres
  • with SQLite

The result appears to be the same: Image pushes mostly fail, retrying them sometimes works. This occurred for a variety of public and private images.

Is there a workaround for this issue available? Would building Gitea + the TryInsert PR help?

@fcwoknhenuxdfiyv
Copy link

It seems some layers are being silently dropped when pushing. When pulling a recently pushed image it kept getting stuck retrying one particular layer.

I checked the contents of the named volume and there is nothing in the bl/ob/blobhash tree. Not even the bl directory exists.

I did a push to an instance of the official Docker registry:2 and then copied the layer to bl/ob/blobhash and pulled successfully from GT.

@PavelMXFox
Copy link
Author

It seems some layers are being silently dropped when pushing. When pulling a recently pushed image it kept getting stuck retrying one particular layer.

I checked the contents of the named volume and there is nothing in the bl/ob/blobhash tree. Not even the bl directory exists.

I did a push to an instance of the official Docker registry:2 and then copied the layer to bl/ob/blobhash and pulled successfully from GT.

Hi, I did the same - recover layer file from backup. Image pull become sucessfull but after some pushes with this layer - it drops again.

@Taha-Firoz
Copy link

It seems some layers are being silently dropped when pushing. When pulling a recently pushed image it kept getting stuck retrying one particular layer.

I checked the contents of the named volume and there is nothing in the bl/ob/blobhash tree. Not even the bl directory exists.

I did a push to an instance of the official Docker registry:2 and then copied the layer to bl/ob/blobhash and pulled successfully from GT.

I'm not sure but it's probably because it doesn't actually check the fs but just checks the database if this layer was ever added. If the database has it recorded it assumes it exists. There really should be a fs check added in their too along with the database one to make sure this problem doesn't come up again.

@KN4CK3R
Copy link
Member

KN4CK3R commented Nov 16, 2022

Copy from https://codeberg.org/woodpecker-plugins/plugin-docker-buildx/issues/42

--

What I think the problem with two uploads uploading the same file is:

  1. Upload 1 starts uploading the blob. This starts a database transaction and creates the database entries.
  2. Upload 2 starts uploading the blob. This starts a database transaction and creates the database entries.
  3. Upload 1 writes the blob into the file storage.
  4. Upload 2 writes the blob into the file storage.
  5. Upload 2 finishes and commits the transaction.
  6. Upload 1 finishes and tries to commit the transaction. This fails because the unique database entries are already present. This signals an error to remove the blob from the file storage because the reference entries from Upload 1 were not created.

Now we have valid database entries from Upload 2 but the blob in the file storage is missing. Every upload afterwards is skipped because the deduplication checks if the blob hash is already present. This does not check the file storage layer because there should be never a missing blob. So a reupload is only possible after all packages which reference this blob are deleted and the registry clean up job removes the unreferenced blob entries.

lunny added a commit that referenced this issue Nov 25, 2022
This PR addresses #19586

I added a mutex to the upload version creation which will prevent the
push errors when two requests try to create these database entries. I'm
not sure if this should be the final solution for this problem.

I added a workaround to allow a reupload of missing blobs. Normally a
reupload is skipped because the database knows the blob is already
present. The workaround checks if the blob exists on the file system.
This should not be needed anymore with the above fix so I marked this
code to be removed with Gitea v1.20.

Co-authored-by: Lunny Xiao <xiaolunwen@gmail.com>
KN4CK3R added a commit to KN4CK3R/gitea that referenced this issue Dec 8, 2022
This PR addresses go-gitea#19586

I added a mutex to the upload version creation which will prevent the
push errors when two requests try to create these database entries. I'm
not sure if this should be the final solution for this problem.

I added a workaround to allow a reupload of missing blobs. Normally a
reupload is skipped because the database knows the blob is already
present. The workaround checks if the blob exists on the file system.
This should not be needed anymore with the above fix so I marked this
code to be removed with Gitea v1.20.

Co-authored-by: Lunny Xiao <xiaolunwen@gmail.com>
KN4CK3R added a commit to KN4CK3R/gitea that referenced this issue Dec 8, 2022
This PR addresses go-gitea#19586

I added a mutex to the upload version creation which will prevent the
push errors when two requests try to create these database entries. I'm
not sure if this should be the final solution for this problem.

I added a workaround to allow a reupload of missing blobs. Normally a
reupload is skipped because the database knows the blob is already
present. The workaround checks if the blob exists on the file system.
This should not be needed anymore with the above fix so I marked this
code to be removed with Gitea v1.20.

Co-authored-by: Lunny Xiao <xiaolunwen@gmail.com>
@Fogapod
Copy link
Contributor

Fogapod commented Dec 9, 2022

I've got this issue again today: #21736
Gitea 1.17.3, local installation, postgres.

gitea[123269]: 2022/12/09 06:23:46 ...ntainer/container.go:84:apiError() [E] [6392d472] open /var/lib/gitea/data/packages/c5/1d/c51da6ab853721f149e9dea36102d7aabe02e0958ad199661066c851e391ede2: no such file or directory

What are the steps to fix this? Last time I had to write a script to delete all docker packages in instance because web ui on 1.17 only allows deleting a single version. Is there a way to tell which version hash c51da6ab853721f149e9dea36102d7aabe02e0958ad199661066c851e391ede2 corresponds to?

Luckily there were only a few versions and I could delete them by hand then run package cleanup. But if other packages referenced same has it would be much harder to fix

@Fogapod
Copy link
Contributor

Fogapod commented Dec 9, 2022

Deleting blob from postgres table as suggested in my issue did work after package was pushed again:

 delete from package_blob where hash_sha256 = 'c51da6ab853721f149e9dea36102d7aabe02e0958ad199661066c851e391ede2';
DELETE 1

@Fogapod
Copy link
Contributor

Fogapod commented Dec 9, 2022

I don't think this was caused by concurrent pushes. I am running a small instance with only a few docker containers. All containers are pushed by drone.
Corrupted repository has this setting in release pipeline:

concurrency:
  limit: 1

and a few steps before / after docker push. Also none other docker builds were running at that time in drone

@KN4CK3R
Copy link
Member

KN4CK3R commented Dec 9, 2022

concurrency:
  limit: 1

is a pipeline setting and not a docker setting.

@Fogapod
Copy link
Contributor

Fogapod commented Dec 9, 2022

is a pipeline setting and not a docker setting.

it is. my point is that it could never push concurrently. and after checking all runs around that time there were gaps in 10/20 mins between any docker pushes

@lunny lunny modified the milestones: 1.17.4, 1.17.5 Dec 21, 2022
@KN4CK3R KN4CK3R closed this as completed Dec 29, 2022
@johnmarksilly
Copy link

@KN4CK3R What is the fix for this? I get this all the time and on push, some layers show a retry at least once.

@KN4CK3R
Copy link
Member

KN4CK3R commented Apr 13, 2023

This is fixed since Gitea 1.17.4 (#21862)

@go-gitea go-gitea locked and limited conversation to collaborators Apr 13, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

Successfully merging a pull request may close this issue.