Closed plnordquist closed 4 years ago
@plnordquist thanks for creaitng this issue, I am not sure what is the root cause of this, but have u tried minikube delete and start again ?
I am wondering if minikube is trying to reuse the older version of container that had a different image
I also see this:
I0512 13:11:14.800630 1596 oci.go:544] error shutdown minikube: docker exec --privileged -t minikube /bin/bash -c "sudo init 0": exit status 1
that makes me believe the container was not able to shutdown and it was stuck, you might want to restart docker.
do you mind sharing how much RAM your docker desktop has ?
My docker desktop has 2GB of ram. If I factory reset my Docker Desktop, minikube can start successfully. Once I minikube stop, minikube delete, and minikube start again, it fails to start with the same container logs I posted in the initial post. I upgraded to v1.10.1 to test this again and I'm seeing the same behavior. Here's some more logs of the successful start and the failed start. I'm running Docker Desktop Edge v2.3.0.1 with the Hyper-V backend. In the failure scenario, minikube logs
fails to produce output since the minikube docker container is stopped and the control plane is not running.
Good minikube start --alsologtostderr
logs:
Good minikube logs
output:
Good docker logs minikube
output from host:
Bad minikube start --alsologtostderr
logs:
Bad docker logs minikube
output from host:
@plnordquist minikube needs min 2GB ram, and your docker desktop has only 2 GB ram shared across all docker containers, I suggest resize your docker desktop to have at least 4 or 6GB ram and try again. do you mind checking if that will fix the problem?
plus the logs from your second start shows that the start was actually healthy !
* Done! kubectl is now configured to use "minikube"
OK I updated the ram for Docker Desktop to 6GB and that didn't work. I found another issue like this one at #7885 and then went down a rabbit hole trying to figure this out since factory resetting Docker Desktop didn't work 100% of the time.
The behavior that works is if I clear the shared preloaded tarball from the file sharing configuration of Docker Desktop and then cancel the request to share the tarball to the container, minikube can start successfully since it uses scp later in the process to copy the tarball into the running container.
I think this might have started in commit https://github.com/kubernetes/minikube/commit/b509d691 since it changed the order of operations. Prior to that commit the main minikube container would have been started and the minikube volume would be initialized from the /var
directory of the kicbase image. In that commit, the order of operations changes and now there is an asynchronous race to initialize the minikube volume from either /var
or /extractDir
and that is why when I don't immediately allow docker to share the preloaded tarball or cancel the sharing request the process succeeds where if the tarball is previously shared it will fail.
In the current version of the code beyond the commit referenced above, the Podman driver doesn't even attempt to cache the preloaded images so it avoids this issue and thus #7885 no longer applies.
I've attached a set of logs that show the error that appears when I cancel the file sharing request, it is not fatal to the minikube start
command and the cluster successfully starts.
Good minikube start --alsologtostderr
logs where sharing is cancelled:
The behavior that works is if I clear the shared preloaded tarball from the file sharing configuration of Docker Desktop and then cancel the request to share the tarball to the container, minikube can start successfully since it uses scp later in the process to copy the tarball into the running container.
@plnordquist interesting!!! thank you very much for providing this amount of detail ! good detective work ! so if you accept the Docke Desktop File Sharing then it wont work ? and it works when you disable the file sharing ? I wonder what happens if u disable preload with the file sharing
if you disable preload, would it work without any issues ?
minikube delete
minikube start --driver=docker --preload=false
Yes using minikube start --driver=docker --preload=false
works without any issues every time. I've used it and minikube delete
a few times now and it successfully creates a minikube instance. I think it might be a little slower but minikube ends up caching images and kubernetes binaries so it's not as slow as waiting for docker in the container to pull the images.
thank you @plnordquist for reporting this, this is a bug. I wonder if we can find a Non-UI way to prevent docker to asking to share the folder with Docker Desktop ?
I also seen that notification on windows, whe minikube starts, docker desktop Asks to share file
Seems like the same type of race conditions, that we have with the podman driver. (see #8056)
I think the best long-term solution would be to just stop mounting all of /var
as a volume... ?
My suggestion is to move /var into a subdirectory of the volume, and then mount it somewhere. Then you can do /var/lib/minikube and friends, either as bind mounts or as regular symlinks ?
The same we do it for the ISO. This also gives us a place to fix the storage driver persistence... If we worry about backwards compatibility, we could set up some symlinks on existing volumes.
here is full log
PS C:\Users\medya\Downloads> docker ps
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
PS C:\Users\medya\Downloads> .\minikube-windows-amd64v_1_11.exe start --driver=docker --alsologtostderr
I0603 17:54:22.358989 7164 start.go:98] hostinfo: {"hostname":"MEDYA1-W","uptime":143,"bootTime":1591231919,"procs":230,"os":"windows","platform":"Microsoft Windows 10 Enterprise","platformFamily":"Standalone Workstation","platformVersion":"10.0.18362 Build 18362","kernelVersion":"","virtualizationSystem":"","virtualizationRole":"","hostid":"b4effa11-ef54-47d5-b2e4-c3a0780dd0d2"}
W0603 17:54:22.359987 7164 start.go:106] gopshost.Virtualization returned error: not implemented yet
* minikube v1.11.0 on Microsoft Windows 10 Enterprise 10.0.18362 Build 18362
I0603 17:54:22.367968 7164 notify.go:125] Checking for updates...
I0603 17:54:22.367968 7164 driver.go:253] Setting default libvirt URI to qemu:///system
I0603 17:54:23.033424 7164 docker.go:95] docker version: linux-19.03.8
* Using the docker driver based on user configuration
I0603 17:54:23.035422 7164 start.go:214] selected driver: docker
I0603 17:54:23.035422 7164 start.go:611] validating driver "docker" against <nil>
I0603 17:54:23.035422 7164 start.go:617] status for docker: {Installed:true Healthy:true Error:<nil> Fix: Doc:}
I0603 17:54:23.036419 7164 start.go:935] auto setting extra-config to "kubeadm.pod-network-cidr=10.244.0.0/16".
I0603 17:54:23.036419 7164 start_flags.go:218] no existing cluster config was found, will generate one from the flags
I0603 17:54:23.041408 7164 cli_runner.go:108] Run: docker system info --format "{{json .}}"
I0603 17:54:25.611451 7164 cli_runner.go:150] Completed: docker system info --format "{{json .}}": (2.5759999s)
I0603 17:54:25.611451 7164 start_flags.go:232] Using suggested 8100MB memory alloc based on sys=32619MB, container=9970MB
I0603 17:54:25.613451 7164 start_flags.go:556] Wait components to verify : map[apiserver:true system_pods:true]
* Starting control plane node minikube in cluster minikube
I0603 17:54:25.616439 7164 cache.go:105] Beginning downloading kic artifacts for docker with docker
I0603 17:54:26.281893 7164 image.go:88] Found gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438 in local docker daemon, skipping pull
I0603 17:54:26.281893 7164 preload.go:95] Checking if preload exists for k8s version v1.18.3 and runtime docker
I0603 17:54:26.284888 7164 preload.go:103] Found local preload: C:\Users\medya\.minikube\cache\preloaded-tarball\preloaded-images-k8s-v3-v1.18.3-docker-overlay2-amd64.tar.lz4
I0603 17:54:26.284888 7164 cache.go:49] Caching tarball of preloaded images
I0603 17:54:26.286883 7164 preload.go:129] Found C:\Users\medya\.minikube\cache\preloaded-tarball\preloaded-images-k8s-v3-v1.18.3-docker-overlay2-amd64.tar.lz4 in cache, skipping download
I0603 17:54:26.286883 7164 cache.go:52] Finished verifying existence of preloaded tar for v1.18.3 on docker
I0603 17:54:26.287880 7164 profile.go:156] Saving config to C:\Users\medya\.minikube\profiles\minikube\config.json ...
I0603 17:54:26.289877 7164 lock.go:35] WriteFile acquiring C:\Users\medya\.minikube\profiles\minikube\config.json: {Name:mk1eb288c63b7363cab0f1c3ec04745eaac56c9e Clock:{} Delay:500ms Timeout:1m0s Cancel:<nil>}
I0603 17:54:26.295861 7164 cache.go:152] Successfully downloaded all kic artifacts
I0603 17:54:26.295861 7164 start.go:240] acquiring machines lock for minikube: {Name:mkb5fc01d338b8709271974409864786bd6beddc Clock:{} Delay:500ms Timeout:15m0s Cancel:<nil>}
I0603 17:54:26.295861 7164 start.go:244] acquired machines lock for "minikube" in 0s
I0603 17:54:26.295861 7164 start.go:84] Provisioning new machine with config: &{Name:minikube KeepContext:false EmbedCerts:false MinikubeISO: KicBaseImage:gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438 Memory:8100 CPUs:2 DiskSize:20000 Driver:docker HyperkitVpnKitSock: HyperkitVSockPorts:[] DockerEnv:[] InsecureRegistry:[] RegistryMirror:[] HostOnlyCIDR:192.168.99.1/24 HypervVirtualSwitch: HypervUseExternalSwitch:false HypervExternalAdapter: KVMNetwork:default KVMQemuURI:qemu:///system KVMGPU:false KVMHidden:false DockerOpt:[] DisableDriverMounts:false NFSShare:[] NFSSharesRoot:/nfsshares UUID: NoVTXCheck:false DNSProxy:false HostDNSResolver:true HostOnlyNicType:virtio NatNicType:virtio KubernetesConfig:{KubernetesVersion:v1.18.3 ClusterName:minikube APIServerName:minikubeCA APIServerNames:[] APIServerIPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin: FeatureGates: ServiceCIDR:10.96.0.0/12 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: ExtraOptions:[{Component:kubeadm Key:pod-network-cidr Value:10.244.0.0/16}] ShouldLoadCachedImages:true EnableDefaultCNI:false NodeIP: NodePort:8443 NodeName:} Nodes:[{Name: IP: Port:8443 KubernetesVersion:v1.18.3 ControlPlane:true Worker:true}] Addons:map[] VerifyComponents:map[apiserver:true system_pods:true]} &{Name: IP: Port:8443 KubernetesVersion:v1.18.3 ControlPlane:true Worker:true}
I0603 17:54:26.296861 7164 start.go:121] createHost starting for "" (driver="docker")
* Creating docker container (CPUs=2, Memory=8100MB) ...
I0603 17:54:26.299853 7164 start.go:157] libmachine.API.Create for "minikube" (driver="docker")
I0603 17:54:26.299853 7164 client.go:161] LocalClient.Create starting
I0603 17:54:26.300849 7164 main.go:110] libmachine: Reading certificate data from C:\Users\medya\.minikube\certs\ca.pem
I0603 17:54:26.304842 7164 main.go:110] libmachine: Decoding PEM data...
I0603 17:54:26.306841 7164 main.go:110] libmachine: Parsing certificate...
I0603 17:54:26.307836 7164 main.go:110] libmachine: Reading certificate data from C:\Users\medya\.minikube\certs\cert.pem
I0603 17:54:26.311828 7164 main.go:110] libmachine: Decoding PEM data...
I0603 17:54:26.311828 7164 main.go:110] libmachine: Parsing certificate...
I0603 17:54:26.332777 7164 cli_runner.go:108] Run: docker ps -a --format {{.Names}}
I0603 17:54:27.009208 7164 cli_runner.go:108] Run: docker volume create minikube --label name.minikube.sigs.k8s.io=minikube --label created_by.minikube.sigs.k8s.io=true
I0603 17:54:27.675663 7164 oci.go:98] Successfully created a docker volume minikube
I0603 17:54:27.675663 7164 preload.go:95] Checking if preload exists for k8s version v1.18.3 and runtime docker
I0603 17:54:27.676661 7164 preload.go:103] Found local preload: C:\Users\medya\.minikube\cache\preloaded-tarball\preloaded-images-k8s-v3-v1.18.3-docker-overlay2-amd64.tar.lz4
I0603 17:54:27.677661 7164 kic.go:134] Starting extracting preloaded images to volume ...
I0603 17:54:27.682647 7164 cli_runner.go:108] Run: docker system info --format "{{json .}}"
I0603 17:54:27.683645 7164 cli_runner.go:108] Run: docker run --rm --entrypoint /usr/bin/tar -v C:\Users\medya\.minikube\cache\preloaded-tarball\preloaded-images-k8s-v3-v1.18.3-docker-overlay2-amd64.tar.lz4:/preloaded.tar:ro -v minikube:/extractDir gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438 -I lz4 -xvf /preloaded.tar -C /extractDir
I0603 17:54:30.251229 7164 cli_runner.go:150] Completed: docker system info --format "{{json .}}": (2.5745355s)
I0603 17:54:30.257214 7164 cli_runner.go:108] Run: docker info --format "'{{json .SecurityOptions}}'"
I0603 17:54:32.866121 7164 cli_runner.go:150] Completed: docker info --format "'{{json .SecurityOptions}}'": (2.6149541s)
I0603 17:54:32.874102 7164 cli_runner.go:108] Run: docker run -d -t --privileged --security-opt seccomp=unconfined --security-opt apparmor=unconfined --tmpfs /tmp --tmpfs /run -v /lib/modules:/lib/modules:ro --hostname minikube --name minikube --label created_by.minikube.sigs.k8s.io=true --label name.minikube.sigs.k8s.io=minikube --label role.minikube.sigs.k8s.io= --label mode.minikube.sigs.k8s.io=minikube --volume minikube:/var --cpus=2 --memory=8100mb -e container=docker --expose 8443 --publish=127.0.0.1::8443 --publish=127.0.0.1::22 --publish=127.0.0.1::2376 --publish=127.0.0.1::5000 gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438
I0603 17:54:34.445362 7164 cli_runner.go:150] Completed: docker run -d -t --privileged --security-opt seccomp=unconfined --security-opt apparmor=unconfined --tmpfs /tmp --tmpfs /run -v /lib/modules:/lib/modules:ro --hostname minikube --name minikube --label created_by.minikube.sigs.k8s.io=true --label name.minikube.sigs.k8s.io=minikube --label role.minikube.sigs.k8s.io= --label mode.minikube.sigs.k8s.io=minikube --volume minikube:/var --cpus=2 --memory=8100mb -e container=docker --expose 8443 --publish=127.0.0.1::8443 --publish=127.0.0.1::22 --publish=127.0.0.1::2376 --publish=127.0.0.1::5000 gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438: (1.5749013s)
I0603 17:54:34.452345 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:35.155019 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:35.338595 7164 cli_runner.go:150] Completed: docker run --rm --entrypoint /usr/bin/tar -v C:\Users\medya\.minikube\cache\preloaded-tarball\preloaded-images-k8s-v3-v1.18.3-docker-overlay2-amd64.tar.lz4:/preloaded.tar:ro -v minikube:/extractDir gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438 -I lz4 -xvf /preloaded.tar -C /extractDir: (7.6726925s)
I0603 17:54:35.338595 7164 kic.go:139] duration metric: took 7.678690 seconds to extract preloaded images to volume
I0603 17:54:35.845418 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:36.541385 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:37.238016 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:37.950889 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:38.715779 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:39.457061 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:40.260200 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:41.106779 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:42.157644 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:43.563419 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:45.684290 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:47.538319 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:54:48.183956 7164 client.go:164] LocalClient.Create took 21.9338269s
I0603 17:54:50.180043 7164 start.go:124] duration metric: createHost completed in 23.9385386s
I0603 17:54:50.180043 7164 start.go:75] releasing machines lock for "minikube", held for 23.9395405s
I0603 17:54:50.195999 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Status}}
I0603 17:54:50.850454 7164 stop.go:36] StopHost: minikube
* Stopping "minikube" in docker ...
I0603 17:54:50.871209 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Status}}
I0603 17:54:51.509795 7164 stop.go:76] host is in state Stopped
I0603 17:54:51.509795 7164 main.go:110] libmachine: Stopping "minikube"...
I0603 17:54:51.520762 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Status}}
I0603 17:54:52.166057 7164 stop.go:56] stop err: Machine "minikube" is already stopped.
I0603 17:54:52.166057 7164 stop.go:59] host is already stopped
* Deleting "minikube" in docker ...
I0603 17:54:53.183364 7164 cli_runner.go:108] Run: docker container inspect -f {{.Id}} minikube
I0603 17:54:53.830232 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Status}}
I0603 17:54:54.476612 7164 cli_runner.go:108] Run: docker exec --privileged -t minikube /bin/bash -c "sudo init 0"
I0603 17:54:55.125628 7164 oci.go:544] error shutdown minikube: docker exec --privileged -t minikube /bin/bash -c "sudo init 0": exit status 1
stdout:
stderr:
Error response from daemon: Container 3619f149a785c9f0a679e00a5f750b2a8047a784a80c3a83ee2e8aae30ecbd64 is not running
I0603 17:54:56.128334 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Status}}
I0603 17:54:56.772808 7164 oci.go:552] container minikube status is Stopped
I0603 17:54:56.772808 7164 oci.go:564] Successfully shutdown container minikube
I0603 17:54:56.778823 7164 cli_runner.go:108] Run: docker rm -f -v minikube
I0603 17:54:57.448846 7164 cli_runner.go:108] Run: docker container inspect -f {{.Id}} minikube
! StartHost failed, but will try again: creating host: create: creating: create kic node: check container "minikube" running: temporary error created container "minikube" is not running yet
I0603 17:55:03.083118 7164 start.go:240] acquiring machines lock for minikube: {Name:mkb5fc01d338b8709271974409864786bd6beddc Clock:{} Delay:500ms Timeout:15m0s Cancel:<nil>}
I0603 17:56:41.759287 7164 start.go:244] acquired machines lock for "minikube" in 0s
I0603 17:56:41.770332 7164 start.go:84] Provisioning new machine with config: &{Name:minikube KeepContext:false EmbedCerts:false MinikubeISO: KicBaseImage:gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438 Memory:8100 CPUs:2 DiskSize:20000 Driver:docker HyperkitVpnKitSock: HyperkitVSockPorts:[] DockerEnv:[] InsecureRegistry:[] RegistryMirror:[] HostOnlyCIDR:192.168.99.1/24 HypervVirtualSwitch: HypervUseExternalSwitch:false HypervExternalAdapter: KVMNetwork:default KVMQemuURI:qemu:///system KVMGPU:false KVMHidden:false DockerOpt:[] DisableDriverMounts:false NFSShare:[] NFSSharesRoot:/nfsshares UUID: NoVTXCheck:false DNSProxy:false HostDNSResolver:true HostOnlyNicType:virtio NatNicType:virtio KubernetesConfig:{KubernetesVersion:v1.18.3 ClusterName:minikube APIServerName:minikubeCA APIServerNames:[] APIServerIPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin: FeatureGates: ServiceCIDR:10.96.0.0/12 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: ExtraOptions:[{Component:kubeadm Key:pod-network-cidr Value:10.244.0.0/16}] ShouldLoadCachedImages:true EnableDefaultCNI:false NodeIP: NodePort:8443 NodeName:} Nodes:[{Name: IP: Port:8443 KubernetesVersion:v1.18.3 ControlPlane:true Worker:true}] Addons:map[] VerifyComponents:map[apiserver:true system_pods:true]} &{Name: IP: Port:8443 KubernetesVersion:v1.18.3 ControlPlane:true Worker:true}
I0603 17:56:41.770332 7164 start.go:121] createHost starting for "" (driver="docker")
* Creating docker container (CPUs=2, Memory=8100MB) ...
I0603 17:56:41.772351 7164 start.go:157] libmachine.API.Create for "minikube" (driver="docker")
I0603 17:56:41.772351 7164 client.go:161] LocalClient.Create starting
I0603 17:56:41.772351 7164 main.go:110] libmachine: Reading certificate data from C:\Users\medya\.minikube\certs\ca.pem
I0603 17:56:41.775349 7164 main.go:110] libmachine: Decoding PEM data...
I0603 17:56:41.775349 7164 main.go:110] libmachine: Parsing certificate...
I0603 17:56:41.775349 7164 main.go:110] libmachine: Reading certificate data from C:\Users\medya\.minikube\certs\cert.pem
I0603 17:56:41.776319 7164 main.go:110] libmachine: Decoding PEM data...
I0603 17:56:41.776319 7164 main.go:110] libmachine: Parsing certificate...
I0603 17:56:41.789289 7164 cli_runner.go:108] Run: docker ps -a --format {{.Names}}
I0603 17:56:42.443503 7164 cli_runner.go:108] Run: docker volume create minikube --label name.minikube.sigs.k8s.io=minikube --label created_by.minikube.sigs.k8s.io=true
I0603 17:56:43.091034 7164 oci.go:98] Successfully created a docker volume minikube
I0603 17:56:43.091034 7164 preload.go:95] Checking if preload exists for k8s version v1.18.3 and runtime docker
I0603 17:56:43.092032 7164 preload.go:103] Found local preload: C:\Users\medya\.minikube\cache\preloaded-tarball\preloaded-images-k8s-v3-v1.18.3-docker-overlay2-amd64.tar.lz4
I0603 17:56:43.092999 7164 kic.go:134] Starting extracting preloaded images to volume ...
I0603 17:56:43.095994 7164 cli_runner.go:108] Run: docker system info --format "{{json .}}"
I0603 17:56:43.097989 7164 cli_runner.go:108] Run: docker run --rm --entrypoint /usr/bin/tar -v C:\Users\medya\.minikube\cache\preloaded-tarball\preloaded-images-k8s-v3-v1.18.3-docker-overlay2-amd64.tar.lz4:/preloaded.tar:ro -v minikube:/extractDir gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438 -I lz4 -xvf /preloaded.tar -C /extractDir
I0603 17:56:45.660100 7164 cli_runner.go:150] Completed: docker system info --format "{{json .}}": (2.5700497s)
I0603 17:56:45.665088 7164 cli_runner.go:108] Run: docker info --format "'{{json .SecurityOptions}}'"
I0603 17:56:48.221911 7164 cli_runner.go:150] Completed: docker info --format "'{{json .SecurityOptions}}'": (2.5627484s)
I0603 17:56:48.226865 7164 cli_runner.go:108] Run: docker run -d -t --privileged --security-opt seccomp=unconfined --security-opt apparmor=unconfined --tmpfs /tmp --tmpfs /run -v /lib/modules:/lib/modules:ro --hostname minikube --name minikube --label created_by.minikube.sigs.k8s.io=true --label name.minikube.sigs.k8s.io=minikube --label role.minikube.sigs.k8s.io= --label mode.minikube.sigs.k8s.io=minikube --volume minikube:/var --cpus=2 --memory=8100mb -e container=docker --expose 8443 --publish=127.0.0.1::8443 --publish=127.0.0.1::22 --publish=127.0.0.1::2376 --publish=127.0.0.1::5000 gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438
I0603 17:56:49.731434 7164 cli_runner.go:150] Completed: docker run -d -t --privileged --security-opt seccomp=unconfined --security-opt apparmor=unconfined --tmpfs /tmp --tmpfs /run -v /lib/modules:/lib/modules:ro --hostname minikube --name minikube --label created_by.minikube.sigs.k8s.io=true --label name.minikube.sigs.k8s.io=minikube --label role.minikube.sigs.k8s.io= --label mode.minikube.sigs.k8s.io=minikube --volume minikube:/var --cpus=2 --memory=8100mb -e container=docker --expose 8443 --publish=127.0.0.1::8443 --publish=127.0.0.1::22 --publish=127.0.0.1::2376 --publish=127.0.0.1::5000 gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438: (1.5080563s)
I0603 17:56:49.737418 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:56:50.321972 7164 cli_runner.go:150] Completed: docker run --rm --entrypoint /usr/bin/tar -v C:\Users\medya\.minikube\cache\preloaded-tarball\preloaded-images-k8s-v3-v1.18.3-docker-overlay2-amd64.tar.lz4:/preloaded.tar:ro -v minikube:/extractDir gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438 -I lz4 -xvf /preloaded.tar -C /extractDir: (7.2407274s)
I0603 17:56:50.321972 7164 kic.go:139] duration metric: took 7.245729 seconds to extract preloaded images to volume
I0603 17:56:50.414140 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:56:51.081381 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:56:51.762519 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:56:52.448253 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:56:53.143576 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:56:53.910601 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:56:54.663396 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:56:55.471023 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:56:56.406370 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:56:57.596336 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:56:59.269524 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:57:00.809654 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:57:02.794544 7164 cli_runner.go:108] Run: docker container inspect minikube --format={{.State.Running}}
I0603 17:57:03.438640 7164 client.go:164] LocalClient.Create took 21.7165073s
I0603 17:57:05.434030 7164 start.go:124] duration metric: createHost completed in 23.7185457s
I0603 17:57:05.434030 7164 start.go:75] releasing machines lock for "minikube", held for 23.7195204s
* Failed to start docker container. "minikube start" may fix it: creating host: create: creating: create kic node: check container "minikube" running: temporary error created container "minikube" is not running yet
I0603 17:57:05.436028 7164 exit.go:58] WithError(error provisioning host)=Failed to start host: creating host: create: creating: create kic node: check container "minikube" running: temporary error created container "minikube" is not running yet called from:
goroutine 1 [running]:
runtime/debug.Stack(0x40acf1, 0x18d85a0, 0x18bd240)
/usr/local/go/src/runtime/debug/stack.go:24 +0xa4
k8s.io/minikube/pkg/minikube/exit.WithError(0x1b44a0c, 0x17, 0x1e16f20, 0xc0008cc420)
/app/pkg/minikube/exit/exit.go:58 +0x3b
k8s.io/minikube/cmd/minikube/cmd.runStart(0x2b6c200, 0xc000128520, 0x0, 0x2)
/app/cmd/minikube/cmd/start.go:169 +0xac9
github.com/spf13/cobra.(*Command).execute(0x2b6c200, 0xc000128500, 0x2, 0x2, 0x2b6c200, 0xc000128500)
/go/pkg/mod/github.com/spf13/cobra@v1.0.0/command.go:846 +0x2b1
github.com/spf13/cobra.(*Command).ExecuteC(0x2b710c0, 0x0, 0x0, 0xc000004e01)
/go/pkg/mod/github.com/spf13/cobra@v1.0.0/command.go:950 +0x350
github.com/spf13/cobra.(*Command).Execute(...)
/go/pkg/mod/github.com/spf13/cobra@v1.0.0/command.go:887
k8s.io/minikube/cmd/minikube/cmd.Execute()
/app/cmd/minikube/cmd/root.go:112 +0x6f5
main.main()
/app/cmd/minikube/main.go:66 +0xf1
W0603 17:57:05.437026 7164 out.go:201] error provisioning host: Failed to start host: creating host: create: creating: create kic node: check container "minikube" running: temporary error created container "minikube" is not running yet
*
X error provisioning host: Failed to start host: creating host: create: creating: create kic node: check container "minikube" running: temporary error created container "minikube" is not running yet
*
* minikube is exiting due to an error. If the above message is not useful, open an issue:
- https://github.com/kubernetes/minikube/issues/new/choose
@afbjorklund the current two docker run commands are these:
docker run -d -t --privileged
--security-opt seccomp=unconfined \
--security-opt apparmor=unconfined \
--tmpfs /tmp --tmpfs /run \
-v /lib/modules:/lib/modules:ro --hostname minikube \
--name minikube --label created_by.minikube.sigs.k8s.io=true \
--label name.minikube.sigs.k8s.io=minikube \
--label role.minikube.sigs.k8s.io= --label mode.minikube.sigs.k8s.io=minikube \
--volume minikube:/var \
--cpus=2 --memory=3900mb \
-e container=docker \
--expose 8443 \
--publish=127.0.0.1::8443 \
--publish=127.0.0.1::22 \
--publish=127.0.0.1::2376 \
--publish=127.0.0.1::5000 \
gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438
and
docker run --rm --entrypoint /usr/bin/tar -v C:\Users\<user>\.minikube\cache\preloaded-tarball\preloaded-images-k8s-v3-v1.18.1-docker-overlay2-amd64.tar.lz4:/preloaded.tar:ro -v minikube:/extractDir gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438 -I lz4 -xvf /preloaded.tar -C /extractDir
if you can explain how we can do it without race condition , we could implement that way
@medyagh : If we use a custom mountpoint also in the first run, then the /var files will stay in image... So there is no need to copy e.g. /var/lib/dpkg, from the ubuntu layer to the minikube volume, anymore
But just like on the VM, we then need to creating the necessary symlinks or bindmounts to the mount So in this case we would need something like the minikube-automount, in order to do the proper setup.
mkdir -p /var/lib
mkdir -p /mnt/$PARTNAME/var/lib/boot2docker
mkdir /var/lib/boot2docker
mount --bind /mnt/$PARTNAME/var/lib/boot2docker /var/lib/boot2docker
mkdir -p /mnt/$PARTNAME/var/lib/docker
mkdir -p /var/lib/docker
mount --bind /mnt/$PARTNAME/var/lib/docker /var/lib/docker
mkdir -p /mnt/$PARTNAME/var/lib/containerd
mkdir -p /var/lib/containerd
mount --bind /mnt/$PARTNAME/var/lib/containerd /var/lib/containerd
mkdir -p /mnt/$PARTNAME/var/lib/containers
mkdir -p /var/lib/containers
mount --bind /mnt/$PARTNAME/var/lib/containers /var/lib/containers
mkdir -p /mnt/$PARTNAME/var/log
mkdir /var/log
mount --bind /mnt/$PARTNAME/var/log /var/log
mkdir -p /mnt/$PARTNAME/var/tmp
mkdir /var/tmp
mount --bind /mnt/$PARTNAME/var/tmp /var/tmp
mkdir -p /mnt/$PARTNAME/var/lib/kubelet
mkdir /var/lib/kubelet
mount --bind /mnt/$PARTNAME/var/lib/kubelet /var/lib/kubelet
mkdir -p /mnt/$PARTNAME/var/lib/cni
mkdir /var/lib/cni
mount --bind /mnt/$PARTNAME/var/lib/cni /var/lib/cni
mkdir -p /mnt/$PARTNAME/data
mkdir /data
mount --bind /mnt/$PARTNAME/data /data
mkdir -p /mnt/$PARTNAME/hostpath_pv
mkdir /tmp/hostpath_pv
mount --bind /mnt/$PARTNAME/hostpath_pv /tmp/hostpath_pv
mkdir -p /mnt/$PARTNAME/hostpath-provisioner
mkdir /tmp/hostpath-provisioner
mount --bind /mnt/$PARTNAME/hostpath-provisioner /tmp/hostpath-provisioner
@afbjorklund I think I'm seeing this error trying to run minikube in Cloud Shell and it seems related to https://github.com/kubernetes/minikube/issues/8163 as well.
WDYT of changing docker's home directory? I'm not super familiar with this issue, but I'm wondering if that would resolve it. If we changed from /var/lib/docker
to /tmp/var/lib/docker
then the preload extract volume would be mounted to /tmp/var
instead of /var
.
Do you know if this would break anything? It seems to work fine testing locally on my Mac & in Cloud Shell.
I don't think we will use a custom mountpoint initially, but just address the race.
It is likely that it is the /extractDir that is the real issue here, rather than the /var.
This issue will be solved as a duplicate of #8151 since it is the same root cause.
Steps to reproduce the issue:
minikube start
with driver set to dockerFull output of failed command:
Full output of
minikube start
command used, if not already included:Optional: Full output of
minikube logs
command:Minikube Container logs: