Kaniko: Snapshotting is taking > 10 minutes

[nicolaferraro]

Actual behavior

We're using Kaniko in Camel K and some users are complaining about builds that became slow after we upgraded to v0.14.0 from 0.9.0 (https://github.com/apache/camel-k/issues/1209) especially on Minikube (towards Minikube internal addon registry).

Under the hood, we use the fabric8/s2i-java:3.0-java8 image which is a bit heavy, but it seems the logs get stuck when doing the snapshot of some jar files in a specific dir (~50 jars):

camel-k-kit-bofk6gui1aal47gim840-builder kaniko INFO[0492] Downloading base image 10.111.197.108/chapter-7/camel-k-kit-bofj39ei1aal47gim830:36212
camel-k-kit-bofk6gui1aal47gim840-builder kaniko INFO[0647] Skipping unpacking as no commands require it.
camel-k-kit-bofk6gui1aal47gim840-builder kaniko INFO[0647] Taking snapshot of full filesystem...
camel-k-kit-bofk6gui1aal47gim840-builder kaniko INFO[0647] Using files from context: [/builder/kit-bofk6gui1aal47gim840/package/context]
camel-k-kit-bofk6gui1aal47gim840-builder kaniko INFO[0647] ADD . /deployments
camel-k-kit-bofk6gui1aal47gim840-builder kaniko INFO[0647] Taking snapshot of files...

Is there any way to speedup Kaniko builds, e.g. by installing something on the host machine?
Shouldn't the snapshot be limited to the added directory after an "ADD" command?

Expected behavior
It should not take ages to build an image.

To Reproduce
Steps to reproduce the behavior:

1. Install Minikube
2. Enable the registry addon
3. Install Camel K 1.0.0-RC1 (kamel install)
4. Build an integration kamel run https://raw.githubusercontent.com/apache/camel-k/master/examples/simple.groovy
5. A kaniko build pod will be started, preceded by an init-container

Triage Notes for the Maintainers

| Description | Yes/No |
|----------------|---------------|
| Please check if this a new feature you are proposing |

• - [ ]

|
| Please check if the build works in docker but not in kaniko |

• - [ ]

|
| Please check if this error is seen when you use --cache flag |

• - [ ]

|
| Please check if your dockerfile is a multistage dockerfile |

• - [ ]

|

[tejal29]

@nicolaferraro For ADD command we only take snapshot of files
the log line below also suggests it.

camel-k-kit-bofk6gui1aal47gim840-builder kaniko INFO[0647] Taking snapshot of files...

https://github.com/GoogleContainerTools/kaniko/blob/master/pkg/snapshot/snapshot.go#L63

Can you provide output with -v=debug flag? Maybe the number of files to be snapshotted are not just files from ADD . ./deployments dir .

[tejal29]

Also, can you provide your dockerfile? Are you copying the / ? see #960

[nicolaferraro]

Hi @tejal29, the Dockerfile is simple:

FROM fabric8/s2i-java:3.0-java8
ADD . /deployments

I've extracted a verbose log. The problem is that after the snapshot there are no more logs, so it's difficult to tell what's going slow.

camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0000] Copying file /builder/kit-boin6figbopchis5erg0/package/context/Dockerfile to /kaniko/Dockerfile 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0000] Skip resolving path /kaniko/Dockerfile       
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0000] Skip resolving path /builder/kit-boin6figbopchis5erg0/package/context 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0000] Skip resolving path /kaniko/cache            
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0000] Skip resolving path                          
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0000] Skip resolving path                          
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0000] Skip resolving path                          
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0000] Resolved base name fabric8/s2i-java:3.0-java8 to fabric8/s2i-java:3.0-java8 
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0000] Resolved base name fabric8/s2i-java:3.0-java8 to fabric8/s2i-java:3.0-java8 
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0000] Downloading base image fabric8/s2i-java:3.0-java8 
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0003] Error while retrieving image from cache: getting file info: stat /kaniko/cache/sha256:9ac5acb3aa8e7e179eb1fd28cda7dac22ef7deac24f00b50cee56265fa259141: no such file or directory 
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0003] Downloading base image fabric8/s2i-java:3.0-java8 
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0005] Built cross stage deps: map[]                
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0005] Downloading base image fabric8/s2i-java:3.0-java8 
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0006] Error while retrieving image from cache: getting file info: stat /kaniko/cache/sha256:9ac5acb3aa8e7e179eb1fd28cda7dac22ef7deac24f00b50cee56265fa259141: no such file or directory 
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0006] Downloading base image fabric8/s2i-java:3.0-java8 
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0008] Executing 0 build triggers                   
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0008] Skipping unpacking as no commands require it. 
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0008] Taking snapshot of full filesystem...        
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Skipping paths under /kaniko, as it is a whitelisted directory 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Skipping paths under /var/run, as it is a whitelisted directory 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Skipping paths under /builder, as it is a whitelisted directory 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Skipping paths under /dev, as it is a whitelisted directory 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Skipping paths under /proc, as it is a whitelisted directory 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Skipping paths under /sys, as it is a whitelisted directory 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Adding / to layer, because it was changed.   
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Adding /var to layer, because it was changed. 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Adding /etc to layer, because it was changed. 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Adding /.dockerenv to layer, because it was changed. 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Adding /workspace to layer, because it was changed. 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Resolved . to .                              
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Resolved /deployments to /deployments        
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0008] Using files from context: [/builder/kit-boin6figbopchis5erg0/package/context] 
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0008] ADD . /deployments                           
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Resolved . to .                              
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Resolved /deployments to /deployments        
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Resolved . to .                              
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Resolved /deployments to /deployments        
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Getting files and contents at root /builder/kit-boin6figbopchis5erg0/package/context 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Creating directory /deployments              
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/Dockerfile to /deployments/Dockerfile 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Creating directory /deployments/dependencies 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/com.sun.xml.bind.jaxb-core-2.3.0.1.jar to /deployments/dependencies/com.sun.xml.bind.jaxb-core-2.3.0.1.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/com.sun.xml.bind.jaxb-impl-2.3.0.jar to /deployments/dependencies/com.sun.xml.bind.jaxb-impl-2.3.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/commons-io.commons-io-2.6.jar to /deployments/dependencies/commons-io.commons-io-2.6.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/javax.xml.bind.jaxb-api-2.3.0.jar to /deployments/dependencies/javax.xml.bind.jaxb-api-2.3.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-api-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-api-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-base-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-base-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-bean-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-bean-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-core-engine-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-core-engine-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-endpointdsl-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-endpointdsl-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-groovy-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-groovy-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-jaxp-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-jaxp-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-log-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-log-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-main-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-main-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-management-api-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-management-api-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-support-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-support-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-timer-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-timer-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-util-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-util-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.camel-util-json-3.0.0.jar to /deployments/dependencies/org.apache.camel.camel-util-json-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.k.camel-k-loader-groovy-1.0.9.jar to /deployments/dependencies/org.apache.camel.k.camel-k-loader-groovy-1.0.9.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.k.camel-k-runtime-core-1.0.9.jar to /deployments/dependencies/org.apache.camel.k.camel-k-runtime-core-1.0.9.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.k.camel-k-runtime-main-1.0.9.jar to /deployments/dependencies/org.apache.camel.k.camel-k-runtime-main-1.0.9.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.camel.spi-annotations-3.0.0.jar to /deployments/dependencies/org.apache.camel.spi-annotations-3.0.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.commons.commons-lang3-3.9.jar to /deployments/dependencies/org.apache.commons.commons-lang3-3.9.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.logging.log4j.log4j-api-2.13.0.jar to /deployments/dependencies/org.apache.logging.log4j.log4j-api-2.13.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.logging.log4j.log4j-core-2.13.0.jar to /deployments/dependencies/org.apache.logging.log4j.log4j-core-2.13.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.apache.logging.log4j.log4j-slf4j-impl-2.13.0.jar to /deployments/dependencies/org.apache.logging.log4j.log4j-slf4j-impl-2.13.0.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.codehaus.groovy.groovy-2.5.8.jar to /deployments/dependencies/org.codehaus.groovy.groovy-2.5.8.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Copying file /builder/kit-boin6figbopchis5erg0/package/context/dependencies/org.slf4j.slf4j-api-1.7.29.jar to /deployments/dependencies/org.slf4j.slf4j-api-1.7.29.jar 
camel-k-kit-boin6figbopchis5erg0-builder kaniko INFO[0008] Taking snapshot of files...                  
camel-k-kit-boin6figbopchis5erg0-builder kaniko DEBU[0008] Taking snapshot of files [/deployments /deployments/Dockerfile /deployments/dependencies /deployments/dependencies/com.sun.xml.bind.jaxb-core-2.3.0.1.jar /deployments/dependencies/com.sun.xml.bind.jaxb-impl-2.3.0.jar /deployments/dependencies/commons-io.commons-io-2.6.jar /deployments/dependencies/javax.xml.bind.jaxb-api-2.3.0.jar /deployments/dependencies/org.apache.camel.camel-api-3.0.0.jar /deployments/dependencies/org.apache.camel.camel-base-3.0.0.jar /deployments/dependencies/org.apache.camel.camel-bean-3.0.0.jar /deployments/dependencies/org.apache.camel.camel-core-engine-3.0.0.jar /deployments/dependencies/org.apache.camel.camel-endpointdsl-3.0.0.jar /deployments/dependencies/org.apache.camel.camel-groovy-3.0.0.jar /deployments/dependencies/org.apache.camel.camel-jaxp-3.0.0.jar /deployments/dependencies/org.apache.camel.camel-log-3.0.0.jar /deployments/dependencies/org.apache.camel.camel-main-3.0.0.jar /deployments/dependencies/org.apache.camel.camel-management-api-3.0.0.jar /deployments/dependencies/org.apache.camel.camel-support-3.0.0.jar /deployments/dependencies/org.apache.camel.camel-timer-3.0.0.jar /deployments/dependencies/org.apache.camel.camel-util-3.0.0.jar /deployments/dependencies/org.apache.camel.camel-util-json-3.0.0.jar /deployments/dependencies/org.apache.camel.k.camel-k-loader-groovy-1.0.9.jar /deployments/dependencies/org.apache.camel.k.camel-k-runtime-core-1.0.9.jar /deployments/dependencies/org.apache.camel.k.camel-k-runtime-main-1.0.9.jar /deployments/dependencies/org.apache.camel.spi-annotations-3.0.0.jar /deployments/dependencies/org.apache.commons.commons-lang3-3.9.jar /deployments/dependencies/org.apache.logging.log4j.log4j-api-2.13.0.jar /deployments/dependencies/org.apache.logging.log4j.log4j-core-2.13.0.jar /deployments/dependencies/org.apache.logging.log4j.log4j-slf4j-impl-2.13.0.jar /deployments/dependencies/org.codehaus.groovy.groovy-2.5.8.jar /deployments/dependencies/org.slf4j.slf4j-api-1.7.29.jar] 

[DjinNO]

"Taking snapshot of full filesystem" is taking > 30 minutes.. Can't start using kaniko because of this :(

My Dockerfile is very simple:

FROM node:10 as builder
WORKDIR /usr/src/app
COPY . .
ENV NODE_ENV=production
RUN yarn install --frozen-lockfile --production; \
        yarn build

[tejal29]

Let me look in to it @DjinNO
Can you also specify what is the size of your current workdir?

[tejal29]

Thanks @nicolaferraro Can you change your dockerfile to

FROM fabric8/s2i-java:3.0-java8
ADD /deployments /deployments

and see if it helps? I want able to reproduce your error. i will try downloading one of these jars in my workspace and see if i can reproduce this issue.

[tejal29]

@nicolaferraro i am not able to reproduce this issue on my end. I downloaded a jar and put it in the my $buildcontext/dependencies directory

DEBU[0013] Taking snapshot of files [/deployments .... /deployments/dependencies/org.apache.camel.camel-util-3.0.0.jar 
...
 /integration_test.go /deployments/replace-gcr-with-local-registry.sh] 

DEBU[0013] build: composite key for command ADD . /deployments &{[sha256:9ac5acb3aa8e7e179eb1fd28cda7dac22ef7deac24f00b50cee56265fa259141 ADD . /deployments 9c3ae8419cd2a88d7f7bfce76d25d10c5836b95282d8e632bb17697cc4b9b764]} 
DEBU[0013] build: cache key for command ADD . /deployments 4b5f61364d4092a8866f0e202e155ac62a8dc5a3278a929e1195d918d5e14e81 
DEBU[0018] mapping stage idx 0 to digest sha256:2a5f2fcb115dc8acf1c7eb46c2df112a3983950ffd58e28b962c6dd7b2f547a5 

