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

Connections test hangs on OpenBSD #8421

Open
vext01 opened this issue Jul 7, 2022 · 9 comments
Open

Connections test hangs on OpenBSD #8421

vext01 opened this issue Jul 7, 2022 · 9 comments
Labels
build Issues caused by or requiring changes to the build system (scripts or Docker image)

Comments

@vext01
Copy link

vext01 commented Jul 7, 2022

Hi,

Updating our OpenBSD package to the latest stable version (1.20.2). One test hangs.

2022/07/07 06:17:14 INFO: TCP listener (127.0.0.1:19275) starting
panic: test timed out after 2m0s

goroutine 35 [running]:
testing.(*M).startAlarm.func1()
	/usr/local/go/src/testing/testing.go:2029 +0x8e
created by time.goFunc
	/usr/local/go/src/time/sleep.go:176 +0x32

goroutine 1 [chan receive]:
testing.(*T).Run(0xc0000a1d40, {0xc31a29?, 0xc000107bb0?}, 0xc6e368)
	/usr/local/go/src/testing/testing.go:1487 +0x37a
testing.runTests.func1(0xc0000a1d40?)
	/usr/local/go/src/testing/testing.go:1839 +0x6e
testing.tRunner(0xc0000a1d40, 0xc000107cd8)
	/usr/local/go/src/testing/testing.go:1439 +0x102
testing.runTests(0xc0000ab0e0?, {0x11f7500, 0xf, 0xf}, {0x29c20f108?, 0x40?, 0x1203880?})
	/usr/local/go/src/testing/testing.go:1837 +0x457
testing.(*M).Run(0xc0000ab0e0)
	/usr/local/go/src/testing/testing.go:1719 +0x5d9
main.main()
	_testmain.go:77 +0x1aa

goroutine 6 [syscall]:
syscall.syscall6(0x47cc80, 0x3, 0x0, 0x0, 0xc00005a718, 0x1, 0x0)
	/usr/local/go/src/runtime/sys_openbsd3.go:46 +0x3b
syscall.kevent(0x0?, 0x0?, 0x0?, 0x0?, 0x0?, 0x0?)
	/usr/local/go/src/syscall/zsyscall_openbsd_amd64.go:271 +0x52
syscall.Kevent(0x0?, {0x0?, 0x0?, 0x0?}, {0xc00005a718?, 0x0?, 0x0?}, 0x0?)
	/usr/local/go/src/syscall/syscall_bsd.go:432 +0x3c
github.com/syncthing/syncthing/vendor/github.com/syncthing/notify.(*kq).Wait(0x0?)
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/vendor/github.com/syncthing/notify/watcher_kqueue.go:139 +0x4c
github.com/syncthing/syncthing/vendor/github.com/syncthing/notify.(*trg).monitor(0xc000094ea0)
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/vendor/github.com/syncthing/notify/watcher_trigger.go:404 +0x3b
created by github.com/syncthing/syncthing/vendor/github.com/syncthing/notify.newWatcher
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/vendor/github.com/syncthing/notify/watcher_trigger.go:112 +0x205

goroutine 7 [chan receive]:
github.com/syncthing/syncthing/vendor/github.com/syncthing/notify.(*nonrecursiveTree).dispatch(0xc0000822a0, 0x0?)
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/vendor/github.com/syncthing/notify/tree_nonrecursive.go:36 +0x45
created by github.com/syncthing/syncthing/vendor/github.com/syncthing/notify.newNonrecursiveTree
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/vendor/github.com/syncthing/notify/tree_nonrecursive.go:29 +0x16a

goroutine 8 [chan receive]:
github.com/syncthing/syncthing/vendor/github.com/syncthing/notify.(*nonrecursiveTree).internal(0xc0000822a0, 0xc000082240)
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/vendor/github.com/syncthing/notify/tree_nonrecursive.go:81 +0x53
created by github.com/syncthing/syncthing/vendor/github.com/syncthing/notify.newNonrecursiveTree
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/vendor/github.com/syncthing/notify/tree_nonrecursive.go:30 +0x1be

goroutine 15 [chan receive]:
testing.(*T).Run(0xc00012b380, {0xc29705?, 0xc21245?}, 0xc00011d440)
	/usr/local/go/src/testing/testing.go:1487 +0x37a
