make test fails with "sudo podman"

[andk]

Steps to reproduce the issue:

1. Running make test first runs into a sudo prompt which I ignore (this user has no sudo permissions); after a while the make test continues to run to the end with a message FAIL

Let me know if this is not something reportworthy, I'd refrain reporting such in the future.

Full output of failed command:

% make test
MINIKUBE_LDFLAGS="-X k8s.io/minikube/pkg/version.version=v1.10.0-beta.2 -X k8s.io/minikube/pkg/version.isoVersion=v1.10.0-beta.2 -X k8s.io/minikube/pkg/version.isoPath=minikube/iso -X k8s.io/minikube/pkg/version.gitCommitID="7102dcbec7c93d8de6455139988dad60a26d52a6"" ./test.sh
= make lint =============================================================
ok
= go mod ================================================================
ok
= boilerplate ===========================================================
ok
= schema_check ==========================================================
ok
= go test ===============================================================
ok      k8s.io/minikube/cmd/minikube/cmd        11.416s coverage: 21.5% of statements
ok      k8s.io/minikube/cmd/minikube/cmd/config 0.191s  coverage: 19.3% of statements
ok      k8s.io/minikube/pkg/addons      0.042s  coverage: 56.9% of statements
ok      k8s.io/minikube/pkg/drivers     0.007s  coverage: 19.6% of statements
ok      k8s.io/minikube/pkg/drivers/hyperkit    0.007s  coverage: 77.3% of statements
ok      k8s.io/minikube/pkg/drivers/kvm 0.019s  coverage: 2.3% of statements
ok      k8s.io/minikube/pkg/minikube/bootstrapper       1.603s  coverage: 72.9% of statements
ok      k8s.io/minikube/pkg/minikube/bootstrapper/bsutil        0.169s  coverage: 63.2% of statements
ok      k8s.io/minikube/pkg/minikube/bootstrapper/bsutil/ktmpl  0.014s  coverage: 100.0% of statements
ok      k8s.io/minikube/pkg/minikube/bootstrapper/images        0.003s  coverage: 88.9% of statements
ok      k8s.io/minikube/pkg/minikube/cluster    0.049s  coverage: 19.1% of statements
ok      k8s.io/minikube/pkg/minikube/command    0.015s  coverage: 3.9% of statements
ok      k8s.io/minikube/pkg/minikube/config     0.323s  coverage: 70.9% of statements
ok      k8s.io/minikube/pkg/minikube/cruntime   0.025s  coverage: 40.6% of statements
ok      k8s.io/minikube/pkg/minikube/docker     0.018s  coverage: 20.8% of statements
ok      k8s.io/minikube/pkg/minikube/driver     0.028s  coverage: 37.3% of statements
ok      k8s.io/minikube/pkg/minikube/extract    0.088s  coverage: 58.8% of statements
ok      k8s.io/minikube/pkg/minikube/kubeconfig 0.082s  coverage: 77.0% of statements
ok      k8s.io/minikube/pkg/minikube/localpath  0.005s  coverage: 51.9% of statements
ok      k8s.io/minikube/pkg/minikube/logs       0.027s  coverage: 1.3% of statements

We trust you have received the usual lecture from the local System
Administrator. It usually boils down to these three things:

    #1) Respect the privacy of others.
    #2) Think before you type.
    #3) With great power comes great responsibility.

