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

KVM failing test: TestFunctional/parallel/MountCmd #10696

Closed
medyagh opened this issue Mar 2, 2021 · 7 comments · Fixed by #10733
Closed

KVM failing test: TestFunctional/parallel/MountCmd #10696

medyagh opened this issue Mar 2, 2021 · 7 comments · Fixed by #10733
Assignees
@govargo
Labels
area/mount co/kvm2-driver KVM2 driver related issues kind/bug Categorizes issue or PR as related to a bug. 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.
Milestone
v.1.19.0

Comments

@medyagh
Copy link
Member

medyagh commented Mar 2, 2021

example https://storage.googleapis.com/minikube-builds/logs/10656/dd6687e/KVM_Linux.html

=== RUN   TestFunctional/parallel/MountCmd
=== PAUSE TestFunctional/parallel/MountCmd
=== CONT  TestFunctional/parallel/MountCmd
=== CONT  TestFunctional/parallel/MountCmd
fn_mount_cmd_test.go:72: (dbg) daemon: [out/minikube-linux-amd64 mount -p functional-20210302173523-7287 /tmp/mounttest342817430:/mount-9p --alsologtostderr -v=1]
fn_mount_cmd_test.go:106: wrote "test-1614706782178722166" to /tmp/mounttest342817430/created-by-test
fn_mount_cmd_test.go:106: wrote "test-1614706782178722166" to /tmp/mounttest342817430/created-by-test-removed-by-pod
fn_mount_cmd_test.go:106: wrote "test-1614706782178722166" to /tmp/mounttest342817430/test-1614706782178722166
fn_mount_cmd_test.go:114: (dbg) Run:  out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p"
=== CONT  TestFunctional/parallel/MountCmd
fn_mount_cmd_test.go:114: (dbg) Non-zero exit: out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p": exit status 1 (440.274675ms)
** stderr ** 
	ssh: Process exited with status 1
** /stderr **
=== CONT  TestFunctional/parallel/MountCmd
fn_mount_cmd_test.go:114: (dbg) Run:  out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p"
fn_mount_cmd_test.go:114: (dbg) Non-zero exit: out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p": exit status 1 (291.706818ms)
** stderr ** 
	ssh: Process exited with status 1
** /stderr **
=== CONT  TestFunctional/parallel/MountCmd
fn_mount_cmd_test.go:114: (dbg) Run:  out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p"
=== CONT  TestFunctional/parallel/MountCmd
fn_mount_cmd_test.go:114: (dbg) Non-zero exit: out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p": exit status 1 (360.793177ms)
** stderr ** 
	ssh: Process exited with status 1
** /stderr **
=== CONT  TestFunctional/parallel/MountCmd
fn_mount_cmd_test.go:114: (dbg) Run:  out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p"
=== CONT  TestFunctional/parallel/MountCmd
fn_mount_cmd_test.go:114: (dbg) Non-zero exit: out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p": exit status 1 (288.610176ms)
** stderr ** 
	ssh: Process exited with status 1
** /stderr **
fn_mount_cmd_test.go:114: (dbg) Run:  out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p"
fn_mount_cmd_test.go:114: (dbg) Non-zero exit: out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p": exit status 1 (289.443264ms)
** stderr ** 
	ssh: Process exited with status 1
** /stderr **
fn_mount_cmd_test.go:114: (dbg) Run:  out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p"
fn_mount_cmd_test.go:114: (dbg) Non-zero exit: out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p": exit status 1 (353.827389ms)
** stderr ** 
	ssh: Process exited with status 1
** /stderr **
=== CONT  TestFunctional/parallel/MountCmd
fn_mount_cmd_test.go:114: (dbg) Run:  out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p"
=== CONT  TestFunctional/parallel/MountCmd
fn_mount_cmd_test.go:114: (dbg) Non-zero exit: out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p": exit status 1 (277.549972ms)
** stderr ** 
	ssh: Process exited with status 1
** /stderr **
=== CONT  TestFunctional/parallel/MountCmd
fn_mount_cmd_test.go:114: (dbg) Run:  out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p"
=== CONT  TestFunctional/parallel/MountCmd
fn_mount_cmd_test.go:114: (dbg) Non-zero exit: out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "findmnt -T /mount-9p | grep 9p": exit status 1 (312.044217ms)
** stderr ** 
	ssh: Process exited with status 1
