Flaky test TestConcurrentVMCreation

[bboreham]

Seen here for instance:

=== RUN   TestConcurrentVMCreation04:27
time="2021-01-13T18:32:10Z" level=info msg="Removed VM with name \"e2e-test-concurrent-vm-create-3\" and ID \"1dc7af60947f98b9\""04:27
time="2021-01-13T18:32:10Z" level=fatal msg="unable to lock \"/tmp/ignite-snapshot.lock\": open /tmp/ignite-snapshot.lock: no such file or directory"04:27
time="2021-01-13T18:32:10Z" level=info msg="Created VM with ID \"72e7877db58da54a\" and name \"e2e-test-concurrent-vm-create-4\""04:27
time="2021-01-13T18:32:10Z" level=info msg="Created VM with ID \"3c329b59d8f1a9ea\" and name \"e2e-test-concurrent-vm-create-1\""04:28
time="2021-01-13T18:32:11Z" level=info msg="Removed VM with name \"e2e-test-concurrent-vm-create-2\" and ID \"e458bf7d3337729a\""04:28
time="2021-01-13T18:32:11Z" level=fatal msg="unable to lock \"/tmp/ignite-snapshot.lock\": open /tmp/ignite-snapshot.lock: no such file or directory"04:28
time="2021-01-13T18:32:11Z" level=info msg="Networking is handled by \"cni\""04:28
time="2021-01-13T18:32:11Z" level=info msg="Started Firecracker VM \"72e7877db58da54a\" in a container with ID \"ignite-72e7877db58da54a\""04:28
time="2021-01-13T18:32:11Z" level=info msg="Networking is handled by \"cni\""04:28
time="2021-01-13T18:32:11Z" level=info msg="Started Firecracker VM \"3c329b59d8f1a9ea\" in a container with ID \"ignite-3c329b59d8f1a9ea\""04:28
time="2021-01-13T18:32:11Z" level=info msg="Waiting for the ssh daemon within the VM to start..."04:28
time="2021-01-13T18:32:11Z" level=info msg="Waiting for the ssh daemon within the VM to start..."04:35
    TestConcurrentVMCreation: zconcurrent_vm_test.go:48: assertion failed: error is not nil: exit status 1: error waiting for the command to finish04:35
    TestConcurrentVMCreation: zconcurrent_vm_test.go:48: assertion failed: error is not nil: exit status 1: error waiting for the command to finish04:35
    TestConcurrentVMCreation: zconcurrent_vm_test.go:50: assertion failed: error is not nil: exit status 1: cmd: 04:35
        "/home/semaphore/ignite/bin/ignite rm -f e2e-test-concurrent-vm-create-1 e2e-test-concurrent-vm-create-2 e2e-test-concurrent-vm-create-3 e2e-test-concurrent-vm-create-4"04:35
        time="2021-01-13T18:32:18Z" level=fatal msg="can't find VM: no ID/name matches for \"e2e-test-concurrent-vm-create-2\""04:35
        04:35
    TestConcurrentVMCreation: zconcurrent_vm_test.go:50: failed to run "/home/semaphore/ignite/bin/ignite rm -f e2e-test-concurrent-vm-create-1 e2e-test-concurrent-vm-create-2 e2e-test-concurrent-vm-create-3 e2e-test-concurrent-vm-create-4": exit status 104:35
--- FAIL: TestConcurrentVMCreation (8.91s)

Another failure here but that was when we had less logging info.

May be fixed by nightlyone/lockfile#34

[darkowlzz]

A few months ago, we saw this failure related to the lockfile only once and were never able to reproduce it. We also tried tracing the code in the lockfile project but couldn't determine exactly what was causing it.
We can use your fix of the lockfile and see if we encounter this issue again. With the docker container stop and this issue resolved, I guess all of our test flakes will be fixed. It'd be easier to see if we encounter failure due to lockfile issue again.

[stealthybox]

Thanks for this. I do remember seeing this issue and having trouble reproducing.
Hopefully the lockfile pkg maintainer responds to your issue.

If we can't get that change worked through, we can start using the fork here to see if it changes the behavior in CI.

I don't recall if our existing lock logic is defensive enough that it would retry if the first lock failed.

[vistaarjuneja]

hey! We have been using ignite in a setup that runs multiple concurrent VMs on a machine and we ran into the same issue. Validated that @bboreham's change fixes it!
Would be awesome if we can get a fix merged for this, happy to open up a PR. We just need a replace directive to a patched version of lockfile in go.mod.