search

goharbor / harbor

An open source trusted cloud native registry project that stores, signs, and scans content.
https://goharbor.io
Apache License 2.0
23.83k stars 4.74k forks source link

Sometimes pushing an image from a Docker client to a harbor fails. #20687

Open Satoshi-Hirai371 opened 3 months ago

Satoshi-Hirai371 commented 3 months ago

Expected behavior and actual behavior: Sometimes pushing an image from a Docker client to a harbor fails. This operation is expected to push normally, but can you identify the cause from the command output and log shown below?

Steps to reproduce the problem: It may fail when pushing images of several GiB.

Versions: Please specify the versions of following systems.

Additional context:

In the Docker CLI, the push is retried once and then failed.

Docker CLI Output：

       [2024-06-27 13:01:31.995] docker push xxx.com:80/project/image111:1.0.0 & date ;
       [2024-06-27 13:01:50.015] [1] 16398
       (snip)
       [2024-06-27 13:01:50.043] The push refers to repository [xxx.com:80/project/image111]
       (snip)
       [2024-06-27 13:28:31.533] 38752ecc8cf2: Pushing [==================================================>]  4.297GB
       [2024-06-27 13:30:50.199]
       [2024-06-27 13:30:50.199] 25a29bff668e: Retrying in 5 seconds
       [2024-06-27 13:30:51.200]
       [2024-06-27 13:30:51.200] 25a29bff668e: Retrying in 4 seconds
       [2024-06-27 13:30:52.199]
       [2024-06-27 13:30:52.199] 25a29bff668e: Retrying in 3 seconds
       [2024-06-27 13:30:53.200]
       [2024-06-27 13:30:53.200] 25a29bff668e: Retrying in 2 seconds
       [2024-06-27 13:30:54.198]
       [2024-06-27 13:30:54.198] 25a29bff668e: Retrying in 1 second
       (snip)
       [2024-06-27 14:09:15.053] unauthorized: unauthorized to access repository: project/image111, action: push: unauthorized to access repository: project/image111, action: push

The Docker service was experiencing Timeout with the following message.

