Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

"TestFunctional/parallel/DryRun" fails on HyperV github action tests #9785

Closed
medyagh opened this issue Nov 26, 2020 · 13 comments
Closed

"TestFunctional/parallel/DryRun" fails on HyperV github action tests #9785

medyagh opened this issue Nov 26, 2020 · 13 comments
Labels
kind/failing-test Categorizes issue or PR as related to a consistently or frequently failing test. lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed. priority/important-longterm Important over the long term, but may not be staffed and/or may need multiple releases to complete.

Comments

@medyagh
Copy link
Member

medyagh commented Nov 26, 2020

"TestFunctional/parallel/DryRun"

this test fails in github action on hyperv driver
it fails on this machine

Domain              : WORKGROUP
Manufacturer        : Microsoft Corporation
Model               : Virtual Machine
Name                : mini-test-7-hv
PrimaryOwnerName    : 
TotalPhysicalMemory : 68718481408

=== RUN   TestFunctional/parallel/DryRun
=== PAUSE TestFunctional/parallel/DryRun
=== CONT  TestFunctional/parallel/DryRun
functional_test.go:473: (dbg) Run:  ./minikube-windows-amd64.exe start -p functional-20201125234332-3228 --dry-run --memory 250MB --alsologtostderr --driver=hyperv
=== CONT  TestFunctional/parallel/DryRun
functional_test.go:473: (dbg) Non-zero exit: ./minikube-windows-amd64.exe start -p functional-20201125234332-3228 --dry-run --memory 250MB --alsologtostderr --driver=hyperv: exit status 1 (5.0407678s)
-- stdout --
	* [functional-20201125234332-3228] minikube v1.15.1 on Microsoft Windows 10 Enterprise N 10.0.18363 Build 18363
	  - KUBECONFIG=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome\kubeconfig
	  - MINIKUBE_HOME=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome
	* Using the hyperv driver based on existing profile
-- /stdout --
** stderr ** 
	I1125 23:49:32.217072   10204 out.go:185] Setting OutFile to fd 1372 ...
	I1125 23:49:32.373045   10204 out.go:232] TERM=,COLORTERM=, which probably does not support color
	I1125 23:49:32.373045   10204 out.go:198] Setting ErrFile to fd 1376...
	I1125 23:49:32.373045   10204 out.go:232] TERM=,COLORTERM=, which probably does not support color
	I1125 23:49:32.404049   10204 out.go:192] Setting JSON to false
	I1125 23:49:32.410053   10204 start.go:104] hostinfo: {"hostname":"mini-test-7-hv","uptime":1145834,"bootTime":1605202338,"procs":193,"os":"windows","platform":"Microsoft Windows 10 Enterprise N","platformFamily":"Standalone Workstation","platformVersion":"10.0.18363 Build 18363","kernelVersion":"","virtualizationSystem":"","virtualizationRole":"","hostid":"9b3837cd-cf48-4f67-a408-2a0186127a2f"}
	W1125 23:49:32.411050   10204 start.go:112] gopshost.Virtualization returned error: not implemented yet
	I1125 23:49:32.428050   10204 out.go:110] * [functional-20201125234332-3228] minikube v1.15.1 on Microsoft Windows 10 Enterprise N 10.0.18363 Build 18363
	I1125 23:49:32.436062   10204 out.go:110]   - KUBECONFIG=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome\kubeconfig
	I1125 23:49:32.442047   10204 out.go:110]   - MINIKUBE_HOME=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome
	I1125 23:49:32.449053   10204 driver.go:308] Setting default libvirt URI to qemu:///system
	I1125 23:49:35.215816   10204 out.go:110] * Using the hyperv driver based on existing profile
	I1125 23:49:35.215816   10204 start.go:266] selected driver: hyperv
	I1125 23:49:35.216817   10204 start.go:680] validating driver "hyperv" against &{Name:functional-20201125234332-3228 KeepContext:false EmbedCerts:false MinikubeISO:https://storage.googleapis.com/minikube/iso/minikube-v1.15.2-snapshot2.iso KicBaseImage:gcr.io/k8s-minikube/kicbase:v0.0.15-snapshot2@sha256:0973e4bcdfef0dc8c5a581ecfcca5e36fa6a1cc8773e832ecfd31de3d2b6bf46 Memory:4000 CPUs:2 DiskSize:20000 VMDriver: Driver:hyperv HyperkitVpnKitSock: HyperkitVSockPorts:[] DockerEnv:[] ContainerVolumeMounts:[] 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.19.4 ClusterName:functional-20201125234332-3228 Namespace:default APIServerNa
me:minikubeCA APIServerNames:[] APIServerIPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin: FeatureGates: ServiceCIDR:10.96.0.0/12 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: ExtraOptions:[] ShouldLoadCachedImages:true EnableDefaultCNI:false CNI: NodeIP: NodePort:8441 NodeName:} Nodes:[{Name: IP:192.168.13.2 Port:8441 KubernetesVersion:v1.19.4 ControlPlane:true Worker:true}] Addons:map[ambassador:false csi-hostpath-driver:false dashboard:false default-storageclass:true efk:false freshpod:false gcp-auth:false gvisor:false helm-tiller:false ingress:false ingress-dns:false istio:false istio-provisioner:false kubevirt:false logviewer:false metallb:false metrics-server:false nvidia-driver-installer:false nvidia-gpu-device-plugin:false olm:false pod-security-policy:false registry:false registry-aliases:false registry-creds:false storage-provisioner:true storage-provisioner-gluster:false volumesnapshots:false] VerifyComponents:map[apiserver:true apps_running:true default_sa
:true kubelet:true system_pods:true] StartHostTimeout:6m0s ScheduledStop:<nil> ExposedPorts:[]}
	I1125 23:49:35.216817   10204 start.go:691] status for hyperv: {Installed:true Healthy:true Running:false NeedsImprovement:false Error:<nil> Fix: Doc:}