Can you provide more information? Are any of these jars symlinks?

[tejal29]

@nicolaferraro i pushed an image gcr.io/kaniko-project/executor:970 with fix #989.
I want to know if we spend to much time calculating the parent directories.
Can you please try this kaniko image?

Thanks
Tejal

[DjinNO]

Can you also specify what is the size of your current workdir?

80M

[DjinNO]

Im using gitlab ci to build image and i want to store cache in gitlab registry.
To try to use gcr.io/kaniko-project/executor:970 i need shell in image

[tejal29]

@DjinNO ok,I pushed a debug image.

gcr.io/kaniko-project/executor:debug_970

[DjinNO]

@DjinNO ok,I pushed a debug image.

gcr.io/kaniko-project/executor:debug_970

With this image i have error:
error building image: error building stage: unable to add file to layered map: error creating hash for : lstat : no such file or directory

On first snapshot

[astefanutti]

I've created #1013 that is a follow-up analysis of the build time for Apache Camel K.

[nicolaferraro]

Thanks @astefanutti, yes snapshotting does not seem to be the problem, it's only referenced in last line printed in the logs.
Kaniko takes a lot to push the image to the registry.

[hrgui]

I seem to have a similar problem with some private builds. I am a JavaScript dev, so I have yarn and node environments.

Using kaniko debug-v0.19.0,
I get stuck in the following:

INFO[0547] Taking snapshot of full filesystem...        
INFO[0548] Resolving paths

The process seems to be stuck and it doesn't use any CPU (CPU dropped from 1 to 0.06).

---

Some things I noticed in my private build

• yarn cache dir could be whitelisted?, although I don't think that can be done in kaniko because its not technically needed for the actual build.

• Single snapshot helps.

[kylecribbs]

This is still happening for me. I do have a huge container; however, sometimes its quick taking the snapshot other times its not.

[hrgui]

@kylecribbs the later versions of kaniko explain more to why as it says its snapshotting X directories. What version of kaniko are you using?

[martaver]

I'm also experiencing this in cloud build... the image is large (the cached layers are 400mb in container registry), but every Full Snapshot after installing node_modules takes many minutes.

Shouldn't subsequent layers be small?

Is there a debug image and some parameters you'd like me to use to get a log?

I'm not sure if it's the snapshotting or the pushing that's taking a long time.

[martaver]

I'm also in europe-north1... I know it's a long shot but... does it matter which region your container registry is in?

[martaver]

The layers that are being pushed by the long-running 'full snapshot' steps end up being quite small... 2MB, 100 bytes etc...

That leads me to believe that it's the actual snapshot step that's slow and long-running. Maybe something with the file system.

A combination of many files (node_modules) and possibly symlinks? I'm using yarn workspaces...