TestMkdirAllHandle_RacingRename fails on single-cpu systems

[sanvila]

Hello. As reported here some time ago:

https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1102300

When I build the Debian package for this program on AWS instances having a single CPU, the test in the title always fails:

=== RUN   TestMkdirAllHandle_RacingRename/openat2=false/swapdir-empty-badmode-partial
panic: test timed out after 20m0s
	running tests:
		TestMkdirAllHandle_RacingRename (15m28s)
		TestMkdirAllHandle_RacingRename/openat2=false (3m14s)
		TestMkdirAllHandle_RacingRename/openat2=false/swapdir-empty-badmode-partial (31s)

goroutine 865 [running]:
testing.(*M).startAlarm.func1()
	/usr/lib/go-1.24/src/testing/testing.go:2484 +0x394
created by time.goFunc
	/usr/lib/go-1.24/src/time/sleep.go:215 +0x2d

goroutine 1 [chan receive, 15 minutes]:
testing.(*T).Run(0xc0000cc540, {0x696fb6?, 0xc0000d9b30?}, 0x6a67f8)
	/usr/lib/go-1.24/src/testing/testing.go:1859 +0x431
testing.runTests.func1(0xc0000cc540)
	/usr/lib/go-1.24/src/testing/testing.go:2279 +0x37
testing.tRunner(0xc0000cc540, 0xc0000d9c70)
	/usr/lib/go-1.24/src/testing/testing.go:1792 +0xf4
testing.runTests(0xc000010288, {0x85f5a0, 0x2c, 0x2c}, {0x8ac220?, 0x7?, 0x8ab0a0?})
	/usr/lib/go-1.24/src/testing/testing.go:2277 +0x4b4
testing.(*M).Run(0xc000094fa0)
	/usr/lib/go-1.24/src/testing/testing.go:2142 +0x64a
main.main()
	_testmain.go:131 +0x9b

goroutine 838 [chan receive, 3 minutes]:
testing.(*T).Run(0xc0003f4000, {0xc0001dc130?, 0xc000061f20?}, 0xc0003c80d8)
	/usr/lib/go-1.24/src/testing/testing.go:1859 +0x431
github.com/cyphar/filepath-securejoin.withWithoutOpenat2(0xc0003f4000, 0x93?, 0x6a6a30)
	/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/src/github.com/cyphar/filepath-securejoin/util_linux_test.go:35 +0x6d
github.com/cyphar/filepath-securejoin.TestMkdirAllHandle_RacingRename(0xc0003f4000?)
	/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/src/github.com/cyphar/filepath-securejoin/mkdir_linux_test.go:325 +0x1c
testing.tRunner(0xc0003f4000, 0x6a67f8)
	/usr/lib/go-1.24/src/testing/testing.go:1792 +0xf4
created by testing.(*T).Run in goroutine 1
	/usr/lib/go-1.24/src/testing/testing.go:1851 +0x413

goroutine 858 [chan receive]:
testing.(*T).Run(0xc0003f4540, {0xc000366040?, 0xc000063cb8?}, 0xc0000bc070)
	/usr/lib/go-1.24/src/testing/testing.go:1859 +0x431
github.com/cyphar/filepath-securejoin.TestMkdirAllHandle_RacingRename.func1(0xc0003f4540)
	/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/src/github.com/cyphar/filepath-securejoin/mkdir_linux_test.go:375 +0x4fc
github.com/cyphar/filepath-securejoin.withWithoutOpenat2.func1(0xc0003f4540)
	/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/src/github.com/cyphar/filepath-securejoin/util_linux_test.go:43 +0x111
testing.tRunner(0xc0003f4540, 0xc0003c80d8)
	/usr/lib/go-1.24/src/testing/testing.go:1792 +0xf4
created by testing.(*T).Run in goroutine 838
	/usr/lib/go-1.24/src/testing/testing.go:1851 +0x413

goroutine 863 [runnable]:
github.com/cyphar/filepath-securejoin.TestMkdirAllHandle_RacingRename.func1.1(0xc0003f4380)
	/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/src/github.com/cyphar/filepath-securejoin/mkdir_linux_test.go:406 +0x2dc
testing.tRunner(0xc0003f4380, 0xc0000bc070)
	/usr/lib/go-1.24/src/testing/testing.go:1792 +0xf4
created by testing.(*T).Run in goroutine 858
	/usr/lib/go-1.24/src/testing/testing.go:1851 +0x413

goroutine 864 [runnable]:
github.com/cyphar/filepath-securejoin.TestMkdirAllHandle_RacingRename.func1.1.1(0xc0003cc700)
	/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/src/github.com/cyphar/filepath-securejoin/mkdir_linux_test.go:382 +0x58
created by github.com/cyphar/filepath-securejoin.TestMkdirAllHandle_RacingRename.func1.1 in goroutine 863
	/<<PKGBUILDDIR>>/obj-x86_64-linux-gnu/src/github.com/cyphar/filepath-securejoin/mkdir_linux_test.go:378 +0x16d
FAIL	github.com/cyphar/filepath-securejoin	1200.017s
FAIL

This used to work ok at version 0.2.3, and it was already failing at version 0.3.4. The current version in Debian unstable, 0.5.2, still fails.

Is this a bug in the test or a bug in the code?

To reproduce (if you don't have a single-CPU VM at hand) you can try configuring GRUB with GRUB_CMDLINE_LINUX="nr_cpus=1" and then rebooting.

Thanks.

[cyphar]

The race tests have to do a lot of filesystem operations (and internally does thousands of retries to exercise a race condition), so if it's failing from a timeout then we are probably doing too many run attempts on single-cpu systems.

I'm not sure what the best way of detecting this in the test code would be, but I would just want to mention that go test -short reduces the number of attempts tried for these tests. Does that cause it to stop failing for you? If so, I would suggest just doing that in the package test scripts?

[sanvila]

Thanks for the hint. I see by looking at the code that the test would indeed be skipped when using -short, but I would prefer to do that only as a last resort.

When a test does not work, I have two options: I can open an issue here so that the authors are aware of it, or I can silently disable the test in the Debian package without telling anybody. The first option is the one I chose here because it's the one which will potentially help more people, but of course only if the bug is diagnosed and fixed.

[ In case the GRUB_CMDLINE_LINUX="nr_cpus=1" trick would not work for you, I could eventually offer a VM to reproduce this where the reported bug happens quite often ].

Thanks.

[cyphar]

Ah okay, I thought I made it reduce the number of runs not skip them entirely. Maybe they should be time-based instead of based on the number of iterations...? Let me think about it.