** /stderr **
functional_test.go:477: dry-run(250MB) exit code = 1, wanted = 23: exit status 1
functional_test.go:484: (dbg) Run:  ./minikube-windows-amd64.exe start -p functional-20201125234332-3228 --dry-run --alsologtostderr -v=1 --driver=hyperv
=== CONT  TestFunctional/parallel/DryRun
functional_test.go:484: (dbg) Non-zero exit: ./minikube-windows-amd64.exe start -p functional-20201125234332-3228 --dry-run --alsologtostderr -v=1 --driver=hyperv: exit status 1 (5.0360811s)
-- stdout --
	* [functional-20201125234332-3228] minikube v1.15.1 on Microsoft Windows 10 Enterprise N 10.0.18363 Build 18363
	  - KUBECONFIG=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome\kubeconfig
	  - MINIKUBE_HOME=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome
	* Using the hyperv driver based on existing profile
-- /stdout --
** stderr ** 
	I1125 23:49:36.953090    9808 out.go:185] Setting OutFile to fd 1356 ...
	I1125 23:49:37.122097    9808 out.go:232] TERM=,COLORTERM=, which probably does not support color
	I1125 23:49:37.122097    9808 out.go:198] Setting ErrFile to fd 1180...
	I1125 23:49:37.122097    9808 out.go:232] TERM=,COLORTERM=, which probably does not support color
	I1125 23:49:37.163109    9808 out.go:192] Setting JSON to false
	I1125 23:49:37.170077    9808 start.go:104] hostinfo: {"hostname":"mini-test-7-hv","uptime":1145839,"bootTime":1605202338,"procs":195,"os":"windows","platform":"Microsoft Windows 10 Enterprise N","platformFamily":"Standalone Workstation","platformVersion":"10.0.18363 Build 18363","kernelVersion":"","virtualizationSystem":"","virtualizationRole":"","hostid":"9b3837cd-cf48-4f67-a408-2a0186127a2f"}
	W1125 23:49:37.171095    9808 start.go:112] gopshost.Virtualization returned error: not implemented yet
	I1125 23:49:37.216076    9808 out.go:110] * [functional-20201125234332-3228] minikube v1.15.1 on Microsoft Windows 10 Enterprise N 10.0.18363 Build 18363
	I1125 23:49:37.238072    9808 out.go:110]   - KUBECONFIG=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome\kubeconfig
	I1125 23:49:37.244080    9808 out.go:110]   - MINIKUBE_HOME=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome
	I1125 23:49:37.249075    9808 driver.go:308] Setting default libvirt URI to qemu:///system
	I1125 23:49:40.103286    9808 out.go:110] * Using the hyperv driver based on existing profile
	I1125 23:49:40.104272    9808 start.go:266] selected driver: hyperv
	I1125 23:49:40.104272    9808 start.go:680] validating driver "hyperv" against &{Name:functional-20201125234332-3228 KeepContext:false EmbedCerts:false MinikubeISO:https://storage.googleapis.com/minikube/iso/minikube-v1.15.2-snapshot2.iso KicBaseImage:gcr.io/k8s-minikube/kicbase:v0.0.15-snapshot2@sha256:0973e4bcdfef0dc8c5a581ecfcca5e36fa6a1cc8773e832ecfd31de3d2b6bf46 Memory:4000 CPUs:2 DiskSize:20000 VMDriver: Driver:hyperv HyperkitVpnKitSock: HyperkitVSockPorts:[] DockerEnv:[] ContainerVolumeMounts:[] 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.19.4 ClusterName:functional-20201125234332-3228 Namespace:default APIServerNa
me:minikubeCA APIServerNames:[] APIServerIPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin: FeatureGates: ServiceCIDR:10.96.0.0/12 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: ExtraOptions:[] ShouldLoadCachedImages:true EnableDefaultCNI:false CNI: NodeIP: NodePort:8441 NodeName:} Nodes:[{Name: IP:192.168.13.2 Port:8441 KubernetesVersion:v1.19.4 ControlPlane:true Worker:true}] Addons:map[ambassador:false csi-hostpath-driver:false dashboard:false default-storageclass:true efk:false freshpod:false gcp-auth:false gvisor:false helm-tiller:false ingress:false ingress-dns:false istio:false istio-provisioner:false kubevirt:false logviewer:false metallb:false metrics-server:false nvidia-driver-installer:false nvidia-gpu-device-plugin:false olm:false pod-security-policy:false registry:false registry-aliases:false registry-creds:false storage-provisioner:true storage-provisioner-gluster:false volumesnapshots:false] VerifyComponents:map[apiserver:true apps_running:true default_sa
:true kubelet:true system_pods:true] StartHostTimeout:6m0s ScheduledStop:<nil> ExposedPorts:[]}
	I1125 23:49:40.104272    9808 start.go:691] status for hyperv: {Installed:true Healthy:true Running:false NeedsImprovement:false Error:<nil> Fix: Doc:}
** /stderr **
functional_test.go:486: dry-run exit code = 1, wanted = 0: exit status 1
--- FAIL: TestFunctional/parallel/DryRun (10.08s)

I rdped into that machine and I ran manually and it seems fine there

PS C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries> .\minikube-windows-amd64 start --dry-run --driver=hyperv --alsologtostderr
I1126 00:16:25.661164   12160 out.go:185] Setting OutFile to fd 88 ...
I1126 00:16:25.743158   12160 out.go:232] TERM=,COLORTERM=, which probably does not support color
I1126 00:16:25.746147   12160 out.go:198] Setting ErrFile to fd 92...
I1126 00:16:25.749144   12160 out.go:232] TERM=,COLORTERM=, which probably does not support color
I1126 00:16:25.776531   12160 out.go:192] Setting JSON to false
I1126 00:16:25.780150   12160 start.go:104] hostinfo: {"hostname":"mini-test-7-hv","uptime":1147447,"bootTime":1605202338,"procs":184,"os":"windows","platform":"Microsoft Windows 10 Enterprise N","platformFamily":"Standalone Workstation","platformVersion":"10.0.18363 Build 18363","kernelVersion":"","virtualizationSystem":"","virtualizationRole":"","hostid":"9b3837cd-cf48-4f67-a408-2a0186127a2f"}
W1126 00:16:25.782148   12160 start.go:112] gopshost.Virtualization returned error: not implemented yet
I1126 00:16:25.801148   12160 out.go:110] * minikube v1.15.1 on Microsoft Windows 10 Enterprise N 10.0.18363 Build 18363
* minikube v1.15.1 on Microsoft Windows 10 Enterprise N 10.0.18363 Build 18363
I1126 00:16:25.805147   12160 driver.go:308] Setting default libvirt URI to qemu:///system
I1126 00:16:27.814561   12160 out.go:110] * Using the hyperv driver based on user configuration
* Using the hyperv driver based on user configuration
I1126 00:16:27.820575   12160 start.go:266] selected driver: hyperv
I1126 00:16:27.822570   12160 start.go:680] validating driver "hyperv" against <nil>
I1126 00:16:27.825607   12160 start.go:691] status for hyperv: {Installed:true Healthy:true Running:false NeedsImprovement:false Error:<nil> Fix: Doc:}
I1126 00:16:27.828570   12160 start_flags.go:235] no existing cluster config was found, will generate one from the flags
I1126 00:16:29.921406   12160 start_flags.go:253] Using suggested 6000MB memory alloc based on sys=65535MB, container=0MB
I1126 00:16:29.923422   12160 start_flags.go:643] Wait components to verify : map[apiserver:true system_pods:true]
I1126 00:16:29.928408   12160 cni.go:74] Creating CNI manager for ""
I1126 00:16:29.931405   12160 cni.go:117] CNI unnecessary in this configuration, recommending no CNI
I1126 00:16:29.934424   12160 start_flags.go:366] config:
{Name:minikube KeepContext:false EmbedCerts:false MinikubeISO: KicBaseImage:gcr.io/k8s-minikube/kicbase:v0.0.15-snapshot@sha256:8aba7f18c2de2d5fa32da5a03653814482682311fa35f146b01d8c569fb73dc5 Memory:6000 CPUs:2 DiskSize:20000 VMDriver: Driver:hyperv HyperkitVpnKitSock: HyperkitVSockPorts:[] DockerEnv:[] ContainerVolumeMounts:[] 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.19.4 ClusterName:minikube Namespace:default APIServerName:minikubeCA APIServerNames:[] APIServerIPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin: FeatureGates: ServiceCIDR:10.96.0.0/12 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: ExtraOptions:[] ShouldLoadCachedImages:true EnableDefaultCNI:false CNI: NodeIP: NodePort:8443 NodeName:} Nodes:[] Addons:map[] VerifyComponents:map[apiserver:true system_pods:true] StartHostTimeout:6m0s ScheduledStop:<nil> ExposedPorts:[]}
I1126 00:16:29.946409   12160 out.go:110] * dry-run validation complete!
* dry-run validation complete!
PS C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries> $LastExitCode
0
PS C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries>
@medyagh medyagh added kind/failing-test Categorizes issue or PR as related to a consistently or frequently failing test. priority/important-soon Must be staffed and worked on either currently, or very soon, ideally in time for the next release. labels Nov 26, 2020
@blueelvis
Copy link
Contributor

/assign

@lingsamuel
Copy link
Contributor

found in #10118 full.log

2021-01-09T19:05:41.6885751Z         	I0109 19:05:40.028386   11148 start.go:713] status for hyperv: {Installed:true Healthy:true Running:false NeedsImprovement:false Error:<nil> Fix: Doc:}
2021-01-09T19:05:41.6886823Z         	I0109 19:05:41.443044   11148 out.go:119] 
2021-01-09T19:05:41.6887852Z         	W0109 19:05:41.443044   11148 out.go:181] X Exiting due to RSRC_INSUFFICIENT_REQ_MEMORY: Requested memory allocation 250MiB is less than the usable minimum of 1800MB
2021-01-09T19:05:41.6890282Z         	X Exiting due to RSRC_INSUFFICIENT_REQ_MEMORY: Requested memory allocation 250MiB is less than the usable minimum of 1800MB
2021-01-09T19:05:41.6893124Z         
2021-01-09T19:05:41.6893967Z         ** /stderr **
2021-01-09T19:05:41.6895288Z     functional_test.go:502: dry-run(250MB) exit code = 1, wanted = 23: exit status 1
2021-01-09T19:05:41.6902289Z     functional_test.go:509: (dbg) Run:  ./minikube-windows-amd64.exe start -p functional-20210109185753-17220 --dry-run --alsologtostderr -v=1 --driver=hyperv

How can this happened...

@lingsamuel
Copy link
Contributor

Some progress:

2021-01-13T04:55:15.3209055Z         	I0113 04:55:14.192858    8608 start.go:1052] validating memory
2021-01-13T04:55:15.3209786Z         	I0113 04:55:14.192858    8608 start.go:920] validating requested memory size
2021-01-13T04:55:15.3212248Z         
2021-01-13T04:55:15.3217740Z         ** /stderr **
2021-01-13T04:55:15.3222621Z     functional_test.go:507: dry-run(250MB) exit code = 1, wanted = 23: exit status 1

minikube/cmd/minikube/cmd/start.go

Lines 919 to 939 in 447b58c

func validateRequestedMemorySize(req int, drvName string) {
klog.Infof("validating requested memory size")
// TODO: Fix MB vs MiB confusion
sysLimit, containerLimit, err := memoryLimits(drvName)
if err != nil {
klog.Warningf("Unable to query memory limits: %v", err)
}
// Detect if their system doesn't have enough memory to work with.
if driver.IsKIC(drvName) && containerLimit < minUsableMem {
if driver.IsDockerDesktop(drvName) {
if runtime.GOOS == "darwin" {
exitIfNotForced(reason.RsrcInsufficientDarwinDockerMemory, "Docker Desktop only has {{.size}}MiB available, less than the required {{.req}}MiB for Kubernetes", out.V{"size": containerLimit, "req": minUsableMem, "recommend": "2.25 GB"})
} else {
exitIfNotForced(reason.RsrcInsufficientWindowsDockerMemory, "Docker Desktop only has {{.size}}MiB available, less than the required {{.req}}MiB for Kubernetes", out.V{"size": containerLimit, "req": minUsableMem, "recommend": "2.25 GB"})
}
}
exitIfNotForced(reason.RsrcInsufficientContainerMemory, "{{.driver}} only has {{.size}}MiB available, less than the required {{.req}}MiB for Kubernetes", out.V{"size": containerLimit, "driver": drvName, "req": minUsableMem})
}
klog.Infof("validating sys and req memory size")

@lingsamuel lingsamuel mentioned this issue Jan 14, 2021
Closed
@lingsamuel
Copy link
Contributor

found in #10118 full.log

2021-01-09T19:05:41.6885751Z         	I0109 19:05:40.028386   11148 start.go:713] status for hyperv: {Installed:true Healthy:true Running:false NeedsImprovement:false Error:<nil> Fix: Doc:}
2021-01-09T19:05:41.6886823Z         	I0109 19:05:41.443044   11148 out.go:119] 
2021-01-09T19:05:41.6887852Z         	W0109 19:05:41.443044   11148 out.go:181] X Exiting due to RSRC_INSUFFICIENT_REQ_MEMORY: Requested memory allocation 250MiB is less than the usable minimum of 1800MB
2021-01-09T19:05:41.6890282Z         	X Exiting due to RSRC_INSUFFICIENT_REQ_MEMORY: Requested memory allocation 250MiB is less than the usable minimum of 1800MB
2021-01-09T19:05:41.6893124Z         
2021-01-09T19:05:41.6893967Z         ** /stderr **
2021-01-09T19:05:41.6895288Z     functional_test.go:502: dry-run(250MB) exit code = 1, wanted = 23: exit status 1
2021-01-09T19:05:41.6902289Z     functional_test.go:509: (dbg) Run:  ./minikube-windows-amd64.exe start -p functional-20210109185753-17220 --dry-run --alsologtostderr -v=1 --driver=hyperv

Notice the output. The success output has one more empty line:

2021-01-13T23:14:15.6578104Z         	I0113 23:14:15.574058   16756 out.go:119] 
2021-01-13T23:14:15.6584332Z         	W0113 23:14:15.574058   16756 out.go:181] X Exiting due to RSRC_INSUFFICIENT_REQ_MEMORY: Requested memory allocation 250MiB is less than the usable minimum of 1800MB
2021-01-13T23:14:15.6589398Z         	X Exiting due to RSRC_INSUFFICIENT_REQ_MEMORY: Requested memory allocation 250MiB is less than the usable minimum of 1800MB
2021-01-13T23:14:15.6593756Z         	I0113 23:14:15.584550   16756 out.go:119]

@lingsamuel
Copy link
Contributor

I highly suspect klog.Flush().

@medyagh
Copy link
Member Author

medyagh commented Feb 19, 2021

this issue still happens

021-02-18T21:11:23.9645805Z     functional_test.go:610: (dbg) Run:  ./minikube-windows-amd64.exe start -p functional-20210218210012-1864 --dry-run --memory 250MB --alsologtostderr --driver=hyperv
2021-02-18T21:11:28.2940210Z === CONT  TestFunctional/parallel/PersistentVolumeClaim
2021-02-18T21:11:28.2946015Z     fn_pvc_test.go:129: (dbg) TestFunctional/parallel/PersistentVolumeClaim: test=storage-provisioner healthy within 25.1292776s
2021-02-18T21:11:28.3077103Z     fn_pvc_test.go:99: (dbg) Run:  kubectl --context functional-20210218210012-1864 exec sp-pod -- touch /tmp/mount/foo
2021-02-18T21:11:29.0275773Z === CONT  TestFunctional/parallel/DryRun
2021-02-18T21:11:29.0289808Z     functional_test.go:610: (dbg) Non-zero exit: ./minikube-windows-amd64.exe start -p functional-20210218210012-1864 --dry-run --memory 250MB --alsologtostderr --driver=hyperv: exit status 1 (5.063206s)
2021-02-18T21:11:29.0364458Z         
2021-02-18T21:11:29.0366502Z         -- stdout --
2021-02-18T21:11:29.0368692Z         	* [functional-20210218210012-1864] minikube v1.17.1 on Microsoft Windows 10 Enterprise N 10.0.18363 Build 18363
2021-02-18T21:11:29.0372485Z         	  - KUBECONFIG=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome\kubeconfig
2021-02-18T21:11:29.0375650Z         	  - MINIKUBE_HOME=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome
2021-02-18T21:11:29.0378437Z         
2021-02-18T21:11:29.0409364Z         -- /stdout --
2021-02-18T21:11:29.0411832Z         ** stderr ** 
2021-02-18T21:11:29.0413398Z         	I0218 21:11:24.629935    8932 out.go:229] Setting OutFile to fd 1056 ...
2021-02-18T21:11:29.0416072Z         	I0218 21:11:24.756932    8932 out.go:276] TERM=,COLORTERM=, which probably does not support color
2021-02-18T21:11:29.0633387Z         	I0218 21:11:24.756932    8932 out.go:242] Setting ErrFile to fd 1208...
2021-02-18T21:11:29.0635191Z         	I0218 21:11:24.756932    8932 out.go:276] TERM=,COLORTERM=, which probably does not support color
2021-02-18T21:11:29.0637308Z         	I0218 21:11:24.789930    8932 out.go:236] Setting JSON to false
2021-02-18T21:11:29.0641013Z         	I0218 21:11:24.795930    8932 start.go:107] hostinfo: {"hostname":"mini-test-7-hv","uptime":66067,"bootTime":1613616617,"procs":143,"os":"windows","platform":"Microsoft Windows 10 Enterprise N","platformFamily":"Standalone Workstation","platformVersion":"10.0.18363 Build 18363","kernelVersion":"10.0.18363 Build 18363","kernelArch":"x86_64","virtualizationSystem":"","virtualizationRole":"","hostId":"9b3837cd-cf48-4f67-a408-2a0186127a2f"}
2021-02-18T21:11:29.0645731Z         	W0218 21:11:24.795930    8932 start.go:115] gopshost.Virtualization returned error: not implemented yet
2021-02-18T21:11:29.0647930Z         	I0218 21:11:24.803941    8932 out.go:119] * [functional-20210218210012-1864] minikube v1.17.1 on Microsoft Windows 10 Enterprise N 10.0.18363 Build 18363
2021-02-18T21:11:29.0650359Z         	I0218 21:11:24.805940    8932 out.go:119]   - KUBECONFIG=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome\kubeconfig
2021-02-18T21:11:29.0653162Z         	I0218 21:11:24.807947    8932 out.go:119]   - MINIKUBE_HOME=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome
2021-02-18T21:11:29.0655139Z         	I0218 21:11:24.812539    8932 driver.go:315] Setting default libvirt URI to qemu:///system
2021-02-18T21:11:29.0656145Z         
2021-02-18T21:11:29.0656808Z         ** /stderr **
2021-02-18T21:11:29.0657891Z     functional_test.go:614: dry-run(250MB) exit code = 1, wanted = 23: exit status 1
2021-02-18T21:11:29.0660459Z     functional_test.go:621: (dbg) Run:  ./minikube-windows-amd64.exe start -p functional-20210218210012-1864 --dry-run --alsologtostderr -v=1 --driver=hyperv
2021-02-18T21:11:29.4201930Z === CONT  TestFunctional/parallel/PersistentVolumeClaim
2021-02-18T21:11:29.4206807Z     fn_pvc_test.go:99: (dbg) Done: kubectl --context functional-20210218210012-1864 exec sp-pod -- touch /tmp/mount/foo: (1.1131304s)
2021-02-18T21:11:29.4345457Z     fn_pvc_test.go:105: (dbg) Run:  kubectl --context functional-20210218210012-1864 delete -f testdata/storage-provisioner/pod.yaml
2021-02-18T21:11:33.3797246Z === CONT  TestFunctional/parallel/DockerEnv
2021-02-18T21:11:33.3804945Z     functional_test.go:221: (dbg) Done: powershell.exe -NoProfile -NonInteractive "./minikube-windows-amd64.exe -p functional-20210218210012-1864 docker-env | Invoke-Expression ;./minikube-windows-amd64.exe status -p functional-20210218210012-1864": (38.9082543s)
2021-02-18T21:11:33.3934464Z     functional_test.go:242: (dbg) Run:  powershell.exe -NoProfile -NonInteractive ./minikube-windows-amd64.exe "-p functional-20210218210012-1864 docker-env | Invoke-Expression ; docker images"
2021-02-18T21:11:33.8920603Z === CONT  TestFunctional/parallel/ProfileCmd/profile_json_output
2021-02-18T21:11:33.8926084Z     functional_test.go:904: (dbg) Done: ./minikube-windows-amd64.exe profile list -o json: (11.961491s)
2021-02-18T21:11:33.8931780Z     functional_test.go:909: Took "11.961491s" to run "./minikube-windows-amd64.exe profile list -o json"
2021-02-18T21:11:33.8937513Z     functional_test.go:917: (dbg) Run:  ./minikube-windows-amd64.exe profile list -o json --light
2021-02-18T21:11:34.0651999Z === CONT  TestFunctional/parallel/DryRun
2021-02-18T21:11:34.0658913Z     functional_test.go:621: (dbg) Non-zero exit: ./minikube-windows-amd64.exe start -p functional-20210218210012-1864 --dry-run --alsologtostderr -v=1 --driver=hyperv: exit status 1 (5.0393872s)
2021-02-18T21:11:34.0664254Z         
2021-02-18T21:11:34.0672229Z         -- stdout --
2021-02-18T21:11:34.0680429Z

