Open sergeykad opened 1 year ago
JoeWang1127
commented
1 year ago Hi @sergeykad, could you provide more information on this issue? For example, the network traffic log is helpful for debugging such an issue. Please refer here for how to examine network traffic.
Also, given a previous issue, this maybe a concurrent bug in the registry, you could try -Djib.serialize=true to disable concurrency (comment).
sergeykad
commented
1 year ago I added the -Djava.util.logging.config.file=path/to/logging.properties -Djib.serialize=true but I am not sure if I see any change at all. There is no additional logging, but it is possible that it solved the original issue. I will monitor the build to see if it happens again.
On the other hand, after I added the flags, I saw the upload get stuck for about an hour until it was killed due to timeout. Edit: the build of the same image got stuck again at the same 91.7%. It uses the same Jib configuration as many other images we have.
Executing tasks:
[=============== ] 51.4% complete
> launching layer pushers
> pushing blob sha256:52cdd9f8700d9cb489a9528af...
Executing tasks:
[=============== ] 51.7% complete
> launching layer pushers
> pushing blob sha256:52cdd9f8700d9cb489a9528af...
Executing tasks:
[================ ] 51.7% complete
> launching layer pushers
> launching layer pushers
Executing tasks:
[================ ] 51.7% complete
> launching layer pushers
> pushing blob sha256:4e15725c22da6eed9e81a957b...
Executing tasks:
[================ ] 53.3% complete
> launching layer pushers
> launching layer pushers
Executing tasks:
[================ ] 53.3% complete
> launching layer pushers
> pushing blob sha256:416d5add0de096256e8ab9570...
Executing tasks:
[================= ] 55.0% complete
> launching layer pushers
> launching layer pushers
Executing tasks:
[================= ] 55.0% complete
> launching layer pushers
> pushing blob sha256:5508d90493dc104092cc77bf4...
Executing tasks:
[================= ] 56.7% complete
> launching layer pushers
> launching layer pushers
Executing tasks:
[================= ] 56.7% complete
> launching layer pushers
> pushing blob sha256:0b2303eef1b4f0ae437e1effc...
Executing tasks:
[================== ] 58.3% complete
> launching layer pushers
Executing tasks:
[================== ] 58.3% complete
> launching layer pushers
> scheduling pushing container configurations
Executing tasks:
[================== ] 58.3% complete
> launching layer pushers
> pushing container configuration
Executing tasks:
[================== ] 58.3% complete
> launching layer pushers
> pushing blob sha256:0ff59cbfde2a1789cb63d2bf1...
Executing tasks:
[==================== ] 66.7% complete
> launching layer pushers
Executing tasks:
[==================== ] 66.7% complete
> launching layer pushers
> checking existence of manifest for sha256:088...
Executing tasks:
[======================= ] 75.0% complete
> launching layer pushers
Executing tasks:
[======================= ] 75.0% complete
> launching layer pushers
> scheduling pushing manifests
Executing tasks:
[======================= ] 75.0% complete
> launching layer pushers
> launching manifest pushers
Executing tasks:
[======================= ] 75.0% complete
> launching layer pushers
> pushing manifest for MR-7982
Executing tasks:
[========================= ] 83.3% complete
> launching layer pushers
Executing tasks:
[========================= ] 83.3% complete
> launching layer pushers
> launching manifest list pushers
Executing tasks:
[============================ ] 91.7% complete
> launching layer pushers
Executing tasks:
[============================ ] 91.7% complete
> launching layer pushers
Built and pushed image as docker-registry.domain.com:5000/services/export/upload:MR-7982
Executing tasks:
[============================ ] 91.7% complete
> launching layer pushers
Cancelling nested steps due to timeout
Sending interrupt signal to process
mpeddada1
commented
1 year ago @sergeykad, We may need to gain a bit more context on why exactly the digest isn't being accepted by the registry. There have been cases in the past (#2372, #1986) where this was caused by unexpected behavior of the registry. To help investigate this further, here are few suggestions:
As a step to unblock, please try running -Djib.serialize without the HTTP traffic collection first. To overcome the timeout issue, you could try increasing the timeout value with -Djib.httpTimeout=...
Is this happening intermittently? If yes, as @JoeWang1127 mentioned, please verify if there are any differences in HTTP traffic of the successful and unsuccessful runs. Please follow these instructions without the -Djib.serialize=true. If configured correctly, they should look like this:
Mar 31, 2020 9:55:52 AM com.google.api.client.http.HttpResponse <init>
CONFIG: -------------- RESPONSE --------------
HTTP/1.1 202 Accepted
Content-Length: 0
Docker-Distribution-Api-Version: registry/2.0
Docker-Upload-Uuid: 6292f0d7-93cb-4a8e-8336-78a1bf7febd2
Location: https://registry-1.docker.io/v2/...
Range: 0-657292
Date: Tue, 31 Mar 2020 13:55:52 GMT
Strict-Transport-Security: max-age=31536000Once you've attained the logs, this example comparative analysis is a great reference to verify the layer SHAs being pushed by jib and understand how the registry responds in each run.
sergeykad
commented
1 year ago I double-checked my configuration and even enabled Gradle debug log, but I still do not see these HTTP log messages. Where should they be printed to?
sergeykad
commented
12 months ago With the Jib logging enabled it seems that the issues I am experiencing correlate with timeout errors. I did not find the root cause yet, since everything else seems normal. If I retry failed jib execution it passes on the second attempt.
PUT http://docker-registry.server.com:5000/v2/best-services/authentication/blobs/uploads/a4837341-06ae-47db-aace-9c5630bb67b5?digest=sha256:de27c5eb92e0d4f02f5e69ee68d3cdbfb0d9e4514fcf4d88bfcc952d9718e460 failed and will be retried
exception thrown while executing request
java.net.SocketTimeoutException: Read timed out
at java.base/sun.nio.ch.NioSocketImpl.timedRead(NioSocketImpl.java:283)
at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:309)
at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:350)
at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:803)
at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966)
at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:280)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:157)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
at com.google.api.client.http.apache.v2.ApacheHttpRequest.execute(ApacheHttpRequest.java:73)
at com.google.api.client.http.HttpRequest.execute(HttpRequest.java:1012)
at com.google.cloud.tools.jib.http.FailoverHttpClient.call(FailoverHttpClient.java:349)
at com.google.cloud.tools.jib.http.FailoverHttpClient.call(FailoverHttpClient.java:255)
at com.google.cloud.tools.jib.registry.RegistryEndpointCaller.call(RegistryEndpointCaller.java:138)
at com.google.cloud.tools.jib.registry.RegistryEndpointCaller.call(RegistryEndpointCaller.java:114)
at com.google.cloud.tools.jib.registry.RegistryClient.callRegistryEndpoint(RegistryClient.java:623)
at com.google.cloud.tools.jib.registry.RegistryClient.pushBlob(RegistryClient.java:564)
at com.google.cloud.tools.jib.builder.steps.PushBlobStep.call(PushBlobStep.java:89)
at com.google.cloud.tools.jib.builder.steps.PushLayerStep.call(PushLayerStep.java:92)
at com.google.cloud.tools.jib.builder.steps.PushLayerStep.call(PushLayerStep.java:33)
at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:131)
at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:74)
at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:82)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
at java.base/java.lang.Thread.run(Thread.java:833)
Environment:
Description of the issue: Sometimes upload to Sonatype Nexus Repository ManagerOSS 3.49.0-02 fails with the following error:
Expected behavior: Upload to the repository will always succeed
Steps to reproduce:
jibGradle taskjib-gradle-pluginConfiguration:Log output:
Additional Information: