mvn compile jib:build no further progress after log about Container entrypoint set to ...

[semistone222]

Environment:

• Jib version: 1.5.0
• Build tool: Maven 3
• OS: Mac OSX

Description of the issue:
I wanted to test jib on Spring boot demo application.
So, I added jib-maven-plugin and set docker image url.
After running mvn compile jib:build,
There is no further progress after log about Container entrypoint set to ....
I waited about 5 min, but It's still not over yet.
Please, give me a advice.
Thanks for providing awesome tools. :D
(It seems to be not related about auth.)

Expected behavior:
mvn compile jib:build should be done.

Steps to reproduce:

1. get spring boot demo project from spring initializer
2. add jib-maven-plugin and set image url as below
3. run mvn compile jib:build
4. wait and check no further progress is being made after Container entrypoint set to ...

jib-maven-plugin Configuration:

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>
    <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>2.1.7.RELEASE</version>
        <relativePath/> <!-- lookup parent from repository -->
    </parent>
    <groupId>com.example</groupId>
    <artifactId>demo</artifactId>
    <version>0.0.1-SNAPSHOT</version>
    <name>demo</name>
    <description>Demo project for Spring Boot</description>

    <properties>
        <java.version>1.8</java.version>
    </properties>

    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
        </dependency>

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
        </dependency>
    </dependencies>

    <build>
        <plugins>
            <plugin>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-maven-plugin</artifactId>
            </plugin>
            <plugin>
                <groupId>com.google.cloud.tools</groupId>
                <artifactId>jib-maven-plugin</artifactId>
                <version>1.5.0</version>
                <configuration>
                    <to>
                        <image>docker.io/y2o2u2n/onair</image>
                    </to>
                </configuration>
            </plugin>
        </plugins>
    </build>

</project>

Log output:

"/Applications/IntelliJ IDEA.app/Contents/jbr/Contents/Home/bin/java" -Dmaven.multiModuleProjectDirectory=/Users/y2o2u2n/Workspace/demo "-Dmaven.home=/Applications/IntelliJ IDEA.app/Contents/plugins/maven/lib/maven3" "-Dclassworlds.conf=/Applications/IntelliJ IDEA.app/Contents/plugins/maven/lib/maven3/bin/m2.conf" "-Dmaven.ext.class.path=/Applications/IntelliJ IDEA.app/Contents/plugins/maven/lib/maven-event-listener.jar" -Dfile.encoding=UTF-8 -classpath "/Applications/IntelliJ IDEA.app/Contents/plugins/maven/lib/maven3/boot/plexus-classworlds-2.6.0.jar" org.codehaus.classworlds.Launcher -Didea.version2019.2 compile jib:build
[INFO] Scanning for projects...
[INFO] 
[INFO] --------------------------< com.example:demo >--------------------------
[INFO] Building demo 0.0.1-SNAPSHOT
[INFO] --------------------------------[ jar ]---------------------------------
[INFO] 
[INFO] --- maven-resources-plugin:3.1.0:resources (default-resources) @ demo ---
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] Copying 1 resource
[INFO] Copying 0 resource
[INFO] 
[INFO] --- maven-compiler-plugin:3.8.1:compile (default-compile) @ demo ---
[INFO] Nothing to compile - all classes are up to date
[INFO] 
[INFO] --- jib-maven-plugin:1.5.0:build (default-cli) @ demo ---
[INFO] 
[INFO] Containerizing application to y2o2u2n/onair...
[INFO] Retrieving registry credentials for registry-1.docker.io...
[INFO] Getting base image gcr.io/distroless/java:8...
[INFO] Building dependencies layer...
[INFO] Building resources layer...
[INFO] Building classes layer...
[INFO] 
[INFO] Container entrypoint set to [java, -cp, /app/resources:/app/classes:/app/libs/*, com.example.demo.DemoApplication]

Additional Information:

[loosebazooka]

Can you try with 1.5.1?

[semistone222]

@loosebazooka
It is same as before with 1.5.1 ;> ...

[briandealwis]

Hi @semistone222

Can you hook up a network monitor to see if there is any traffic going across? If you're pushing across a slow connection, one possibility is that our progress ticks don't have sufficient granularity to capture the slow pushes. On macOS, you should be able to run nettop -p java and see some detail.

Does a jib:build complete after a successful docker push? Providing that you're pushing to the same image reference, then Jib should only push changed layers, and so it should be very fast.

If you follow the process in the FAQ to obtain a network trace (https://github.com/GoogleContainerTools/jib/blob/master/docs/faq.md#how-can-i-examine-network-traffic), you'll seecurl commands to reproduce the http connection. You could try running one of the PUT calls.

[gpando]

The same happened to me, I went back to version 1.4.0 and that's how it works

[chanseokoh]

@gpando we'd like to know exactly what is happening and why with which Jib versions in your case.

Could you also capture detailed network traces for both 1.4.0 and 1.5.1 and share them (after stripping out any sensitive info, if any)? Also add -X (Maven) or --debug (Gradle) to make Jib log more information. If you succeed, you'll see (in a serialized manner) logs like this.

[ndarilek]

I'm hitting this one as well, but under Gradle and not Maven. Essentially, last week I upgraded Jib from 1.2 to 1.5.1. Initially, my builds hung. I then downgraded to 1.2.0, removed my build/ directory, and my initial build was very fast. I then re-upgraded to 1.5.1, blaming intermittent network issues and my slow connection. But today slow builds are back, coinciding with a new upstream base image.

I haven't followed the earlier debugging suggestions yet because I came to this thread a bit late, having already done some debugging already. I'm also kind of on a time/budget crunch and don't have the luxury of comparing logs on different versions. Here's what I've found, though:

I'm pulling a base image that's around 3.1G in size and has some largeish layers (one is ~700MB.) I'm also on a relatively slow connection.

docker pull pulls this image in 20-30 minutes or so. Jib is at 1h11m and my cache is only 1.5G. I set useOnlyProjectCache to make this a bit easier to debug. So the download seems slower by a significant margin.

It almost seems like there's significant buffering happening in the HTTP layer. Maybe it isn't as noticeable on fast connections, but slow things down and you'll almost certainly see it. But it isn't entirely the connection's fault, since again Docker is very fast. Was something changed in how images are downloaded/processed since 1.2, or possibly 1.4?

I can try switching versions, capturing logs, and analyzing cache growth if I have time. But I at least thought I'd note that downloads are significantly slower than Docker on the same connection, and that this does seem to have changed since 1.2. Is there any way you might instrument HTTP client throughput on 1.2/1.4 vs. 1.5.1? Not just logging, but determining how many bytes are passing through the download process per second on 1.2/1.4 and 1.5? Meanwhile, I'm going to let this download finish and hope our upstream image doesn't bump again.

[ndarilek]

Heh, and while I wrote that last comment, I noticed the download finished with a final cache size of 1.5G and about 1.5 hours' duration. I guess the cache size is compressed whereas the 3G image size is uncompressed. Anyhow, Docker definitely didn't take 1.5 hours to download that image.

So for anyone thinking their download is hanging, make sure your cache is growing, and that the download isn't just happening very slowly. :) Sorry for the spam--I'd expected that download to take another 2-3 hours and was pleasantly surprised that it'd finished while I was ranting.

[chanseokoh]

@ndarilek thanks for the update. I'd like to rule out one thing. Could you try docker pull after deleting all of its local images? Some image layers may be shared across different images.

$ docker stop $( docker ps -aq ) # may fail if no container is running
$ docker rm $( docker ps -aq )
$ docker rmi -f $( docker images -aq )
# docker images -aq # make sure nothing is printed
$ time docker pull <your base image>

[ndarilek]

I'll look into this more tomorrow, but I'm pretty sure it's a non-issue. Our dev environment is Minikube-based, and our setup script points Docker at the Minikube-hosted daemon. Whenever I send reports like the previous, I try doing so from a known base state. In this case, that base state was `minikube delete; minikube start` and running our dev-setup script, which provisions an empty VM. And I've confirmed via `docker images -a` that my non-Minikube Docker cache is empty. I'll see if I can spare some time next week to collect more detailed logs. Sorry I can't be of more help.

[ndarilek]

Sorry, looked at your command stream. I'll do a `time docker pull...` to report on actual time spent pulling the image in the VM so we'll have another data point next to my ~1.5 hour pull time in Jib.

[chanseokoh]

Oh, sorry, forgot to ask one thing. (I feel like I'm spamming.) Are you using <allowInsecureRegistries> to pull from an insecure (possibly non-HTTP) registry?

[ndarilek]

Nope, it's gcr.io.

[chanseokoh]

I believe I can reproduce this at home where my network is very slow.

Closing as a dup of #1970, but if anyone finds their case is different, feel free to re-open or open a new issue.

[TadCordle]

@semistone222 @gpando 1.6.0 has been released with the fix.

[vishnu3152]

Hi,

May i know how can we skip JUNIT tests while running skaffold configuration.