@lingsamuel do u mean we need to do klog.Flush ?

@lingsamuel
Copy link
Contributor

Yes.
Look at the log I found here:

2021-01-09T19:05:41.6886823Z         	I0109 19:05:41.443044   11148 out.go:119] 
2021-01-09T19:05:41.6887852Z         	W0109 19:05:41.443044   11148 out.go:181] X Exiting due to RSRC_INSUFFICIENT_REQ_MEMORY: Requested memory allocation 250MiB is less than the usable minimum of 1800MB
2021-01-09T19:05:41.6890282Z         	X Exiting due to RSRC_INSUFFICIENT_REQ_MEMORY: Requested memory allocation 250MiB is less than the usable minimum of 1800MB
2021-01-09T19:05:41.6893124Z         
2021-01-09T19:05:41.6893967Z         ** /stderr **

I guess this is the closest log I can find to the real cause.
The function exitIfNotForced is called, and it entered displayText in out_reason.go, and the Ln("") and ErrT() printed normally, but the last one Ln("") didn't.
While the error kind doesn't have advice/url/issues to print, and if we assume klog.Flush() inside last Ln wont crash the program, I guess:

  • The Ln calls klog.Flush(), but ErrT doesn't, maybe it should.

@medyagh
Copy link
Member Author

medyagh commented Feb 24, 2021

still happening. functional_test.go:617: dry-run(250MB) exit code = 1, wanted = 23: exit status 1

@spowelljr spowelljr added priority/important-longterm Important over the long term, but may not be staffed and/or may need multiple releases to complete. and removed priority/important-soon Must be staffed and worked on either currently, or very soon, ideally in time for the next release. labels Apr 7, 2021
@medyagh
Copy link
Member Author

medyagh commented Apr 19, 2021

weird thing is I see many Info logs been sent out to the stderr



=== RUN   TestFunctional/parallel/DryRun
=== PAUSE TestFunctional/parallel/DryRun
=== CONT  TestFunctional/parallel/DryRun
functional_test.go:703: (dbg) Run:  ./minikube-windows-amd64.exe start -p functional-20210419024902-8968 --dry-run --memory 250MB --alsologtostderr --driver=hyperv
=== CONT  TestFunctional/parallel/DryRun
functional_test.go:703: (dbg) Non-zero exit: ./minikube-windows-amd64.exe start -p functional-20210419024902-8968 --dry-run --memory 250MB --alsologtostderr --driver=hyperv: exit status 1 (5.0358397s)
-- stdout --
	* [functional-20210419024902-8968] minikube v1.19.0 on Microsoft Windows 10 Enterprise N 10.0.18363 Build 18363
	  - KUBECONFIG=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome\kubeconfig
	  - MINIKUBE_HOME=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome
	* Using the hyperv driver based on existing profile