[sudo] password for sand: 127.0.0.1:42191
I0508 05:05:37.029274  879483 start.go:104] createHost starting for "minikube" (driver="mock")
W0508 05:05:37.029588  879483 out.go:79] [unset outFile]: * Running on localhost (CPUs=3, Memory=12881MB, Disk=64379MB) ...
I0508 05:05:37.029647  879483 start.go:140] libmachine.API.Create for "" (driver="mock")
I0508 05:05:37.029690  879483 start.go:145] duration metric: libmachine.API.Create for "" took 42.552µs
I0508 05:05:37.029701  879483 start.go:186] post-start starting for "mock-machine-0.60466029" (driver="mock")
I0508 05:05:37.029708  879483 start.go:189] post-start completed in 755ns
I0508 05:05:37.029727  879483 start.go:107] duration metric: createHost completed in 437.342µs
I0508 05:05:37.029802  879483 start.go:104] createHost starting for "minikube" (driver="mock")
W0508 05:05:37.030143  879483 out.go:79] [unset outFile]: * Running on localhost (CPUs=3, Memory=12881MB, Disk=64379MB) ...
I0508 05:05:37.030392  879483 start.go:140] libmachine.API.Create for "" (driver="mock")
I0508 05:05:37.030802  879483 start.go:145] duration metric: libmachine.API.Create for "" took 409.744µs
I0508 05:05:37.030814  879483 start.go:186] post-start starting for "mock-machine-0.94050909" (driver="mock")
I0508 05:05:37.030822  879483 start.go:189] post-start completed in 761ns
I0508 05:05:37.030846  879483 start.go:107] duration metric: createHost completed in 1.032536ms
I0508 05:05:37.030872  879483 start.go:223] acquiring machines lock for mock-machine-0.94050909: {Name:mkd0555c848d0e189dc21d144bbe23d5eae562a7 Clock:{} Delay:500ms Timeout:15m0s Cancel:<nil>}
I0508 05:05:37.030977  879483 start.go:227] acquired machines lock for "mock-machine-0.94050909" in 70.353µs
I0508 05:05:37.030991  879483 start.go:87] Skipping create...Using existing machine configuration
I0508 05:05:37.031007  879483 fix.go:53] fixHost starting: mock-machine-0.94050909
I0508 05:05:37.031044  879483 fix.go:105] recreateIfNeeded on mock-machine-0.94050909: state=Running err=<nil>
W0508 05:05:37.031054  879483 fix.go:131] unexpected machine state, will restart: <nil>
W0508 05:05:37.035015  879483 out.go:79] [unset outFile]: * Updating the running mock "mock-machine-0.94050909" bare metal machine ...
I0508 05:05:37.035060  879483 fix.go:55] fixHost completed within 4.053746ms
I0508 05:05:37.035072  879483 start.go:74] releasing machines lock for "mock-machine-0.94050909", held for 4.081226ms
I0508 05:05:37.035176  879483 start.go:104] createHost starting for "minikube" (driver="mock")
W0508 05:05:37.035551  879483 out.go:79] [unset outFile]: * Running on localhost (CPUs=3, Memory=12881MB, Disk=64379MB) ...
I0508 05:05:37.035631  879483 start.go:140] libmachine.API.Create for "" (driver="mock")
I0508 05:05:37.035735  879483 start.go:145] duration metric: libmachine.API.Create for "" took 103.986µs
I0508 05:05:37.035743  879483 start.go:186] post-start starting for "mock-machine-0.66456005" (driver="mock")
I0508 05:05:37.035751  879483 start.go:189] post-start completed in 787ns
I0508 05:05:37.035766  879483 start.go:107] duration metric: createHost completed in 578.691µs
I0508 05:05:37.035818  879483 start.go:223] acquiring machines lock for mock-machine-0.66456005: {Name:mkd0555c848d0e189dc21d144bbe23d5eae562a7 Clock:{} Delay:500ms Timeout:15m0s Cancel:<nil>}
I0508 05:05:37.035989  879483 start.go:227] acquired machines lock for "mock-machine-0.66456005" in 121.943µs
I0508 05:05:37.036023  879483 start.go:87] Skipping create...Using existing machine configuration
I0508 05:05:37.036033  879483 fix.go:53] fixHost starting: mock-machine-0.66456005
I0508 05:05:37.036089  879483 fix.go:105] recreateIfNeeded on mock-machine-0.66456005: state=Error err=machine does not exist
I0508 05:05:37.036104  879483 fix.go:110] machineExists: false. err=machine does not exist
W0508 05:05:37.036193  879483 out.go:79] [unset outFile]: * mock "mock-machine-0.66456005" bare metal machine is missing, will recreate.
I0508 05:05:37.036204  879483 delete.go:117] DEMOLISHING mock-machine-0.66456005 ...
Stopping "mock-machine-0.66456005"...
Error getting machine state: machine does not exist
Machine "mock-machine-0.66456005" was stopped.
I0508 05:05:37.036309  879483 stop.go:64] duration metric: stop complete within 97.421µs
W0508 05:05:37.036486  879483 out.go:79] [unset outFile]: * Deleting "mock-machine-0.66456005" in mock ...
W0508 05:05:37.036523  879483 delete.go:132] delete failed (probably ok) <nil>
I0508 05:05:37.036532  879483 fix.go:117] Sleeping 1 second for extra luck!
I0508 05:05:38.036756  879483 start.go:104] createHost starting for "mock-machine-0.66456005" (driver="mock")
W0508 05:05:38.037063  879483 out.go:79] [unset outFile]: * Running on localhost (CPUs=3, Memory=12881MB, Disk=64379MB) ...
I0508 05:05:38.037119  879483 start.go:140] libmachine.API.Create for "mock-machine-0.66456005" (driver="mock")
I0508 05:05:38.037164  879483 start.go:145] duration metric: libmachine.API.Create for "mock-machine-0.66456005" took 44.932µs
I0508 05:05:38.037171  879483 start.go:186] post-start starting for "mock-machine-0.43771419" (driver="mock")
I0508 05:05:38.037178  879483 start.go:189] post-start completed in 762ns
I0508 05:05:38.037191  879483 start.go:107] duration metric: createHost completed in 408.901µs
W0508 05:05:38.037204  879483 fix.go:131] unexpected machine state, will restart: <nil>
I0508 05:05:38.037213  879483 fix.go:55] fixHost completed within 1.001182074s
I0508 05:05:38.037218  879483 start.go:74] releasing machines lock for "mock-machine-0.66456005", held for 1.001197673s
I0508 05:05:38.037247  879483 start.go:223] acquiring machines lock for mock-machine-0.43771419: {Name:mkd0555c848d0e189dc21d144bbe23d5eae562a7 Clock:{} Delay:500ms Timeout:15m0s Cancel:<nil>}
I0508 05:05:38.037308  879483 start.go:227] acquired machines lock for "mock-machine-0.43771419" in 50.004µs
I0508 05:05:38.037316  879483 start.go:87] Skipping create...Using existing machine configuration
I0508 05:05:38.037322  879483 fix.go:53] fixHost starting: mock-machine-0.43771419
I0508 05:05:38.037352  879483 fix.go:105] recreateIfNeeded on mock-machine-0.43771419: state=Running err=<nil>
W0508 05:05:38.037358  879483 fix.go:131] unexpected machine state, will restart: <nil>
W0508 05:05:38.037391  879483 out.go:79] [unset outFile]: * Updating the running mock "mock-machine-0.43771419" bare metal machine ...
I0508 05:05:38.037400  879483 fix.go:55] fixHost completed within 77.988µs
I0508 05:05:38.037405  879483 start.go:74] releasing machines lock for "mock-machine-0.43771419", held for 89.294µs
I0508 05:05:38.037453  879483 start.go:104] createHost starting for "minikube" (driver="mock")
W0508 05:05:38.037676  879483 out.go:79] [unset outFile]: * Running on localhost (CPUs=3, Memory=12881MB, Disk=64379MB) ...
I0508 05:05:38.037705  879483 start.go:140] libmachine.API.Create for "" (driver="mock")
I0508 05:05:38.037740  879483 start.go:145] duration metric: libmachine.API.Create for "" took 35.699µs
I0508 05:05:38.037746  879483 start.go:186] post-start starting for "mock-machine-0.42463750" (driver="mock")
I0508 05:05:38.037752  879483 start.go:189] post-start completed in 672ns
I0508 05:05:38.037764  879483 start.go:107] duration metric: createHost completed in 304.707µs
I0508 05:05:38.037773  879483 start.go:223] acquiring machines lock for mock-machine-0.42463750: {Name:mkd0555c848d0e189dc21d144bbe23d5eae562a7 Clock:{} Delay:500ms Timeout:15m0s Cancel:<nil>}
I0508 05:05:38.037817  879483 start.go:227] acquired machines lock for "mock-machine-0.42463750" in 35.699µs
I0508 05:05:38.037825  879483 start.go:87] Skipping create...Using existing machine configuration
I0508 05:05:38.037830  879483 fix.go:53] fixHost starting: mock-machine-0.42463750
I0508 05:05:38.037852  879483 fix.go:105] recreateIfNeeded on mock-machine-0.42463750: state=Stopped err=<nil>
W0508 05:05:38.037874  879483 fix.go:131] unexpected machine state, will restart: <nil>
W0508 05:05:38.037908  879483 out.go:79] [unset outFile]: * Restarting existing mock bare metal machine for "mock-machine-0.42463750" ...
I0508 05:05:38.037928  879483 fix.go:55] fixHost completed within 97.658µs
I0508 05:05:38.037933  879483 start.go:74] releasing machines lock for "mock-machine-0.42463750", held for 108.461µs
I0508 05:05:38.037978  879483 start.go:223] acquiring machines lock for : {Name:mkd0555c848d0e189dc21d144bbe23d5eae562a7 Clock:{} Delay:500ms Timeout:15m0s Cancel:<nil>}
I0508 05:05:38.038018  879483 start.go:227] acquired machines lock for "" in 30.62µs
I0508 05:05:38.038026  879483 start.go:83] Provisioning new machine with config: {Name: KeepContext:false EmbedCerts:false MinikubeISO: KicBaseImage: Memory:0 CPUs:0 DiskSize:0 Driver:mock HyperkitVpnKitSock: HyperkitVSockPorts:[] DockerEnv:[MOCK_MAKE_IT_PROVISION=true] InsecureRegistry:[] RegistryMirror:[] HostOnlyCIDR: HypervVirtualSwitch: HypervUseExternalSwitch:false HypervExternalAdapter: KVMNetwork: KVMQemuURI: KVMGPU:false KVMHidden:false DockerOpt:[] DisableDriverMounts:false NFSShare:[] NFSSharesRoot: UUID: NoVTXCheck:false DNSProxy:false HostDNSResolver:false HostOnlyNicType: NatNicType: KubernetesConfig:{KubernetesVersion: ClusterName: APIServerName: APIServerNames:[] APIServerIPs:[] DNSDomain: ContainerRuntime: CRISocket: NetworkPlugin: FeatureGates: ServiceCIDR: ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: ExtraOptions:[] ShouldLoadCachedImages:false EnableDefaultCNI:false NodeIP: NodePort:0 NodeName:} Nodes:[{Name:minikube IP: Port:0 KubernetesVersion: ControlPlane:false Worker:false}] Addons:map[] VerifyComponents:map[]} {Name:minikube IP: Port:0 KubernetesVersion: ControlPlane:false Worker:false}
I0508 05:05:38.038073  879483 start.go:104] createHost starting for "minikube" (driver="mock")
W0508 05:05:38.038288  879483 out.go:79] [unset outFile]: * Running on localhost (CPUs=3, Memory=12881MB, Disk=64379MB) ...
I0508 05:05:38.038316  879483 start.go:140] libmachine.API.Create for "" (driver="mock")
I0508 05:05:38.038352  879483 start.go:145] duration metric: libmachine.API.Create for "" took 35.404µs
I0508 05:05:38.038357  879483 start.go:186] post-start starting for "mock-machine-0.68682307" (driver="mock")
I0508 05:05:38.038363  879483 start.go:189] post-start completed in 679ns
I0508 05:05:38.038375  879483 start.go:107] duration metric: createHost completed in 284.453µs
I0508 05:05:38.038381  879483 start.go:74] releasing machines lock for "", held for 355.91µs
I0508 05:05:38.038425  879483 start.go:223] acquiring machines lock for -minikube: {Name:mkd0555c848d0e189dc21d144bbe23d5eae562a7 Clock:{} Delay:500ms Timeout:15m0s Cancel:<nil>}
I0508 05:05:38.038484  879483 start.go:227] acquired machines lock for "-minikube" in 36.629µs
I0508 05:05:38.038493  879483 start.go:83] Provisioning new machine with config: {Name: KeepContext:false EmbedCerts:false MinikubeISO: KicBaseImage: Memory:0 CPUs:0 DiskSize:0 Driver:mock HyperkitVpnKitSock: HyperkitVSockPorts:[] DockerEnv:[FOO=BAR] InsecureRegistry:[] RegistryMirror:[] HostOnlyCIDR: HypervVirtualSwitch: HypervUseExternalSwitch:false HypervExternalAdapter: KVMNetwork: KVMQemuURI: KVMGPU:false KVMHidden:false DockerOpt:[param=value] DisableDriverMounts:false NFSShare:[] NFSSharesRoot: UUID: NoVTXCheck:false DNSProxy:false HostDNSResolver:false HostOnlyNicType: NatNicType: KubernetesConfig:{KubernetesVersion: ClusterName: APIServerName: APIServerNames:[] APIServerIPs:[] DNSDomain: ContainerRuntime: CRISocket: NetworkPlugin: FeatureGates: ServiceCIDR: ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: ExtraOptions:[] ShouldLoadCachedImages:false EnableDefaultCNI:false NodeIP: NodePort:0 NodeName:} Nodes:[] Addons:map[] VerifyComponents:map[]} {Name:minikube IP: Port:0 KubernetesVersion: ControlPlane:false Worker:false}
I0508 05:05:38.038518  879483 start.go:104] createHost starting for "minikube" (driver="mock")
W0508 05:05:38.038712  879483 out.go:79] [unset outFile]: * Running on localhost (CPUs=3, Memory=12881MB, Disk=64379MB) ...
I0508 05:05:38.038744  879483 start.go:140] libmachine.API.Create for "" (driver="mock")
I0508 05:05:38.038778  879483 start.go:145] duration metric: libmachine.API.Create for "" took 34.195µs
I0508 05:05:38.038784  879483 start.go:186] post-start starting for "mock-machine-0.06563702" (driver="mock")
I0508 05:05:38.038790  879483 start.go:189] post-start completed in 680ns
I0508 05:05:38.038801  879483 start.go:107] duration metric: createHost completed in 277.167µs
I0508 05:05:38.038806  879483 start.go:74] releasing machines lock for "-minikube", held for 314.842µs
I0508 05:05:38.038840  879483 stop.go:36] StopHost: mock-machine-0.06563702
I0508 05:05:38.038872  879483 start.go:104] createHost starting for "minikube" (driver="mock")
W0508 05:05:38.039082  879483 out.go:79] [unset outFile]: * Running on localhost (CPUs=3, Memory=12881MB, Disk=64379MB) ...
I0508 05:05:38.039117  879483 start.go:140] libmachine.API.Create for "" (driver="mock")
I0508 05:05:38.039160  879483 start.go:145] duration metric: libmachine.API.Create for "" took 43.495µs
I0508 05:05:38.039166  879483 start.go:186] post-start starting for "mock-machine-0.15651925" (driver="mock")
I0508 05:05:38.039172  879483 start.go:189] post-start completed in 700ns
I0508 05:05:38.039184  879483 start.go:107] duration metric: createHost completed in 305.463µs
I0508 05:05:38.039189  879483 stop.go:36] StopHost: mock-machine-0.15651925
W0508 05:05:38.039221  879483 out.go:79] [unset outFile]: * Stopping "mock-machine-0.15651925" in mock ...
Stopping "mock-machine-0.15651925"...
Machine "mock-machine-0.15651925" was stopped.
I0508 05:05:38.039254  879483 stop.go:64] duration metric: stop complete within 26.055µs
I0508 05:05:38.039280  879483 start.go:104] createHost starting for "minikube" (driver="mock")
W0508 05:05:38.039658  879483 out.go:79] [unset outFile]: * Running on localhost (CPUs=3, Memory=12881MB, Disk=64379MB) ...
I0508 05:05:38.039716  879483 start.go:140] libmachine.API.Create for "" (driver="mock")
I0508 05:05:38.039802  879483 start.go:145] duration metric: libmachine.API.Create for "" took 86.5µs
I0508 05:05:38.039835  879483 start.go:186] post-start starting for "mock-machine-0.09696952" (driver="mock")
I0508 05:05:38.039860  879483 start.go:189] post-start completed in 795ns
I0508 05:05:38.039926  879483 start.go:107] duration metric: createHost completed in 640.057µs
W0508 05:05:38.040037  879483 out.go:79] [unset outFile]: * Deleting "mock-machine-0.09696952" in mock ...
I0508 05:05:38.040096  879483 start.go:104] createHost starting for "minikube" (driver="mock")
W0508 05:05:38.040410  879483 out.go:79] [unset outFile]: * Running on localhost (CPUs=3, Memory=12881MB, Disk=64379MB) ...
I0508 05:05:38.040482  879483 start.go:140] libmachine.API.Create for "" (driver="mock")
I0508 05:05:38.040576  879483 start.go:145] duration metric: libmachine.API.Create for "" took 92.809µs
I0508 05:05:38.040606  879483 start.go:186] post-start starting for "mock-machine-0.30091186" (driver="mock")
I0508 05:05:38.040630  879483 start.go:189] post-start completed in 802ns
I0508 05:05:38.040664  879483 start.go:107] duration metric: createHost completed in 512.293µs
I0508 05:05:38.040754  879483 cli_runner.go:108] Run: docker inspect  --format={{.State.Status}}
I0508 05:05:38.134548  879483 delete.go:45] couldn't inspect container "" before deleting: unknown state "": docker inspect  --format={{.State.Status}}: exit status 1
stdout:


