search

kubernetes / minikube

Run Kubernetes locally
https://minikube.sigs.k8s.io/
Apache License 2.0
29.44k stars 4.89k forks source link

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

Closed medyagh closed 3 years ago

medyagh commented 3 years ago

"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>
blueelvis commented 3 years ago

/assign

lingsamuel commented 3 years ago

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 commented 3 years ago

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

https://github.com/kubernetes/minikube/blob/447b58cb24622809c136d8acb7d0bc807dcd312f/cmd/minikube/cmd/start.go#L919-L939

lingsamuel commented 3 years ago

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 commented 3 years ago

I highly suspect klog.Flush().

medyagh commented 3 years ago

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 commented 3 years ago

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:

medyagh commented 3 years ago

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

medyagh commented 3 years ago

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 commented 3 years ago

@blueelvis are you still working on this ?

fejta-bot commented 3 years ago

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-triage-robot commented 3 years ago

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:

You can:

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

/lifecycle rotten

spowelljr commented 3 years ago

This test seems to pass now, closing.