-- /stdout --
** stderr ** 
	I0419 02:59:43.971865    8812 out.go:278] Setting OutFile to fd 1700 ...
	I0419 02:59:44.081857    8812 out.go:325] TERM=,COLORTERM=, which probably does not support color
	I0419 02:59:44.081857    8812 out.go:291] Setting ErrFile to fd 1712...
	I0419 02:59:44.081857    8812 out.go:325] TERM=,COLORTERM=, which probably does not support color
	I0419 02:59:44.108861    8812 out.go:285] Setting JSON to false
	I0419 02:59:44.112855    8812 start.go:108] hostinfo: {"hostname":"mini-test-7-hv","uptime":379216,"bootTime":1618421968,"procs":146,"os":"windows","platform":"Microsoft Windows 10 Enterprise N","platformFamily":"Standalone Workstation","platformVersion":"10.0.18363 Build 18363","kernelVersion":"10.0.18363 Build 18363","kernelArch":"x86_64","virtualizationSystem":"","virtualizationRole":"","hostId":"9b3837cd-cf48-4f67-a408-2a0186127a2f"}
	W0419 02:59:44.113862    8812 start.go:116] gopshost.Virtualization returned error: not implemented yet
	I0419 02:59:44.117866    8812 out.go:157] * [functional-20210419024902-8968] minikube v1.19.0 on Microsoft Windows 10 Enterprise N 10.0.18363 Build 18363
	I0419 02:59:44.118856    8812 out.go:157]   - KUBECONFIG=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome\kubeconfig
	I0419 02:59:44.119854    8812 out.go:157]   - MINIKUBE_HOME=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome
	I0419 02:59:44.123865    8812 driver.go:322] Setting default libvirt URI to qemu:///system
	I0419 02:59:46.961634    8812 out.go:157] * Using the hyperv driver based on existing profile
	I0419 02:59:46.961860    8812 start.go:276] selected driver: hyperv
	I0419 02:59:46.962068    8812 start.go:718] validating driver "hyperv" against &{Name:functional-20210419024902-8968 KeepContext:false EmbedCerts:false MinikubeISO:https://storage.googleapis.com/minikube/iso/minikube-v1.19.0.iso KicBaseImage:gcr.io/k8s-minikube/kicbase:v0.0.20@sha256:0250dab3644403384bd54f566921c6b57138eecffbb861f9392feef9b2ec44f6 Memory:4000 CPUs:2 DiskSize:20000 VMDriver: Driver:hyperv HyperkitVpnKitSock: HyperkitVSockPorts:[] DockerEnv:[] ContainerVolumeMounts:[] InsecureRegistry:[] RegistryMirror:[] HostOnlyCIDR:192.168.99.1/24 HypervVirtualSwitch: HypervUseExternalSwitch:false HypervExternalAdapter: KVMNetwork:default KVMQemuURI:qemu:///system KVMGPU:false KVMHidden:false KVMNUMACount:1 DockerOpt:[] DisableDriverMounts:false NFSShare:[] NFSSharesRoot:/nfsshares UUID: NoVTXCheck:false DNSProxy:false HostDNSResolver:true HostOnlyNicType:virtio NatNicType:virtio SSHIPAddress: SSHUser:root SSHKey: SSHPort:22 KubernetesConfig:{KubernetesVersion:v1.20.2 ClusterName:functional-20210419
024902-8968 Namespace:default APIServerName:minikubeCA APIServerNames:[] APIServerIPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin: FeatureGates: ServiceCIDR:10.96.0.0/12 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: CustomIngressCert: ExtraOptions:[{Component:apiserver Key:enable-admission-plugins Value:NamespaceAutoProvision}] ShouldLoadCachedImages:true EnableDefaultCNI:false CNI: NodeIP: NodePort:8441 NodeName:} Nodes:[{Name: IP:172.17.15.173 Port:8441 KubernetesVersion:v1.20.2 ControlPlane:true Worker:true}] Addons:map[ambassador:false auto-pause:false csi-hostpath-driver:false dashboard:false default-storageclass:true efk:false freshpod:false gcp-auth:false gvisor:false helm-tiller:false ingress:false ingress-dns:false istio:false istio-provisioner:false kubevirt:false logviewer:false metallb:false metrics-server:false nvidia-driver-installer:false nvidia-gpu-device-plugin:false olm:false pod-security-policy:false registry:false registry-aliases:false registry-c
reds:false storage-provisioner:true storage-provisioner-gluster:false volumesnapshots:false] VerifyComponents:map[apiserver:true apps_running:true default_sa:true extra:true kubelet:true node_ready:true system_pods:true] StartHostTimeout:6m0s ScheduledStop:<nil> ExposedPorts:[] ListenAddress: Network: MultiNodeRequested:false}
	I0419 02:59:46.962805    8812 start.go:729] status for hyperv: {Installed:true Healthy:true Running:false NeedsImprovement:false Error:<nil> Reason: Fix: Doc:}
** /stderr **
functional_test.go:707: dry-run(250MB) exit code = 1, wanted = 23: exit status 1
functional_test.go:714: (dbg) Run:  ./minikube-windows-amd64.exe start -p functional-20210419024902-8968 --dry-run --alsologtostderr -v=1 --driver=hyperv
=== CONT  TestFunctional/parallel/DryRun
functional_test.go:714: (dbg) Non-zero exit: ./minikube-windows-amd64.exe start -p functional-20210419024902-8968 --dry-run --alsologtostderr -v=1 --driver=hyperv: exit status 1 (5.0402328s)
-- stdout --
	* [functional-20210419024902-8968] minikube v1.19.0 on Microsoft Windows 10 Enterprise N 10.0.18363 Build 18363
	  - KUBECONFIG=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome\kubeconfig
	  - MINIKUBE_HOME=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome
	* Using the hyperv driver based on existing profile