stderr:
Error: No such object: 
I0508 05:05:38.134630  879483 cli_runner.go:108] Run: sudo podman inspect  --format={{.State.Status}}
FAIL    k8s.io/minikube/pkg/minikube/machine    10.039s
ok      k8s.io/minikube/pkg/minikube/notify     0.015s  coverage: 92.9% of statements
ok      k8s.io/minikube/pkg/minikube/out        0.014s  coverage: 67.4% of statements
ok      k8s.io/minikube/pkg/minikube/perf       0.764s  coverage: 54.7% of statements
ok      k8s.io/minikube/pkg/minikube/problem    0.017s  coverage: 91.7% of statements
ok      k8s.io/minikube/pkg/minikube/proxy      0.008s  coverage: 98.3% of statements
ok      k8s.io/minikube/pkg/minikube/registry   0.008s  coverage: 75.5% of statements
ok      k8s.io/minikube/pkg/minikube/service    0.090s  coverage: 84.2% of statements
ok      k8s.io/minikube/pkg/minikube/storageclass       0.017s  coverage: 100.0% of statements
ok      k8s.io/minikube/pkg/minikube/translate  0.006s  coverage: 10.5% of statements
ok      k8s.io/minikube/pkg/minikube/tunnel     2.325s  coverage: 64.2% of statements
ok      k8s.io/minikube/pkg/util        0.554s  coverage: 77.9% of statements
ok      k8s.io/minikube/pkg/util/lock   0.005s  coverage: 18.2% of statements
ok      k8s.io/minikube/pkg/util/retry  0.014s  coverage: 0.0% of statements
FAIL
make: *** [Makefile:271: test] Error 32

Full output of minikube start command used, if not already included:

Optional: Full output of minikube logs command:

[afbjorklund]

Let me know if this is not something reportworthy, I'd refrain reporting such in the future.

Thanks for reporting, it seems related to the issues with the podman driver: #7958

I0508 05:05:38.134630 879483 cli_runner.go:108] Run: sudo podman inspect --format={{.State.Status}}

The workaround (for now), is to use sudo -n so that it will fail instead of asking for a password.

Should be fix on master, can you try again ?

[andk]

Thanks you, Anders, but no, I do not see your or any commit after 7102dcb yet; I'm using github as my remote (https://github.com/kubernetes/minikube), is there a better upstream?

[afbjorklund]

@andk : sorry, my bad - I thought that #7959 had been merged

[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

[priyawadhwa]

Looks like #7959 has been merged, are you still seeing this issue?

[andk]

Looks good. make test has no problem in my environment. Thanks!

[sharifelgamal]

Great, I'm going to close this then.