docker.service：
       Jun 27 04:30:49 hostname dockerd[15943]: time="2024-06-27T04:30:49.402608879Z" level=error msg="Upload failed, retrying: received unexpected HTTP status:504 Gateway Timeout"
       Jun 27 04:34:12 hostname dockerd[15943]: time="2024-06-27T04:34:12.738471545Z" level=error msg="Upload failed, retrying: received unexpected HTTP status:504 Gateway Timeout"
       Jun 27 04:34:22 hostname dockerd[15943]: time="2024-06-27T04:34:22.242356188Z" level=error msg="Upload failed, retrying: received unexpected HTTP status: 504 Gateway Timeout"
       Jun 27 04:34:34 hostname dockerd[15943]: time="2024-06-27T04:34:34.546293953Z" level=error msg="Upload failed, retrying: received unexpected HTTP status: 504 Gateway Timeout"
       Jun 27 05:09:13 hostname dockerd[15943]: time="2024-06-27T05:09:13.941019511Z" level=error msg="Upload failed: unauthorized: unauthorized to access repository: project/image111, action: push: unauthorized to access repository: project/image111, action: push"
       Jun 27 05:09:14 hostname dockerd[15943]: time="2024-06-27T05:09:14.033404759Z" level=info msg="Attempting next endpoint for push after error: unauthorized: unauthorized to access repository: project/image111, action: push: unauthorized to access repository: project/image111, action: push" spanID=9f7f82f8d0efc15d traceID=69885a88db3dacaf65f25f785ba96e87
       Jun 27 05:12:22 hostname systemd[1]: var-lib-docker-overlay2-7ukh9slir226ob10w7g2kc457-merged.mount: Deactivated successfully.
       Jun 27 05:12:23 hostname dockerd[15943]: time="2024-06-27T05:12:23.647034588Z" level=error msg="Upload failed: unauthorized: unauthorized to access repository: project/image113, action: push: unauthorized to access repository: project/image113, action: push"
       Jun 27 05:12:23 hostname dockerd[15943]: time="2024-06-27T05:12:23.647600914Z" level=info msg="Attempting next endpoint for push after error: unauthorized: unauthorized to access repository: project/image113, action: push: unauthorized to access repository: project/image113, action: push" spanID=089b020dafe9dab8 traceID=857c006e7c8a330fe2edab4fb06d1353
       Jun 27 05:12:39 hostname systemd[1]: var-lib-docker-overlay2-banjpiwwghrl4rrpeiy3yqhw1-merged.mount: Deactivated successfully.
       Jun 27 05:12:42 hostname systemd[1]: var-lib-docker-overlay2-6a1evhes8kjehoyh7vnz6j2dh-merged.mount: Deactivated successfully.
       Jun 27 05:12:42 hostname dockerd[15943]: time="2024-06-27T05:12:42.671127899Z" level=error msg="Upload failed: unauthorized: unauthorized to access repository: project/image114, action: push: unauthorized to access repository: project/image114, action: push"
       Jun 27 05:12:42 hostname dockerd[15943]: time="2024-06-27T05:12:42.671180461Z" level=info msg="Attempting next endpoint for push after error: unauthorized: unauthorized to access repository: project/image114, action: push: unauthorized to access repository: project/image114, action: push" spanID=641343939c048c89 traceID=8603b0e1e08c8a9a546939d38363a134
       Jun 27 05:12:45 hostname dockerd[15943]: time="2024-06-27T05:12:45.612649409Z" level=error msg="Upload failed: unauthorized: unauthorized to access repository: project/image112, action: push: unauthorized to access repository: project/image112, action: push"
       Jun 27 05:12:45 hostname dockerd[15943]: time="2024-06-27T05:12:45.613215154Z" level=info msg="Attempting next endpoint for push after error: unauthorized: unauthorized to access repository: project/image112, action: push: unauthorized to access repository: project/image112, action: push" spanID=52c3a91612ee1ca0 traceID=5d8290efabc904f792579eee274a0dc8
Harbor core.log:
       Jun 27 13:29:58 172.25.0.1 core[897]: 2024/06/27 04:29:58 http: proxy error: context canceled
       Jun 27 13:33:21 172.25.0.1 core[897]: 2024/06/27 04:33:21 http: proxy error: context canceled
       Jun 27 13:33:31 172.25.0.1 core[897]: 2024/06/27 04:33:31 http: proxy error: context canceled
       Jun 27 13:33:43 172.25.0.1 core[897]: 2024/06/27 04:33:43 http: proxy error: context canceled
       Jun 27 14:00:28 172.25.0.1 core[897]: 2024-06-27T05:00:28Z [INFO] [/pkg/task/dao/execution.go:471]: scanned out 2 executions with outdate status, refresh status to db
       Jun 27 14:00:29 172.25.0.1 core[897]: 2024-06-27T05:00:29Z [INFO] [/pkg/task/dao/execution.go:512]: refresh outdate execution status done, 2 succeed, 0 failed
       Jun 27 14:08:22 172.25.0.1 core[897]: 2024-06-27T05:08:22Z [ERROR] [/pkg/token/token.go:82]: parse token error, token is expired by 8m3.731441924s
       Jun 27 14:08:22 172.25.0.1 core[897]: 2024-06-27T05:08:22Z [WARNING] [/server/middleware/security/v2_token.go:67][requestID="f5987767-2ab7-40e7-88c7-94ac735e91cb"]: failed to decode bearer token: token is expired by 8m3.731441924s
       Jun 27 14:11:32 172.25.0.1 core[897]: 2024-06-27T05:11:32Z [ERROR] [/pkg/token/token.go:82]: parse token error, token is expired by 7m44.502467466s
       Jun 27 14:11:32 172.25.0.1 core[897]: 2024-06-27T05:11:32Z [WARNING] [/server/middleware/security/v2_token.go:67][requestID="79ba1437-7178-4c32-aa88-bdab5123efb2"]: failed to decode bearer token: token is expired by 7m44.502467466s
       Jun 27 14:11:51 172.25.0.1 core[897]: 2024-06-27T05:11:51Z [ERROR] [/pkg/token/token.go:82]: parse token error, token is expired by 8m15.505121582s
       Jun 27 14:11:51 172.25.0.1 core[897]: 2024-06-27T05:11:51Z [WARNING] [/server/middleware/security/v2_token.go:67][requestID="a893a7a0-ea15-4193-a8f1-f42327d8630e"]: failed to decode bearer token: token is expired by 8m15.505121582s
       Jun 27 14:11:54 172.25.0.1 core[897]: 2024-06-27T05:11:54Z [ERROR] [/pkg/token/token.go:82]: parse token error, token is expired by 8m27.425278265s
       Jun 27 14:11:54 172.25.0.1 core[897]: 2024-06-27T05:11:54Z [WARNING] [/server/middleware/security/v2_token.go:67][requestID="955866af-a032-4ee2-a361-7e6d801b5001"]: failed to decode bearer token: token is expired by 8m27.425278265s