github.com/syncthing/syncthing/lib/connections.TestConnectionEstablishment(0xc00012b380)
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/lib/connections/connections_test.go:387 +0x1ea
testing.tRunner(0xc00012b380, 0xc6e368)
	/usr/local/go/src/testing/testing.go:1439 +0x102
created by testing.(*T).Run
	/usr/local/go/src/testing/testing.go:1486 +0x35f

goroutine 16 [IO wait]:
internal/poll.runtime_pollWait(0x2c535aeb0, 0x77)
	/usr/local/go/src/runtime/netpoll.go:302 +0x89
internal/poll.(*pollDesc).wait(0xc000214180?, 0xc000327d5c?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:83 +0x32
internal/poll.(*pollDesc).waitWrite(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Write(0xc000214180, {0xc000326000, 0x4016, 0x5500})
	/usr/local/go/src/internal/poll/fd_unix.go:391 +0x2c5
net.(*netFD).Write(0xc000214180, {0xc000326000?, 0x4006?, 0xc00023e228?})
	/usr/local/go/src/net/fd_posix.go:96 +0x29
net.(*conn).Write(0xc00020c040, {0xc000326000?, 0x473ace?, 0xc000236560?})
	/usr/local/go/src/net/net.go:195 +0x45
crypto/tls.(*Conn).write(0xc00023e000, {0xc000326000?, 0x5?, 0x4000?})
	/usr/local/go/src/crypto/tls/conn.go:920 +0x108
crypto/tls.(*Conn).writeRecordLocked(0xc00023e000, 0x17, {0xc000180000, 0x20000, 0x20000})
	/usr/local/go/src/crypto/tls/conn.go:988 +0x351
crypto/tls.(*Conn).Write(0x0?, {0xc000180000, 0x20000, 0x20000})
	/usr/local/go/src/crypto/tls/conn.go:1159 +0x3f4
github.com/syncthing/syncthing/lib/connections.TestConnectionEstablishment.func1.1({{0xd3b450, 0xc00023e000}, 0x2, 0xa, {0x0, 0xeda58635a, 0x1203880}}, {{0xd3b450, 0xc0000f8e00}, 0x3, ...})
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/lib/connections/connections_test.go:389 +0x93
github.com/syncthing/syncthing/lib/connections.withConnectionPair({0xd339c0, 0xc00012b520}, {0xc29705, 0x11}, 0xc000145f38)
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/lib/connections/connections_test.go:493 +0xcd7
github.com/syncthing/syncthing/lib/connections.TestConnectionEstablishment.func1(0xc00012b380?)
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/lib/connections/connections_test.go:388 +0x71
testing.tRunner(0xc00012b520, 0xc00011d440)
	/usr/local/go/src/testing/testing.go:1439 +0x102
created by testing.(*T).Run
	/usr/local/go/src/testing/testing.go:1486 +0x35f

goroutine 18 [select]:
github.com/syncthing/syncthing/vendor/github.com/thejerf/suture/v4.(*Supervisor).Serve(0xc0000acdc0, {0xd39420?, 0xc000080e00?})
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/vendor/github.com/thejerf/suture/v4/supervisor.go:354 +0x46e
github.com/syncthing/syncthing/vendor/github.com/thejerf/suture/v4.(*Supervisor).ServeBackground.func1()
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/vendor/github.com/thejerf/suture/v4/supervisor.go:297 +0x2e
created by github.com/syncthing/syncthing/vendor/github.com/thejerf/suture/v4.(*Supervisor).ServeBackground
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/vendor/github.com/thejerf/suture/v4/supervisor.go:296 +0xc5

goroutine 19 [IO wait]:
internal/poll.runtime_pollWait(0x2c535afa0, 0x72)
	/usr/local/go/src/runtime/netpoll.go:302 +0x89
internal/poll.(*pollDesc).wait(0xc000214000?, 0xc00004cf00?, 0x0)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:83 +0x32
internal/poll.(*pollDesc).waitRead(...)
	/usr/local/go/src/internal/poll/fd_poll_runtime.go:88
internal/poll.(*FD).Accept(0xc000214000)
	/usr/local/go/src/internal/poll/fd_unix.go:614 +0x22c
net.(*netFD).accept(0xc000214000)
	/usr/local/go/src/net/fd_unix.go:172 +0x35
net.(*TCPListener).accept(0xc000218000)
	/usr/local/go/src/net/tcpsock_posix.go:139 +0x28
net.(*TCPListener).Accept(0xc000218000)
	/usr/local/go/src/net/tcpsock.go:288 +0x3d
github.com/syncthing/syncthing/lib/connections.(*tcpListener).serve(0xc0000ab360, {0xd39420, 0xc000080f00})
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/lib/connections/tcp_listen.go:105 +0x8b3
github.com/syncthing/syncthing/lib/svcutil.(*service).Serve(0xc000080ec0, {0xd39420, 0xc000080f00})
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/lib/svcutil/svcutil.go:125 +0x92
github.com/syncthing/syncthing/vendor/github.com/thejerf/suture/v4.(*Supervisor).runService.func2()
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/vendor/github.com/thejerf/suture/v4/supervisor.go:565 +0xec
created by github.com/syncthing/syncthing/vendor/github.com/thejerf/suture/v4.(*Supervisor).runService
	/usr/local/pobj/syncthing-1.20.2/go/src/github.com/syncthing/syncthing/vendor/github.com/thejerf/suture/v4/supervisor.go:539 +0x1d5
FAIL	github.com/syncthing/syncthing/lib/connections	120.075s

I assume it's the kevent goroutine causing this. We've had issues with the notify library on OpenBSD before, haven't we?

Any ideas?
@vext01 vext01 added bug A problem with current functionality, as opposed to missing functionality (enhancement) needs-triage New issues needed to be validated labels Jul 7, 2022
@calmh
Copy link
Member

calmh commented Jul 7, 2022

That test tries to establish a connection to itself with the various methods we support, I don't think inotify is involved. Maybe run with -v and try to figure out what it says and what part of the test hangs.

@vext01
Copy link
Author

vext01 commented Jul 7, 2022

Am i running the test right?

$ go test -v github.com/syncthing/syncthing/lib/connections
=== RUN   TestFixupPort
--- PASS: TestFixupPort (0.00s)
=== RUN   TestAllowedNetworks
--- PASS: TestAllowedNetworks (0.00s)
=== RUN   TestGetDialer
--- PASS: TestGetDialer (0.00s)
=== RUN   TestConnectionStatus
--- PASS: TestConnectionStatus (0.00s)
=== RUN   TestNextDialRegistryCleanup
--- PASS: TestNextDialRegistryCleanup (0.00s)
=== RUN   TestConnectionEstablishment
=== RUN   TestConnectionEstablishment/tcp
2022/07/07 11:20:56 INFO: TCP listener (127.0.0.1:13873) starting

Hangs forever...

This is on git main now.

@calmh
Copy link
Member

calmh commented Jul 7, 2022

Yep, looks right. To the extent that it shows where it hangs.

@AudriusButkevicius
Copy link
Member

Firewalls?

@vext01
Copy link
Author

vext01 commented Jul 7, 2022

Firewall is disabled.

@AudriusButkevicius
Copy link
Member

Not sure we can help a lot here, as it seems platform specific.
Seems both sides of the connection are hanging on a syscall.

@calmh
Copy link
Member

calmh commented Jul 7, 2022

I think connections in general work on OpenBSD so I would guess there's an incorrect assumption in the test somewhere, or the test environment is somehow hostile. But yeah, it needs debugging on OpenBSD.

@vext01
Copy link
Author

vext01 commented Jul 8, 2022

I would guess there's an incorrect assumption in the test

I tend to agree.

I'm not likely to find time to look deeper into this right now. I don't think this will block updating our package, and I will link to this issue in our Makefile.

Thanks

@calmh calmh added build Issues caused by or requiring changes to the build system (scripts or Docker image) and removed bug A problem with current functionality, as opposed to missing functionality (enhancement) needs-triage New issues needed to be validated labels Mar 10, 2023
@diizzyy
Copy link

diizzyy commented Jun 18, 2023 •
edited

I'm seeing this on FreeBSD 13.2-RELEASE aswell or something very similar using latest release (1.23.5).
Using Go 1.19.8 it works but fails using Go 1.20.3.

As with other distros I needed to patch out the -race switch otherwise I'd get fatal error: checkptr: converted pointer straddles multiple allocations

References:
https://git.alpinelinux.org/aports/tree/community/syncthing/only-test-with-race-when-provided.patch
https://gitlab.archlinux.org/archlinux/packaging/packages/syncthing/-/blob/main/gcc-pie-segfaults-race.patch

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
build Issues caused by or requiring changes to the build system (scripts or Docker image)
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@calmh @vext01 @AudriusButkevicius @diizzyy