Checking cache takes ages and rebuilds the whole image after each change #5499

isengartz · 2021-03-06T12:52:30Z

Whenever I start skaffold dev or whenever I do a change locally skaffold outputs Checking Cache... which last for 10 mins !!
After that it outputs Not found. Building and builds the whole image again ! I'm working on this project for the last 8 months and I didnt have any issues until I removed the old version of skaffold ( I dont remember which one ) and installed the latest ( v1.20.0 ) via Windows Binary ( I tested the choco version too, doesnt change something ).

I tried --cache-artifacts but I get the same issue.

Expected behavior

It should sync the changes instantly

Watching for changes...
[client] Compiled successfully!
Syncing 1 files for isengart/food-client:cce47aa08340a03e9c17dba35def88e5e1ea024ac2be1295f5139f0231647
452

Actual behavior

It stucks at Checking Cache... for 10 min then rebuild the whole image

Watching for changes...
[client] Files successfully emitted, waiting for typecheck results...
[client] Compiled successfully!
Generating tags...
 - isengart/food-client -> isengart/food-client:92ab132-dirty
Checking cache...
 - isengart/food-client: Not found. Building
Found [docker-desktop] context, using local docker daemon.
Building [isengart/food-client]...
Sending build context to Docker daemon  369.9MB
Step 1/9 : FROM node:alpine
 ---> 65db8a8f7b03
Step 2/9 : WORKDIR /app
 ---> Using cache
 ---> b113beced6ae
Step 3/9 : COPY package.json .
 ---> Using cache
 ---> 964b5b936c06
Step 4/9 : ENV CI=true
 ---> Using cache
 ---> a20029f064cd
Step 5/9 : RUN npm install --only=prod --legacy-peer-deps
 ---> Using cache
 ---> 6179989f1840
Step 6/9 : RUN npm install react-scripts -g
 ---> Using cache
 ---> b55bed19074e
Step 7/9 : COPY . .
 ---> b785fcc3c93b
Step 8/9 : EXPOSE 3000
 ---> Running in ff673c629931
 ---> ddb7af1efcfd
Step 9/9 : CMD ["npm", "start"]
 ---> Running in b6388d5f95d7
 ---> 641ea539ee85
Successfully built 641ea539ee85
Successfully tagged isengart/food-client:92ab132-dirty

Information

Skaffold version: 1.20.0
Operating system: Winblows 10
Installed via: Windows Binary
Contents of skaffold.yaml:

apiVersion: skaffold/v2alpha3
kind: Config
deploy:
  kubectl:
    manifests: # shouldn't add the persistent Volumes and dbs to skaffold
      - ./infra/k8s/nats-depl.yaml
      - ./infra/k8s/client/client-depl.yaml
      - ./infra/k8s/menu/menu-depl.yaml
      - ./infra/k8s/notification/notification-depl.yaml
      - ./infra/k8s/order/order-depl.yaml
      - ./infra/k8s/restaurant/restaurant-depl.yaml
      - ./infra/k8s/user/user-depl.yaml
      - ./infra/k8s-dev/*
build:
  local:
    push: false
  artifacts:
    - image: isengart/food-user
      context: user
      docker:
        dockerfile: Dockerfile
      sync:
        manual:
          - src: 'src/**/*.ts'
            dest: .
    - image: isengart/food-restaurant
      context: restaurant
      docker:
        dockerfile: Dockerfile
      sync:
        manual:
          - src: 'src/**/*.ts'
            dest: .
    - image: isengart/food-menu
      context: menu
      docker:
        dockerfile: Dockerfile
      sync:
        manual:
          - src: 'src/**/*.ts'
            dest: .
    - image: isengart/food-order
      context: order
      docker:
        dockerfile: Dockerfile
      sync:
        manual:
          - src: 'src/**/*.ts'
            dest: .
    - image: isengart/food-notification
      context: notification
      docker:
        dockerfile: Dockerfile
      sync:
        manual:
          - src: 'src/**/*.ts'
            dest: .
    - image: isengart/food-client
      context: client
      docker:
        dockerfile: Dockerfile
      sync:
        infer:
          - '**/*.ts'
          - '**/*.tsx'
          - '**/*.less'

Steps to reproduce the behavior

https://github.com/isengartz/sin-food
skaffold dev

The text was updated successfully, but these errors were encountered:

briandealwis · 2021-03-08T02:52:34Z

It sync'd for me out of the box (-v info shows more logging information):

$ skaffold dev -v info
INFO[0287] files modified: [client/src/index.tsx]       
Syncing 1 files for isengart/food-client:2d4b524d630c867444aa0ffd69ef2ce9aa2076292d30e9365fa587edd1b7521d
INFO[0287] Copying files: map[client/src/index.tsx:[/app/src/index.tsx]] to isengart/food-client:2d4b524d630c867444aa0ffd69ef2ce9aa2076292d30e9365fa587edd1b7521d 
Watching for changes...
[client] Failed to compile.

What files did you edit? Is it possible that your editor is placing temp files alongside the file being edited? These temp files can lead to rebuilds.

briandealwis · 2021-03-08T03:03:32Z

I forgot to add that checking the cache is fast for me:

Checking cache...
 - isengart/food-client: Found Locally
INFO[0001] Cache check completed in 88.45775ms

Could you please try running with -vdebug so that we can see what else is going on?

isengartz · 2021-03-08T15:36:52Z

Hello , I was changing .ts / .tsx files . The .idea folder is outside of the service folder so there is no way that it would affect each service .

This is what happens when I start the project with skaffold dev -vdebug

C:\Users\Sin\Desktop\sin-food>skaffold dev -vdebug
time="2021-03-08T16:51:33+02:00" level=info msg="starting gRPC server on port 50051"
time="2021-03-08T16:51:33+02:00" level=info msg="starting gRPC HTTP server on port 50052"
time="2021-03-08T16:51:33+02:00" level=info msg="Skaffold &{Version:v1.20.0 ConfigVersion:skaffold/v2beta12 GitVersion: GitCommit:c48e97690d8daffd68141c2a68fcbe3df6f6936a GitTreeState:dir
ty BuildDate:2021-02-11T22:56:45Z GoVersion:go1.14.14 Compiler:gc Platform:windows/amd64}"
time="2021-03-08T16:51:33+02:00" level=debug msg="Update check not enabled, skipping."
time="2021-03-08T16:51:33+02:00" level=info msg="Loaded Skaffold defaults from \"C:\\\\Users\\\\Sin\\\\.skaffold\\\\config\""
time="2021-03-08T16:51:33+02:00" level=debug msg="could not parse date \"\""
time="2021-03-08T16:51:33+02:00" level=debug msg="config version out of date: upgrading to latest \"skaffold/v2beta12\""
time="2021-03-08T16:51:33+02:00" level=debug msg="parsed 1 configs from configuration file C:\\Users\\Sin\\Desktop\\sin-food\\skaffold.yaml"
time="2021-03-08T16:51:33+02:00" level=info msg="Using kubectl context: docker-desktop"
time="2021-03-08T16:51:33+02:00" level=debug msg="setting Docker user agent to skaffold-v1.20.0"
time="2021-03-08T16:51:33+02:00" level=debug msg="Using builder: local"
Listing files to watch...
 - isengart/food-user
time="2021-03-08T16:51:33+02:00" level=debug msg="Found dependencies for dockerfile: [{package.json /app true} {. /app true}]"
time="2021-03-08T16:51:33+02:00" level=debug msg="Skipping excluded path: node_modules"
 - isengart/food-restaurant
time="2021-03-08T16:51:33+02:00" level=debug msg="Found dependencies for dockerfile: [{package.json /app true} {. /app true}]"
time="2021-03-08T16:51:33+02:00" level=debug msg="Skipping excluded path: node_modules"
 - isengart/food-menu
time="2021-03-08T16:51:33+02:00" level=debug msg="Found dependencies for dockerfile: [{package.json /app true} {. /app true}]"
time="2021-03-08T16:51:33+02:00" level=debug msg="Skipping excluded path: node_modules"
 - isengart/food-order
time="2021-03-08T16:51:33+02:00" level=debug msg="Found dependencies for dockerfile: [{package.json /app true} {. /app true}]"
time="2021-03-08T16:51:33+02:00" level=debug msg="Skipping excluded path: node_modules"
 - isengart/food-notification
time="2021-03-08T16:51:33+02:00" level=debug msg="Found dependencies for dockerfile: [{package.json /app true} {. /app true}]"
time="2021-03-08T16:51:33+02:00" level=debug msg="Skipping excluded path: node_modules"
 - isengart/food-client
time="2021-03-08T16:51:33+02:00" level=debug msg="Found dependencies for dockerfile: [{package.json /app true} {. /app true}]"
time="2021-03-08T16:51:41+02:00" level=info msg="List generated in 7.836 seconds"
Generating tags...
 - isengart/food-user -> time="2021-03-08T16:51:41+02:00" level=debug msg="Running command: [git describe --tags --always]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Running command: [git describe --tags --always]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Running command: [git describe --tags --always]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Running command: [git describe --tags --always]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Running command: [git describe --tags --always]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Running command: [git describe --tags --always]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Command output: [5192c74\n]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Command output: [5192c74\n]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Command output: [5192c74\n]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Command output: [5192c74\n]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Command output: [5192c74\n]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Command output: [5192c74\n]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Running command: [git status . --porcelain]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Running command: [git status . --porcelain]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Running command: [git status . --porcelain]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Running command: [git status . --porcelain]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Running command: [git status . --porcelain]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Running command: [git status . --porcelain]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Command output: []"
time="2021-03-08T16:51:41+02:00" level=debug msg="Command output: []"
time="2021-03-08T16:51:41+02:00" level=debug msg="Command output: []"
time="2021-03-08T16:51:41+02:00" level=debug msg="Command output: []"
time="2021-03-08T16:51:41+02:00" level=debug msg="Command output: []"
isengart/food-user:5192c74
 - isengart/food-restaurant -> isengart/food-restaurant:5192c74
 - isengart/food-menu -> time="2021-03-08T16:51:41+02:00" level=debug msg="Command output: []"