** /stderr **
fn_mount_cmd_test.go:124: /mount-9p did not appear within 17.747581045s: exit status 1
fn_mount_cmd_test.go:79: "TestFunctional/parallel/MountCmd" failed, getting debug info...
fn_mount_cmd_test.go:80: (dbg) Run:  out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "mount | grep 9p; ls -la /mount-9p; cat /mount-9p/pod-dates"
=== CONT  TestFunctional/parallel/MountCmd
fn_mount_cmd_test.go:80: (dbg) Non-zero exit: out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "mount | grep 9p; ls -la /mount-9p; cat /mount-9p/pod-dates": exit status 1 (407.087062ms)
-- stdout --
	total 0
	drwxr-xr-x  2 root root  40 Mar  2 17:39 .
	drwxr-xr-x 19 root root 500 Mar  2 17:39 ..
	cat: /mount-9p/pod-dates: No such file or directory
-- /stdout --
** stderr ** 
	ssh: Process exited with status 1
** /stderr **
fn_mount_cmd_test.go:82: debugging command "out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh \"mount | grep 9p; ls -la /mount-9p; cat /mount-9p/pod-dates\"" failed : exit status 1
fn_mount_cmd_test.go:89: (dbg) Run:  out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "sudo umount -f /mount-9p"
=== CONT  TestFunctional/parallel/MountCmd
fn_mount_cmd_test.go:89: (dbg) Non-zero exit: out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh "sudo umount -f /mount-9p": exit status 1 (393.610895ms)
-- stdout --
	umount: /mount-9p: not mounted.
-- /stdout --
** stderr ** 
	ssh: Process exited with status 32
** /stderr **
fn_mount_cmd_test.go:91: "out/minikube-linux-amd64 -p functional-20210302173523-7287 ssh \"sudo umount -f /mount-9p\"": exit status 1
fn_mount_cmd_test.go:93: (dbg) stopping [out/minikube-linux-amd64 mount -p functional-20210302173523-7287 /tmp/mounttest342817430:/mount-9p --alsologtostderr -v=1] ...
fn_mount_cmd_test.go:93: (dbg) [out/minikube-linux-amd64 mount -p functional-20210302173523-7287 /tmp/mounttest342817430:/mount-9p --alsologtostderr -v=1] stdout:
* Mounting host path /tmp/mounttest342817430 into VM as /mount-9p ...
- Mount type:   
- User ID:      docker
- Group ID:     docker
- Version:      9p2000.L
- Message Size: 262144
- Permissions:  755 (-rwxr-xr-x)
- Options:      map[]
- Bind Address: 192.168.39.29:38969
* Userspace file server: ufs starting
* Userspace file server is shutdown
fn_mount_cmd_test.go:93: (dbg) [out/minikube-linux-amd64 mount -p functional-20210302173523-7287 /tmp/mounttest342817430:/mount-9p --alsologtostderr -v=1] stderr:
I0302 17:39:42.319536    9828 out.go:229] Setting OutFile to fd 1 ...
I0302 17:39:42.319889    9828 out.go:276] TERM=,COLORTERM=, which probably does not support color
I0302 17:39:42.319904    9828 out.go:242] Setting ErrFile to fd 2...
I0302 17:39:42.319911    9828 out.go:276] TERM=,COLORTERM=, which probably does not support color
I0302 17:39:42.320111    9828 root.go:308] Updating PATH: /home/jenkins/minikube-integration/linux-amd64-kvm2--10656-2894-dd6687ecb2d95647810c3fe334f12e92c7227707/.minikube/bin
I0302 17:39:42.320444    9828 mustload.go:66] Loading cluster: functional-20210302173523-7287
I0302 17:39:42.321736    9828 main.go:121] libmachine: Found binary path at /home/jenkins/workspace/KVM_Linux_integration/out/docker-machine-driver-kvm2
I0302 17:39:42.321811    9828 main.go:121] libmachine: Launching plugin server for driver kvm2
I0302 17:39:42.344148    9828 main.go:121] libmachine: Plugin server listening at address 127.0.0.1:35317
I0302 17:39:42.344958    9828 main.go:121] libmachine: () Calling .GetVersion
I0302 17:39:42.345727    9828 main.go:121] libmachine: Using API Version  1
I0302 17:39:42.345756    9828 main.go:121] libmachine: () Calling .SetConfigRaw
I0302 17:39:42.346195    9828 main.go:121] libmachine: () Calling .GetMachineName
I0302 17:39:42.346358    9828 main.go:121] libmachine: (functional-20210302173523-7287) Calling .GetState
I0302 17:39:42.352080    9828 host.go:66] Checking if "functional-20210302173523-7287" exists ...
I0302 17:39:42.352739    9828 main.go:121] libmachine: Found binary path at /home/jenkins/workspace/KVM_Linux_integration/out/docker-machine-driver-kvm2
I0302 17:39:42.352802    9828 main.go:121] libmachine: Launching plugin server for driver kvm2
I0302 17:39:42.370399    9828 main.go:121] libmachine: Plugin server listening at address 127.0.0.1:38909
I0302 17:39:42.371167    9828 main.go:121] libmachine: () Calling .GetVersion
I0302 17:39:42.371896    9828 main.go:121] libmachine: Using API Version  1
I0302 17:39:42.371932    9828 main.go:121] libmachine: () Calling .SetConfigRaw
I0302 17:39:42.372356    9828 main.go:121] libmachine: () Calling .GetMachineName
I0302 17:39:42.372619    9828 main.go:121] libmachine: (functional-20210302173523-7287) Calling .DriverName
I0302 17:39:42.372820    9828 main.go:121] libmachine: (functional-20210302173523-7287) Calling .DriverName
I0302 17:39:42.373049    9828 main.go:121] libmachine: (functional-20210302173523-7287) Calling .GetIP
I0302 17:39:42.391219    9828 main.go:121] libmachine: (functional-20210302173523-7287) Calling .DriverName
I0302 17:39:42.398646    9828 out.go:119] * Mounting host path /tmp/mounttest342817430 into VM as /mount-9p ...
I0302 17:39:42.400992    9828 out.go:119]   - Mount type:   
I0302 17:39:42.403136    9828 out.go:119]   - User ID:      docker
I0302 17:39:42.405268    9828 out.go:119]   - Group ID:     docker
I0302 17:39:42.407363    9828 out.go:119]   - Version:      9p2000.L
I0302 17:39:42.409425    9828 out.go:119]   - Message Size: 262144
I0302 17:39:42.412314    9828 out.go:119]   - Permissions:  755 (-rwxr-xr-x)
I0302 17:39:42.414496    9828 out.go:119]   - Options:      map[]
I0302 17:39:42.416604    9828 out.go:119]   - Bind Address: 192.168.39.29:38969
I0302 17:39:42.416824    9828 ssh_runner.go:149] Run: /bin/bash -c "[ "x$(findmnt -T /mount-9p | grep /mount-9p)" != "x" ] && sudo umount -f /mount-9p || echo "
I0302 17:39:42.416873    9828 main.go:121] libmachine: (functional-20210302173523-7287) Calling .GetSSHHostname
I0302 17:39:42.418806    9828 out.go:119] * Userspace file server: 
I0302 17:39:42.418949    9828 main.go:107] stdlog: ufs.go:27 listen tcp 192.168.39.29:38969: bind: cannot assign requested address
I0302 17:39:42.420937    9828 out.go:119] * Userspace file server is shutdown
I0302 17:39:42.424618    9828 main.go:121] libmachine: (functional-20210302173523-7287) Calling .GetSSHPort
I0302 17:39:42.424808    9828 main.go:121] libmachine: (functional-20210302173523-7287) Calling .GetSSHKeyPath
I0302 17:39:42.424982    9828 main.go:121] libmachine: (functional-20210302173523-7287) Calling .GetSSHUsername
I0302 17:39:42.425149    9828 sshutil.go:53] new ssh client: &{IP:192.168.39.29 Port:22 SSHKeyPath:/home/jenkins/minikube-integration/linux-amd64-kvm2--10656-2894-dd6687ecb2d95647810c3fe334f12e92c7227707/.minikube/machines/functional-20210302173523-7287/id_rsa Username:docker}
I0302 17:39:42.615584    9828 mount.go:147] unmount for /mount-9p ran successfully
I0302 17:39:42.615626    9828 ssh_runner.go:149] Run: /bin/bash -c "sudo mkdir -m 755 -p /mount-9p"
I0302 17:39:42.631783    9828 ssh_runner.go:149] Run: /bin/bash -c "sudo mount -t 9p -o dfltgid=$(grep ^docker: /etc/group | cut -d: -f3),dfltuid=$(id -u docker),msize=262144,port=38969,trans=tcp,version=9p2000.L 192.168.39.29 /mount-9p"
I0302 17:39:42.692337    9828 out.go:119] 
W0302 17:39:42.692588    9828 out.go:181] X Exiting due to GUEST_MOUNT: mount with cmd /bin/bash -c "sudo mount -t 9p -o dfltgid=$(grep ^docker: /etc/group | cut -d: -f3),dfltuid=$(id -u docker),msize=262144,port=38969,trans=tcp,version=9p2000.L 192.168.39.29 /mount-9p" : /bin/bash -c "sudo mount -t 9p -o dfltgid=$(grep ^docker: /etc/group | cut -d: -f3),dfltuid=$(id -u docker),msize=262144,port=38969,trans=tcp,version=9p2000.L 192.168.39.29 /mount-9p": Process exited with status 32
stdout:
stderr:
mount: /mount-9p: mount(2) system call failed: Connection refused.
X Exiting due to GUEST_MOUNT: mount with cmd /bin/bash -c "sudo mount -t 9p -o dfltgid=$(grep ^docker: /etc/group | cut -d: -f3),dfltuid=$(id -u docker),msize=262144,port=38969,trans=tcp,version=9p2000.L 192.168.39.29 /mount-9p" : /bin/bash -c "sudo mount -t 9p -o dfltgid=$(grep ^docker: /etc/group | cut -d: -f3),dfltuid=$(id -u docker),msize=262144,port=38969,trans=tcp,version=9p2000.L 192.168.39.29 /mount-9p": Process exited with status 32
stdout:
stderr:
mount: /mount-9p: mount(2) system call failed: Connection refused.
W0302 17:39:42.693024    9828 out.go:181] * 
* 
W0302 17:39:42.693070    9828 out.go:181] * If the above advice does not help, please let us know: 
* If the above advice does not help, please let us know: 
W0302 17:39:42.693118    9828 out.go:181]   - https://github.com/kubernetes/minikube/issues/new/choose
- https://github.com/kubernetes/minikube/issues/new/choose
I0302 17:39:42.697927    9828 out.go:119] 
--- FAIL: TestFunctional/parallel/MountCmd (18.66s)
@medyagh medyagh added this to the v.1.19.0 milestone Mar 2, 2021
@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. area/mount labels Mar 2, 2021
@medyagh
Copy link
Member Author

medyagh commented Mar 2, 2021

this flake started breaking 100% rate since Feb 19

@govargo
Copy link
Contributor

govargo commented Mar 3, 2021

I'm not familier with minikube mount but I'm interested in this flaky test.

Could I take this instead of ilya, if you don't mind?

@medyagh medyagh assigned govargo and unassigned ilya-zuyev Mar 3, 2021
@medyagh
Copy link
Member Author

medyagh commented Mar 6, 2021

@govargo is yours ! plz let me know if any questions

@govargo
Copy link
Contributor

govargo commented Mar 6, 2021 •
edited
Loading

I investigated the cause of this error.

I found out this error has happend since d48b0a5.

minikube/pkg/minikube/cluster/ip.go

Lines 49 to 54 in 09ee84d

case driver.KVM2:
ip, err := host.Driver.GetIP()
if err != nil {
return []byte{}, errors.Wrap(err, "Error getting VM/Host IP address")
}
return net.ParseIP(ip), nil 

$ sudo virsh net-dhcp-leases minikube-net
 Expiry Time          MAC address        Protocol  IP address                Hostname        Client ID or DUID
-------------------------------------------------------------------------------------------------------------------
 2021-03-06 11:49:48  28:ff:2f:41:67:9f  ipv4      192.168.39.181/24         minikube        01:28:ff:2f:41:67:9f

host.Driver.GetIP() returns the minikube vm's ip. In this case, host.Driver.GetIP() returns 192.168.39.181.
And minikube mount with KVM2 will try to use 192.168.39.181.

However, minikube mount must use host ip address of nic, not minikube vm's ip.
The ip address of nic is following.

$ ip a
9: virbr1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000
    link/ether 52:54:00:a6:7c:ba brd ff:ff:ff:ff:ff:ff
    inet 192.168.39.1/24 brd 192.168.39.255 scope global virbr1
       valid_lft forever preferred_lft forever
10: virbr1-nic: <BROADCAST,MULTICAST> mtu 1500 qdisc pfifo_fast master virbr1 state DOWN group default qlen 1000
    link/ether 52:54:00:a6:7c:ba brd ff:ff:ff:ff:ff:ff

@govargo
Copy link
Contributor

govargo commented Mar 6, 2021 •
edited
Loading

I think the users which uses KVM2 always fail to minikube mount.

I'll revert this portion of codes.

@govargo
Copy link
Contributor

govargo commented Mar 6, 2021

/kind bug

@k8s-ci-robot k8s-ci-robot added the kind/bug Categorizes issue or PR as related to a bug. label Mar 6, 2021
@govargo govargo mentioned this issue Mar 6, 2021
Merged
@afbjorklund afbjorklund added the co/kvm2-driver KVM2 driver related issues label Mar 7, 2021
@afbjorklund
Copy link
Collaborator

Should leave the fix for #10439, and not go back to hardcoding IP

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@govargo govargo

Labels
area/mount co/kvm2-driver KVM2 driver related issues kind/bug Categorizes issue or PR as related to a bug. 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.
Projects
None yet
Milestone
v.1.19.0
Development

Successfully merging a pull request may close this issue.

Fix the failure of minikube mount in case of KVM2
5 participants
@medyagh @afbjorklund @k8s-ci-robot @govargo @ilya-zuyev