docker/podman: add solution message when container exits after start/create #8501
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
k8s-ci-robot
added
cncf-cla: yes
medyagh
changed the title
|
[APPROVALNOTIFIER] This PR is APPROVED This pull-request has been approved by: medyagh The full list of commands accepted by this bot can be found here. The pull request process is described here
Needs approval from an approver in each of these files:
Approvers can indicate their approval by writing |
k8s-ci-robot
added
the
approved
medyagh
changed the title
k8s-ci-robot
added
the
do-not-merge/work-in-progress
medyagh
force-pushed
the
sol_msg_check_running
branch
from
d4d0166
to
736f521
Compare
k8s-ci-robot
added
size/XS
k8s-ci-robot
added
size/M
Travis tests have failedHey @medyagh, 1st Buildmake testTravisBuddy Request Identifier: 5f96d120-b0da-11ea-b9a3-b9754cbad7e4 |
Travis tests have failedHey @medyagh, 1st Buildmake testTravisBuddy Request Identifier: 0a8a6180-b0e2-11ea-b9a3-b9754cbad7e4 |
medyagh
changed the title
k8s-ci-robot
added
size/L
Codecov Report
@@ Coverage Diff @@
## master #8501 +/- ##
==========================================
- Coverage 33.97% 33.87% -0.10%
==========================================
Files 153 154 +1
Lines 9869 9897 +28
==========================================
Hits 3353 3353
- Misses 6112 6140 +28
Partials 404 404
|
tstromberg
suggested changes
Jun 17, 2020
pkg/drivers/kic/oci/oci.go
Outdated
| return runCmd(exec.Command(ociBin, "logs", "--timestamps", name)) | ||
| } | ||
|
|
||
| //PrintPostPortem will print relevant docker/podman infos after a container fails |
There was a problem hiding this comment.
This seems to log instead of print (normally associated to stdout). Perhaps LogContainerStatus?
There was a problem hiding this comment.
how about LogContainerDebug? since we are doing three things there
|
/ok-to-test |
k8s-ci-robot
added
the
ok-to-test
|
kvm2 Driver Times for Minikube (PR 8501): [63.271461281 65.25239230300001 64.041630812] Averages Time Per Log docker Driver Times for Minikube (PR 8501): [27.803309603000002 26.478580284999996 27.285987896] Averages Time Per Log |
tstromberg
approved these changes
Jun 18, 2020
medyagh
changed the title
medyagh
changed the title
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Helps with debugging issues like this: #8163
by adding a solution message and also adding postmortem
docker logsanddocker infologs to the verbose logafter this PR normal logs:
logs with --alsologtostderr include dokcer info and docke logs
medya@~/workspace/minikube (sol_msg_check_running) $ make && ./out/minikube start --driver=docker --alsologtostderr make: `out/minikube' is up to date. I0617 14:49:59.608496 10636 start.go:98] hostinfo: {"hostname":"medya-macbookpro3.roam.corp.google.com","uptime":416677,"bootTime":1592013922,"procs":470,"os":"darwin","platform":"darwin","platformFamily":"","platformVersion":"10.15.5","kernelVersion":"19.5.0","virtualizationSystem":"","virtualizationRole":"","hostid":"54f1a78d-6f41-32bd-bfed-4381f9f6e2ef"} W0617 14:49:59.608605 10636 start.go:106] gopshost.Virtualization returned error: not implemented yet 😄 minikube v1.11.0 on Darwin 10.15.5 I0617 14:49:59.628329 10636 driver.go:260] Setting default libvirt URI to qemu:///system I0617 14:49:59.628843 10636 notify.go:125] Checking for updates... I0617 14:49:59.683138 10636 docker.go:96] docker version: linux-19.03.8 ✨ Using the docker driver based on user configuration I0617 14:49:59.696978 10636 start.go:207] selected driver: docker I0617 14:49:59.696989 10636 start.go:604] validating driver "docker" against I0617 14:49:59.697005 10636 start.go:615] status for docker: {Installed:true Healthy:true Error: Fix: Doc:} I0617 14:49:59.697026 10636 start.go:933] auto setting extra-config to "kubeadm.pod-network-cidr=10.244.0.0/16". I0617 14:49:59.697074 10636 start_flags.go:218] no existing cluster config was found, will generate one from the flags I0617 14:49:59.697195 10636 cli_runner.go:109] Run: docker system info --format "{{json .}}" I0617 14:49:59.789710 10636 start_flags.go:232] Using suggested 4000MB memory alloc based on sys=16384MB, container=7966MB I0617 14:49:59.789811 10636 start_flags.go:556] Wait components to verify : map[apiserver:true system_pods:true] 👍 Starting control plane node minikube in cluster minikube I0617 14:49:59.894971 10636 image.go:92] Found gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438 in local docker daemon, skipping pull I0617 14:49:59.895029 10636 cache.go:113] gcr.io/k8s-minikube/kicbase:v0.0.10@sha256:f58e0c4662bac8a9b5dda7984b185bad8502ade5d9fa364bf2755d636ab51438 exists in daemon, skipping pull I0617 14:49:59.895043 10636 preload.go:95] Checking if preload exists for k8s version v1.18.3 and runtime docker I0617 14:49:59.895103 10636 preload.go:103] Found local preload: /Users/medya/.minikube/cache/preloaded-tarball/preloaded-images-k8s-v3-v1.18.3-docker-overlay2-amd64.tar.lz4 I0617 14:49:59.895114 10636 cache.go:51] Caching tarball of preloaded images I0617 14:49:59.895139 10636 preload.go:129] Found /Users/medya/.minikube/cache/preloaded-tarball/preloaded-images-k8s-v3-v1.18.3-docker-overlay2-amd64.tar.lz4 in cache, skipping download I0617 14:49:59.895147 10636 cache.go:54] Finished verifying existence of preloaded tar for v1.18.3 on docker I0617 14:49:59.895477 10636 profile.go:156] Saving config to /Users/medya/.minikube/profiles/minikube/config.json ... I0617 14:49:59.895661 10636 lock.go:35] WriteFile acquiring /Users/medya/.minikube/profiles/minikube/config.json: {Name:mkcfdcaaa21816d14cd9720660d7b2e91b28d741 Clock:{} Delay:500ms Timeout:1m0s Cancel:} I0617 14:49:59.896100 10636 cache.go:178] Successfully downloaded all kic artifacts I0617 14:49:59.896130 10636 start.go:240] acquiring machines lock for minikube: {Name:mk776146a90e3c3e4f2a4d11e614d78349a56d54 Clock:{} Delay:500ms Timeout:15m0s Cancel:} I0617 14:49:59.896640 10636 start.go:244] acquired machines lock for "minikube" in 496.393µs I0617 14:49:59.896670 10636 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:4000 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} I0617 14:49:59.897317 10636 start.go:121] createHost starting for "" (driver="docker") 🔥 Creating docker container (CPUs=2, Memory=4000MB) ... I0617 14:49:59.916529 10636 start.go:157] libmachine.API.Create for "minikube" (driver="docker") I0617 14:49:59.916561 10636 client.go:161] LocalClient.Create starting I0617 14:49:59.916615 10636 main.go:115] libmachine: Reading certificate data from /Users/medya/.minikube/certs/ca.pem I0617 14:49:59.916836 10636 main.go:115] libmachine: Decoding PEM data... I0617 14:49:59.916854 10636 main.go:115] libmachine: Parsing certificate... I0617 14:49:59.916973 10636 main.go:115] libmachine: Reading certificate data from /Users/medya/.minikube/certs/cert.pem I0617 14:49:59.917095 10636 main.go:115] libmachine: Decoding PEM data... I0617 14:49:59.917104 10636 main.go:115] libmachine: Parsing certificate... I0617 14:49:59.917809 10636 cli_runner.go:109] Run: docker ps -a --format {{.Names}} I0617 14:49:59.954494 10636 cli_runner.go:109] Run: docker volume create minikube --label name.minikube.sigs.k8s.io=minikube --label created_by.minikube.sigs.k8s.io=true I0617 14:49:59.991003 10636 oci.go:101] Successfully created a docker volume minikube I0617 14:49:59.991118 10636 preload.go:95] Checking if preload exists for k8s version v1.18.3 and runtime docker I0617 14:49:59.991171 10636 preload.go:103] Found local preload: /Users/medya/.minikube/cache/preloaded-tarball/preloaded-images-k8s-v3-v1.18.3-docker-overlay2-amd64.tar.lz4 I0617 14:49:59.991181 10636 kic.go:134] Starting extracting preloaded images to volume ... I0617 14:49:59.991198 10636 cli_runner.go:109] Run: docker info --format "'{{json .SecurityOptions}}'" I0617 14:49:59.991258 10636 cli_runner.go:109] Run: docker run --rm --entrypoint /usr/bin/tar -v /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 I0617 14:50:00.090703 10636 cli_runner.go:109] 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=4000mb -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 I0617 14:50:00.536278 10636 cli_runner.go:109] Run: docker container inspect minikube --format={{.State.Running}} I0617 14:50:00.584421 10636 cli_runner.go:109] Run: docker container inspect minikube --format={{.State.Status}} I0617 14:50:00.628605 10636 oci.go:215] the created container "minikube" has a running status. I0617 14:50:00.628808 10636 cli_runner.go:109] Run: docker logs --timestamps --details minikube W0617 14:50:00.673132 10636 oci.go:595] Postmortem container logs: docker logs --timestamps --details minikube I0617 14:50:00.673341 10636 cli_runner.go:109] Run: docker system info --format "{{json .}}" W0617 14:50:00.945030 10636 oci.go:602] postmortem docker info: {ID:5FLL:BD2R:ZVCB:VJLW:7PTG:BH2A:7PZM:AFWX:P3KO:IPHN:RWUP:ANSG Containers:2 ContainersRunning:2 ContainersPaused:0 ContainersStopped:0 Images:50 Driver:overlay2 DriverStatus:[[Backing Filesystem ] [Supports d_type true] [Native Overlay Diff true]] SystemStatus: Plugins:{Volume:[local] Network:[bridge host ipvlan macvlan null overlay] Authorization: Log:[awslogs fluentd gcplogs gelf journald json-file local logentries splunk syslog]} MemoryLimit:true SwapLimit:true KernelMemory:true KernelMemoryTCP:true CPUCfsPeriod:true CPUCfsQuota:true CPUShares:true CPUSet:true PidsLimit:true IPv4Forwarding:true BridgeNfIptables:true BridgeNfIP6Tables:true Debug:true NFd:55 OomKillDisable:true NGoroutines:69 SystemTime:2020-06-17 21:50:00.807387362 +0000 UTC LoggingDriver:json-file CgroupDriver:cgroupfs NEventsListener:4 KernelVersion:4.19.76-linuxkit OperatingSystem:Docker Desktop OSType:linux Architecture:x86_64 IndexServerAddress:https://index.docker.io/v1/ RegistryConfig:{AllowNondistributableArtifactsCIDRs:[] AllowNondistributableArtifactsHostnames:[] InsecureRegistryCIDRs:[127.0.0.0/8] IndexConfigs:{DockerIo:{Name:docker.io Mirrors:[] Secure:true Official:true}} Mirrors:[]} NCPU:4 MemTotal:8353480704 GenericResources: DockerRootDir:/var/lib/docker HTTPProxy:gateway.docker.internal:3128 HTTPSProxy:gateway.docker.internal:3129 NoProxy: Name:docker-desktop Labels:[] ExperimentalBuild:false ServerVersion:19.03.8 ClusterStore: ClusterAdvertise: Runtimes:{Runc:{Path:runc}} DefaultRuntime:runc Swarm:{NodeID: NodeAddr: LocalNodeState:inactive ControlAvailable:false Error: RemoteManagers:} LiveRestoreEnabled:false Isolation: InitBinary:docker-init ContainerdCommit:{ID:7ad184331fa3e55e52b890ea95e65ba581ae3429 Expected:7ad184331fa3e55e52b890ea95e65ba581ae3429} RuncCommit:{ID:dc9208a3303feef5b3839f4323d9beb36df0a9dd Expected:dc9208a3303feef5b3839f4323d9beb36df0a9dd} InitCommit:{ID:fec3683 Expected:fec3683} SecurityOptions:[name=seccomp,profile=default] ProductLicense:Community Engine Warnings: ClientInfo:{Debug:false Plugins:[] Warnings:}} I0617 14:50:00.945476 10636 cli_runner.go:109] Run: docker system info --format "{{json .}}" I0617 14:50:01.065230 10636 client.go:164] LocalClient.Create took 1.148639891s I0617 14:50:03.070308 10636 start.go:124] duration metric: createHost completed in 3.1728951s I0617 14:50:03.070360 10636 start.go:75] releasing machines lock for "minikube", held for 3.173652637s I0617 14:50:03.071346 10636 cli_runner.go:109] Run: docker container inspect minikube --format={{.State.Status}} I0617 14:50:03.123201 10636 stop.go:36] StopHost: minikube ✋ Stopping "minikube" in docker ... I0617 14:50:03.245922 10636 cli_runner.go:109] Run: docker container inspect minikube --format={{.State.Status}} 🛑 Powering off "minikube" via SSH ... I0617 14:50:03.302790 10636 cli_runner.go:109] Run: docker exec --privileged -t minikube /bin/bash -c "sudo init 0" I0617 14:50:04.479601 10636 cli_runner.go:109] Run: docker container inspect minikube --format={{.State.Status}} I0617 14:50:04.549037 10636 oci.go:564] container minikube status is Stopped I0617 14:50:04.549080 10636 oci.go:576] Successfully shutdown container minikube I0617 14:50:04.549086 10636 stop.go:84] shutdown container: err= I0617 14:50:04.549147 10636 main.go:115] libmachine: Stopping "minikube"... I0617 14:50:04.549386 10636 cli_runner.go:109] Run: docker container inspect minikube --format={{.State.Status}} I0617 14:50:04.610384 10636 stop.go:56] stop err: Machine "minikube" is already stopped. I0617 14:50:04.610430 10636 stop.go:59] host is already stopped 🔥 Deleting "minikube" in docker ... I0617 14:50:05.732498 10636 cli_runner.go:109] Run: docker container inspect -f {{.Id}} minikube I0617 14:50:05.773289 10636 cli_runner.go:109] Run: docker container inspect minikube --format={{.State.Status}} I0617 14:50:05.822674 10636 cli_runner.go:109] Run: docker exec --privileged -t minikube /bin/bash -c "sudo init 0" I0617 14:50:05.864031 10636 oci.go:556] error shutdown minikube: docker exec --privileged -t minikube /bin/bash -c "sudo init 0": exit status 1 stdout:stderr:
Error response from daemon: Container 56df4631d07fc5dcf87dead126fb35e8be59d999aab74f351c5dd6e811249ab0 is not running
I0617 14:50:06.085813 10636 cli_runner.go:151] Completed: docker run --rm --entrypoint /usr/bin/tar -v /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: (6.094403356s)
I0617 14:50:06.085854 10636 kic.go:139] duration metric: took 6.094567 seconds to extract preloaded images to volume
I0617 14:50:06.867514 10636 cli_runner.go:109] Run: docker container inspect minikube --format={{.State.Status}}
I0617 14:50:06.922364 10636 oci.go:564] container minikube status is Stopped
I0617 14:50:06.922424 10636 oci.go:576] Successfully shutdown container minikube
I0617 14:50:06.922569 10636 cli_runner.go:109] Run: docker rm -f -v minikube
I0617 14:50:06.989180 10636 cli_runner.go:109] Run: docker container inspect -f {{.Id}} minikube
I0617 14:50:07.033575 10636 start.go:364] will skip retrying to create machine because error is not retriable: creating host: create: creating: create kic node: container name "minikube": container status is not running after creation
💥 Unfortunately docker container exited after it was created, with an unclear root cause.
💡 If you are still interested to make docker driver work. The following suggestions might help you get passed this issue:
I0617 14:50:07.126777 10636 exit.go:58] WithError(error provisioning host)=Failed to start host: creating host: create: creating: create kic node: container name "minikube": container status is not running after creation called from:
goroutine 1 [running]:
runtime/debug.Stack(0x14, 0x583626f, 0x65)
/usr/local/Cellar/go/1.13.7/libexec/src/runtime/debug/stack.go:24 +0x9d
k8s.io/minikube/pkg/minikube/exit.WithError(0x57cad7e, 0x17, 0x5abc140, 0xc0008fa380)
/Users/medya/workspace/minikube/pkg/minikube/exit/exit.go:58 +0x34
k8s.io/minikube/cmd/minikube/cmd.runStart(0x68b40a0, 0xc000194e20, 0x0, 0x2)
/Users/medya/workspace/minikube/cmd/minikube/cmd/start.go:162 +0xaef
github.com/spf13/cobra.(*Command).execute(0x68b40a0, 0xc000194e00, 0x2, 0x2, 0x68b40a0, 0xc000194e00)
/Users/medya/go/pkg/mod/github.com/spf13/cobra@v1.0.0/command.go:846 +0x2aa
github.com/spf13/cobra.(*Command).ExecuteC(0x68b8f60, 0x0, 0x1, 0xc0006222a0)
/Users/medya/go/pkg/mod/github.com/spf13/cobra@v1.0.0/command.go:950 +0x349
github.com/spf13/cobra.(*Command).Execute(...)
/Users/medya/go/pkg/mod/github.com/spf13/cobra@v1.0.0/command.go:887
k8s.io/minikube/cmd/minikube/cmd.Execute()
/Users/medya/workspace/minikube/cmd/minikube/cmd/root.go:106 +0x747
main.main()
/Users/medya/workspace/minikube/cmd/minikube/main.go:71 +0x143
W0617 14:50:07.128156 10636 out.go:201] error provisioning host: Failed to start host: creating host: create: creating: create kic node: container name "minikube": container status is not running after creation
💣 error provisioning host: Failed to start host: creating host: create: creating: create kic node: container name "minikube": container status is not running after creation
😿 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