isengart/food-menu:5192c74
 - isengart/food-order -> isengart/food-order:5192c74
 - isengart/food-notification -> isengart/food-notification:5192c74
 - isengart/food-client -> isengart/food-client:5192c74
time="2021-03-08T16:51:41+02:00" level=info msg="Tags generated in 160.9964ms"
Checking cache...
time="2021-03-08T16:51:41+02:00" level=debug msg="Found dependencies for dockerfile: [{package.json /app true} {. /app true}]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Found dependencies for dockerfile: [{package.json /app true} {. /app true}]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Found dependencies for dockerfile: [{package.json /app true} {. /app true}]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Found dependencies for dockerfile: [{package.json /app true} {. /app true}]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Found dependencies for dockerfile: [{package.json /app true} {. /app true}]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Skipping excluded path: node_modules"
time="2021-03-08T16:51:41+02:00" level=debug msg="Found dependencies for dockerfile: [{package.json /app true} {. /app true}]"
time="2021-03-08T16:51:41+02:00" level=debug msg="Skipping excluded path: node_modules"
time="2021-03-08T16:51:41+02:00" level=debug msg="Skipping excluded path: node_modules"
time="2021-03-08T16:51:41+02:00" level=debug msg="Skipping excluded path: node_modules"
time="2021-03-08T16:51:41+02:00" level=debug msg="Skipping excluded path: node_modules"
time="2021-03-08T16:57:35+02:00" level=debug msg="Could not import artifact from Docker, building instead (import of missing images disabled)"
 - isengart/food-user: Found. Tagging
 - isengart/food-restaurant: Found. Tagging
 - isengart/food-menu: Found. Tagging
 - isengart/food-order: Found. Tagging
 - isengart/food-notification: Found. Tagging
 - isengart/food-client: Not found. Building
time="2021-03-08T16:57:35+02:00" level=info msg="Cache check completed in 5 minutes 53.973 seconds"
Found [docker-desktop] context, using local docker daemon.
Building [isengart/food-client]...
time="2021-03-08T16:57:35+02:00" level=debug msg="Running docker build: context: client, dockerfile: Dockerfile"
Sending build context to Docker daemon    370MB

The issue seems to be this time="2021-03-08T16:57:35+02:00" level=debug msg="Could not import artifact from Docker, building instead (import of missing images disabled)" . I dont know why it cant find it, but the image should exist locally.
I guess its duplicate of #4842 . The thing is that I have a terrible internet connection and I would prefer to not download the image every time by adding the tryImportMissing: true .

After the image rebuilt , I stopped skaffold with ctrl+c and pressed skaffold dev again it output exactly the same. Waited 6 minutes and redownload/rebuilt the food-client image. When I checked the Docker Desktop, the image with that specific tag already existed.

Lastly it seems that I currently have ~ 70 images of the food-client locally all generated from skaffold.

Is this a normal behavior ? I'm really sorry if I do any silly questions I'm really new with Docker/K8s/Skaffold and I dont have everything clear in my head yet !

MarlonGamez · 2021-03-17T18:58:13Z

Hey @isengartz, I believe skaffold should be pruning images from your hosts local docker daemon upon ctrl+cing, but this seems to not be working. I'll try to get some more information on this

briandealwis · 2021-06-04T19:07:16Z

@isengartz would it be possible to try to reproduce with Skaffold v1.25.0, our latest release? And if it does still happen, could you try some earlier releases to help pinpoint which change might be causing your issue?

isengartz · 2021-06-06T14:37:57Z

@briandealwis Using latest release , it builds instantly without further waiting !!

tejal29 · 2021-06-07T18:07:32Z

Thanks @isengartz. Closing this issue now. Please comment if you see this again.

briandealwis added the triage/needs-information Information requested label Mar 8, 2021

nkubala added area/cache kind/bug Something isn't working needs-reproduction needs reproduction from the maintainers to validate the issue is truly a skaffold bug priority/p2 May take a couple of releases labels Apr 1, 2021

tejal29 closed this as completed Jun 7, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Checking cache takes ages and rebuilds the whole image after each change #5499

Checking cache takes ages and rebuilds the whole image after each change #5499

isengartz commented Mar 6, 2021 •

edited

Loading

briandealwis commented Mar 8, 2021

briandealwis commented Mar 8, 2021

isengartz commented Mar 8, 2021

MarlonGamez commented Mar 17, 2021

briandealwis commented Jun 4, 2021

isengartz commented Jun 6, 2021

tejal29 commented Jun 7, 2021

Checking cache takes ages and rebuilds the whole image after each change #5499

Checking cache takes ages and rebuilds the whole image after each change #5499

Comments

isengartz commented Mar 6, 2021 • edited Loading

Expected behavior

Actual behavior

Information

Steps to reproduce the behavior

briandealwis commented Mar 8, 2021

briandealwis commented Mar 8, 2021

isengartz commented Mar 8, 2021

MarlonGamez commented Mar 17, 2021

briandealwis commented Jun 4, 2021

isengartz commented Jun 6, 2021

tejal29 commented Jun 7, 2021

isengartz commented Mar 6, 2021 •

edited

Loading