-- /stdout --
** stderr ** 
	I0419 02:59:48.936556    3416 out.go:278] Setting OutFile to fd 1140 ...
	I0419 02:59:49.054513    3416 out.go:325] TERM=,COLORTERM=, which probably does not support color
	I0419 02:59:49.054513    3416 out.go:291] Setting ErrFile to fd 1720...
	I0419 02:59:49.054513    3416 out.go:325] TERM=,COLORTERM=, which probably does not support color
	I0419 02:59:49.084521    3416 out.go:285] Setting JSON to false
	I0419 02:59:49.090514    3416 start.go:108] hostinfo: {"hostname":"mini-test-7-hv","uptime":379221,"bootTime":1618421968,"procs":148,"os":"windows","platform":"Microsoft Windows 10 Enterprise N","platformFamily":"Standalone Workstation","platformVersion":"10.0.18363 Build 18363","kernelVersion":"10.0.18363 Build 18363","kernelArch":"x86_64","virtualizationSystem":"","virtualizationRole":"","hostId":"9b3837cd-cf48-4f67-a408-2a0186127a2f"}
	W0419 02:59:49.090514    3416 start.go:116] gopshost.Virtualization returned error: not implemented yet
	I0419 02:59:49.094517    3416 out.go:157] * [functional-20210419024902-8968] minikube v1.19.0 on Microsoft Windows 10 Enterprise N 10.0.18363 Build 18363
	I0419 02:59:49.096516    3416 out.go:157]   - KUBECONFIG=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome\kubeconfig
	I0419 02:59:49.096516    3416 out.go:157]   - MINIKUBE_HOME=C:\Users\jenkins\actions-runner\_work\minikube\minikube\minikube_binaries\testhome
	I0419 02:59:49.101529    3416 driver.go:322] Setting default libvirt URI to qemu:///system
	I0419 02:59:52.231541    3416 out.go:157] * Using the hyperv driver based on existing profile
	I0419 02:59:52.232098    3416 start.go:276] selected driver: hyperv
	I0419 02:59:52.232098    3416 start.go:718] validating driver "hyperv" against &{Name:functional-20210419024902-8968 KeepContext:false EmbedCerts:false MinikubeISO:https://storage.googleapis.com/minikube/iso/minikube-v1.19.0.iso KicBaseImage:gcr.io/k8s-minikube/kicbase:v0.0.20@sha256:0250dab3644403384bd54f566921c6b57138eecffbb861f9392feef9b2ec44f6 Memory:4000 CPUs:2 DiskSize:20000 VMDriver: Driver:hyperv HyperkitVpnKitSock: HyperkitVSockPorts:[] DockerEnv:[] ContainerVolumeMounts:[] InsecureRegistry:[] RegistryMirror:[] HostOnlyCIDR:192.168.99.1/24 HypervVirtualSwitch: HypervUseExternalSwitch:false HypervExternalAdapter: KVMNetwork:default KVMQemuURI:qemu:///system KVMGPU:false KVMHidden:false KVMNUMACount:1 DockerOpt:[] DisableDriverMounts:false NFSShare:[] NFSSharesRoot:/nfsshares UUID: NoVTXCheck:false DNSProxy:false HostDNSResolver:true HostOnlyNicType:virtio NatNicType:virtio SSHIPAddress: SSHUser:root SSHKey: SSHPort:22 KubernetesConfig:{KubernetesVersion:v1.20.2 ClusterName:functional-20210419
024902-8968 Namespace:default APIServerName:minikubeCA APIServerNames:[] APIServerIPs:[] DNSDomain:cluster.local ContainerRuntime:docker CRISocket: NetworkPlugin: FeatureGates: ServiceCIDR:10.96.0.0/12 ImageRepository: LoadBalancerStartIP: LoadBalancerEndIP: CustomIngressCert: ExtraOptions:[{Component:apiserver Key:enable-admission-plugins Value:NamespaceAutoProvision}] ShouldLoadCachedImages:true EnableDefaultCNI:false CNI: NodeIP: NodePort:8441 NodeName:} Nodes:[{Name: IP:172.17.15.173 Port:8441 KubernetesVersion:v1.20.2 ControlPlane:true Worker:true}] Addons:map[ambassador:false auto-pause:false csi-hostpath-driver:false dashboard:false default-storageclass:true efk:false freshpod:false gcp-auth:false gvisor:false helm-tiller:false ingress:false ingress-dns:false istio:false istio-provisioner:false kubevirt:false logviewer:false metallb:false metrics-server:false nvidia-driver-installer:false nvidia-gpu-device-plugin:false olm:false pod-security-policy:false registry:false registry-aliases:false registry-c
reds:false storage-provisioner:true storage-provisioner-gluster:false volumesnapshots:false] VerifyComponents:map[apiserver:true apps_running:true default_sa:true extra:true kubelet:true node_ready:true system_pods:true] StartHostTimeout:6m0s ScheduledStop:<nil> ExposedPorts:[] ListenAddress: Network: MultiNodeRequested:false}
	I0419 02:59:52.232849    3416 start.go:729] status for hyperv: {Installed:true Healthy:true Running:false NeedsImprovement:false Error:<nil> Reason: Fix: Doc:}
** /stderr **
functional_test.go:716: dry-run exit code = 1, wanted = 0: exit status 1
--- FAIL: TestFunctional/parallel/DryRun (10.08s)

@medyagh
Copy link
Member Author

medyagh commented Apr 19, 2021

@blueelvis are you still working on this ?

@fejta-bot
Copy link

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-contributor-experience at kubernetes/community.
/lifecycle stale

@k8s-ci-robot k8s-ci-robot added the lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. label Jul 18, 2021
@k8s-triage-robot
Copy link

The Kubernetes project currently lacks enough active contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

  • After 90d of inactivity, lifecycle/stale is applied
  • After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
  • After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

  • Mark this issue or PR as fresh with /remove-lifecycle rotten
  • Close this issue or PR with /close
  • Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/lifecycle rotten

@k8s-ci-robot k8s-ci-robot added lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed. and removed lifecycle/stale Denotes an issue or PR has remained open with no activity and has become stale. labels Aug 17, 2021
@spowelljr
Copy link
Member

This test seems to pass now, closing.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
kind/failing-test Categorizes issue or PR as related to a consistently or frequently failing test. lifecycle/rotten Denotes an issue or PR that has aged beyond stale and will be auto-closed. priority/important-longterm Important over the long term, but may not be staffed and/or may need multiple releases to complete.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
7 participants
@medyagh @blueelvis @lingsamuel @k8s-ci-robot @fejta-bot @spowelljr @k8s-triage-robot