LoadImages in parallel

[medyagh]

When preloading is not available we should load the images in parallel:

checking the time stamps it takes considerable amount of seconds.

ge-provisioner_v1.8.1
I0310 18:36:05.380502   53440 cache_images.go:100] "k8s.gcr.io/etcd:3.4.3-0" needs transfer: "k8s.gcr.io/etcd:3.4.3-0" does not exist at hash "303ce5db0e90dab1c5728ec70d21091201a23cdf8aeca70ab54943bbaaf0833f" in container runtime
I0310 18:36:05.380565   53440 cache_images.go:211] Loading image from cache: /Users/medmac/.minikube/cache/images/k8s.gcr.io/etcd_3.4.3-0
I0310 18:36:05.435343   53440 containerd.go:236] Loading image: /var/lib/minikube/images/storage-provisioner_v1.8.1
I0310 18:36:05.620210   53440 cache_images.go:100] "k8s.gcr.io/kube-controller-manager:v1.17.3" needs transfer: "k8s.gcr.io/kube-controller-manager:v1.17.3" does not exist at hash "b0f1517c1f4bb153597033d2efd81a9ac630e6a569307f993b2c0368afcf0302" in container runtime
I0310 18:36:05.620261   53440 cache_images.go:211] Loading image from cache: /Users/medmac/.minikube/cache/images/k8s.gcr.io/kube-controller-manager_v1.17.3
I0310 18:36:05.816640   53440 cache_images.go:100] "k8s.gcr.io/kube-proxy:v1.17.3" needs transfer: "k8s.gcr.io/kube-proxy:v1.17.3" does not exist at hash "ae853e93800dc2572aeb425e5765cf9b25212bfc43695299e61dece06cffa4a1" in container runtime
I0310 18:36:05.816693   53440 cache_images.go:211] Loading image from cache: /Users/medmac/.minikube/cache/images/k8s.gcr.io/kube-proxy_v1.17.3
I0310 18:36:06.038944   53440 cache_images.go:100] "k8s.gcr.io/pause:3.1" needs transfer: "k8s.gcr.io/pause:3.1" does not exist at hash "da86e6ba6ca197bf6bc5e9d900febd906b133eaa4750e6bed647b0fbe50ed43e" in container runtime
I0310 18:36:06.039011   53440 cache_images.go:211] Loading image from cache: /Users/medmac/.minikube/cache/images/k8s.gcr.io/pause_3.1
I0310 18:36:06.224310   53440 cache_images.go:100] "k8s.gcr.io/coredns:1.6.5" needs transfer: "k8s.gcr.io/coredns:1.6.5" does not exist at hash "70f311871ae12c14bd0e02028f249f933f925e4370744e4e35f706da773a8f61" in container runtime
I0310 18:36:06.224357   53440 cache_images.go:211] Loading image from cache: /Users/medmac/.minikube/cache/images/k8s.gcr.io/coredns_1.6.5
I0310 18:36:06.406085   53440 cache_images.go:100] "k8s.gcr.io/kube-scheduler:v1.17.3" needs transfer: "k8s.gcr.io/kube-scheduler:v1.17.3" does not exist at hash "d109c0821a2b9225b69b99a95000df5cd1de5d606bc187b3620d730d7769c6ad" in container runtime
I0310 18:36:06.406136   53440 cache_images.go:211] Loading image from cache: /Users/medmac/.minikube/cache/images/k8s.gcr.io/kube-scheduler_v1.17.3
I0310 18:36:06.637809   53440 cache_images.go:100] "k8s.gcr.io/kube-apiserver:v1.17.3" needs transfer: "k8s.gcr.io/kube-apiserver:v1.17.3" does not exist at hash "90d27391b7808cde8d9a81cfa43b1e81de5c4912b4b52a7dccb19eb4fe3c236b" in container runtime
I0310 18:36:06.637871   53440 cache_images.go:211] Loading image from cache: /Users/medmac/.minikube/cache/images/k8s.gcr.io/kube-apiserver_v1.17.3
I0310 18:36:09.820182   53440 cache_images.go:100] "kubernetesui/dashboard:v2.0.0-beta8" needs transfer: "kubernetesui/dashboard:v2.0.0-beta8" does not exist at hash "eb51a359752560a66f314602e87155b75f428fb838bf951079ff1f9621958c0c" in container runtime
I0310 18:36:09.820229   53440 cache_images.go:211] Loading image from cache: /Users/medmac/.minikube/cache/images/kubernetesui/dashboard_v2.0.0-beta8
I0310 18:36:10.156399   53440 cache_images.go:100] "kubernetesui/metrics-scraper:v1.0.2" needs transfer: "kubernetesui/metrics-scraper:v1.0.2" does not exist at hash "3b08661dc379d9f80155be9d658f71578988640357ebae1aab287d6954c723d1" in container runtime
I0310 18:36:10.156449   53440 cache_images.go:211] Loading image from cache: /Users/medmac/.minikube/cache/images/kubernetesui/metrics-scraper_v1.0.2
I0310 18:36:20.395006   53440 kic_runner.go:117] Done: [docker exec --privileged containerd-20200306T154523.072896063-17429 sudo ctr -n=k8s.io images import /var/lib/minikube/images/storage-provisioner_v1.8.1]: (14.959648536s)
I0310 18:36:20.395067   53440 cache_images.go:233] Transferred and loaded /Users/medmac/.minikube/cache/images/gcr.io/k8s-minikube/storage-provisioner_v1.8.1 from cache
I0310 18:36:20.395097   53440 containerd.go:236] Loading image: /var/lib/minikube/images/etcd_3.4.3-0
I0310 18:36:28.880723   53440 kic_runner.go:117] Done: [docker exec --privileged containerd-20200306T154523.072896063-17429 sudo ctr -n=k8s.io images import /var/lib/minikube/images/etcd_3.4.3-0]: (8.485618537s)
I0310 18:36:28.880781   53440 cache_images.go:233] Transferred and loaded /Users/medmac/.minikube/cache/images/k8s.gcr.io/etcd_3.4.3-0 from cache
I0310 18:36:28.880808   53440 containerd.go:236] Loading image: /var/lib/minikube/images/kube-controller-manager_v1.17.3
I0310 18:36:35.351872   53440 kic_runner.go:117] Done: [docker exec --privileged containerd-20200306T154523.072896063-17429 sudo ctr -n=k8s.io images import /var/lib/minikube/images/kube-controller-manager_v1.17.3]: (6.471003275s)
I0310 18:36:35.351972   53440 cache_images.go:233] Transferred and loaded /Users/medmac/.minikube/cache/images/k8s.gcr.io/kube-controller-manager_v1.17.3 from cache
I0310 18:36:35.352009   53440 containerd.go:236] Loading image: /var/lib/minikube/images/kube-proxy_v1.17.3
I0310 18:36:46.243225   53440 kic_runner.go:117] Done: [docker exec --privileged containerd-20200306T154523.072896063-17429 sudo ctr -n=k8s.io images import /var/lib/minikube/images/kube-proxy_v1.17.3]: (10.891230669s)
I0310 18:36:46.243288   53440 cache_images.go:233] Transferred and loaded /Users/medmac/.minikube/cache/images/k8s.gcr.io/kube-proxy_v1.17.3 from cache
I0310 18:36:46.243318   53440 containerd.go:236] Loading image: /var/lib/minikube/images/pause_3.1
I0310 18:36:46.595719   53440 cache_images.go:233] Transferred and loaded /Users/medmac/.minikube/cache/images/k8s.gcr.io/pause_3.1 from cache
I0310 18:36:46.595821   53440 containerd.go:236] Loading image: /var/lib/minikube/images/coredns_1.6.5
I0310 18:36:48.084810   53440 kic_runner.go:117] Done: [docker exec --privileged containerd-20200306T154523.072896063-17429 sudo ctr -n=k8s.io images import /var/lib/minikube/images/coredns_1.6.5]: (1.488759235s)
I0310 18:36:48.084927   53440 cache_images.go:233] Transferred and loaded /Users/medmac/.minikube/cache/images/k8s.gcr.io/coredns_1.6.5 from cache
I0310 18:36:48.085040   53440 containerd.go:236] Loading image: /var/lib/minikube/images/kube-scheduler_v1.17.3
I0310 18:36:50.020397   53440 kic_runner.go:117] Done: [docker exec --privileged containerd-20200306T154523.072896063-17429 sudo ctr -n=k8s.io images import /var/lib/minikube/images/kube-scheduler_v1.17.3]: (1.935106514s)
I0310 18:36:50.020459   53440 cache_images.go:233] Transferred and loaded /Users/medmac/.minikube/cache/images/k8s.gcr.io/kube-scheduler_v1.17.3 from cache
I0310 18:36:50.020497   53440 containerd.go:236] Loading image: /var/lib/minikube/images/kube-apiserver_v1.17.3
I0310 18:36:53.507321   53440 kic_runner.go:117] Done: [docker exec --privileged containerd-20200306T154523.072896063-17429 sudo ctr -n=k8s.io images import /var/lib/minikube/images/kube-apiserver_v1.17.3]: (3.486666341s)
I0310 18:36:53.507403   53440 cache_images.go:233] Transferred and loaded /Users/medmac/.minikube/cache/images/k8s.gcr.io/kube-apiserver_v1.17.3 from cache
I0310 18:36:53.507440   53440 containerd.go:236] Loading image: /var/lib/minikube/images/dashboard_v2.0.0-beta8
I0310 18:36:56.444391   53440 kic_runner.go:117] Done: [docker exec --privileged containerd-20200306T154523.072896063-17429 sudo ctr -n=k8s.io images import /var/lib/minikube/images/dashboard_v2.0.0-beta8]: (2.93676958s)
I0310 18:36:56.444475   53440 cache_images.go:233] Transferred and loaded /Users/medmac/.minikube/cache/images/kubernetesui/dashboard_v2.0.0-beta8 from cache
I0310 18:36:56.444520   53440 containerd.go:236] Loading image: /var/lib/minikube/images/metrics-scraper_v1.0.2
I0310 18:36:57.907007   53440 kic_runner.go:117] Done: [docker exec --privileged containerd-20200306T154523.072896063-17429 sudo ctr -n=k8s.io images import /var/lib/minikube/images/metrics-scraper_v1.0.2]: (1.462271611s)
I0310 18:36:57.907067   53440 cache_images.go:233] Transferred and loaded /Users/medmac/.minikube/cache/images/kubernetesui/metrics-scraper_v1.0.2 from cache
I0310 18:36:57.907099   53440 cache_images.go:107] Successfully loaded all cached images
I0310 18:36:57.907110   53440 cache_images.go:78] LoadImages completed in 54.827512543s
I0310 18:36:57.907253   53440 kubeadm.go:125] kubeadm options: {CertDir:/var/lib/minikube/certs ServiceCIDR:10.96.0.0/12 PodSubnet:10.244.0.0/16 AdvertiseAddress:172.17.0.2 APIServerPort:8444 KubernetesVersion:v1.17.3 EtcdDataDir:/var/lib/minikube/etcd ClusterName:containerd-20200306T154523.072896063-17429 NodeName:m01 DNSDomain:cluster.local CRISocket:/run/containerd/containerd.sock ImageRepository: ComponentOptions:[{Component:apiServer ExtraArgs:map[enable-admission-plugins:NamespaceLifecycle,LimitRanger,ServiceAccount,DefaultStorageClass,DefaultTolerationSeconds,NodeRestriction,MutatingAdmissionWebhook,ValidatingAdmissionWebhook,ResourceQuota] 

[afbjorklund]

This was added for the podman loader, since it ran out of memory loading all at once: 98a2a55

Then it got added also to the docker loader by mistake, when we introduced cruntime: 966b245

The docker daemon should take care of handling multiple loads at once, internally...

But with podman, we need to keep an eye on the total load (mostly memory and i/o)

[afbjorklund]

It might be possible to do e.g. two at a time, so perhaps the mutex can be a made into a pool.

pkg/minikube/machine/cache_images.go:// loadImageLock is used to serialize image loads to avoid overloading the guest VM
pkg/minikube/machine/cache_images.go:var loadImageLock sync.Mutex

The docker load should probably still do all at once, but for podman this might improve things ?

[medyagh]

Thanks for the great investigattive history @afbjorklund

We should totally make it parallel again for docker and not parallel for podman

[afbjorklund]

There were some awful bugs when loading multiple images from the same tarball (like in #6934)

EDIT: in libpod, that was

I hope those are fixed, or else we will end up having to disable preload as well (load from multiple)

UPDATE: seems not

[afbjorklund]

Most likely this will change to making a flexible worker pool of image loaders, instead of a mutex.

[fejta-bot]

Issues go stale after 90d of inactivity.
Mark the issue as fresh with /remove-lifecycle stale.
Stale issues rot after an additional 30d of inactivity and eventually close.

If this issue is safe to close now please do so with /close.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/lifecycle stale

[fejta-bot]

Stale issues rot after 30d of inactivity.
Mark the issue as fresh with /remove-lifecycle rotten.
Rotten issues close after an additional 30d of inactivity.

If this issue is safe to close now please do so with /close.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/lifecycle rotten

[fejta-bot]

Rotten issues close after 30d of inactivity.
Reopen the issue with /reopen.
Mark the issue as fresh with /remove-lifecycle rotten.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/close

[k8s-ci-robot]

@fejta-bot: Closing this issue.

In response to this:

Rotten issues close after 30d of inactivity.
Reopen the issue with /reopen.
Mark the issue as fresh with /remove-lifecycle rotten.

Send feedback to sig-testing, kubernetes/test-infra and/or fejta.
/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.