crazyelectron-io commented 3 months ago

I experience a very similar issue with a 712MB image, pushing from a (Debian 12.6) Linux client with Docker 27.0.3 and Harbor v2.12.0-f86f1ceb. Smaller images work fine, but this one keeps failing.

The docker client hangs at ~400-600 MB and after timeout returns unknown: Client Closed Request. The docker service logs:

Jul 08 08:11:22 gandalf dockerd[481773]: time="2024-07-08T08:11:22.156010705+02:00" level=error msg="Upload failed, retrying: unknown: Client Closed Request"
Jul 08 08:12:27 gandalf dockerd[481773]: time="2024-07-08T08:12:27.330959239+02:00" level=error msg="Upload failed, retrying: unknown: Client Closed Request"
Jul 08 08:13:37 gandalf dockerd[481773]: time="2024-07-08T08:13:37.633370636+02:00" level=error msg="Upload failed, retrying: unknown: Client Closed Request"
Jul 08 08:14:52 gandalf dockerd[481773]: time="2024-07-08T08:14:52.895728642+02:00" level=error msg="Upload failed, retrying: unknown: Client Closed Request"
Jul 08 08:16:13 gandalf dockerd[481773]: time="2024-07-08T08:16:13.150553594+02:00" level=error msg="Upload failed: unknown: Client Closed Request"
Jul 08 08:16:13 gandalf dockerd[481773]: time="2024-07-08T08:16:13.150661807+02:00" level=error msg="Not continuing with push after error: unknown: Client Closed Request"

The harbor.core log:

2024/07/08 08:11:22 http: proxy error: context canceled
2024/07/08 08:12:27 http: proxy error: context canceled
2024/07/08 08:13:37 http: proxy error: context canceled
2024/07/08 08:14:52 http: proxy error: context canceled
2024/07/08 08:16:13 http: proxy error: context canceled

I run Harbor on Kubernetes 1.30.1 behind a Traefik 3.0 proxy that handles LE certificates and routing. The Traefik logs show no error or warning.

wy65701436 commented 3 months ago

@Satoshi-Hirai371 what size of your image? How did you install harbor? Through offline installer or helm chart?

crazyelectron-io commented 3 months ago

I tested it from a small Linux server first and now from my M2 Pro MacBook and that works (is much faster, so no timeout issues probably).

Satoshi-Hirai371 commented 2 months ago

@Satoshi-Hirai371 what size of your image? How did you install harbor? Through offline installer or helm chart?

The image is 4GIB and uses an offline installer.

github-actions[bot] commented 3 weeks ago

This issue is being marked stale due to a period of inactivity. If this issue is still relevant, please comment or remove the stale label. Otherwise, this issue will close in 30 days.