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.

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

Flaking TestMemberAdd e2e test on arm64 and amd64 #17778

Open
jmhbnz opened this issue Apr 11, 2024 · 2 comments
Open

Flaking TestMemberAdd e2e test on arm64 and amd64 #17778

jmhbnz opened this issue Apr 11, 2024 · 2 comments

Comments

@jmhbnz
Copy link
Member

jmhbnz commented Apr 11, 2024

Which Github Action / Prow Jobs are flaking?

https://github.com/etcd-io/etcd/actions/runs/8651891234/job/23723600400
TestMemberAdd/Learner/StrictReconfigCheck/WaitForQuorum/PeerTLS

https://github.com/etcd-io/etcd/actions/runs/8636559314/job/23676748079
TestMemberAdd/Learner/StrictReconfigCheck/WaitForQuorum/QuorumLastVersion

Reason for failure (if possible)

2024-04-11T19:36:24.4284254Z --- FAIL: TestMemberAdd (316.52s)
2024-04-11T19:36:24.4285202Z     before.go:36: Changing working directory to: /tmp/TestMemberAdd3833117478/001
2024-04-11T19:36:24.4286828Z     --- FAIL: TestMemberAdd/Learner/StrictReconfigCheck/WaitForQuorum/PeerTLS (12.17s)
2024-04-11T19:36:24.4289242Z         logger.go:146: 2024-04-11T19:28:05.468Z	INFO	starting server...	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-2"}
2024-04-11T19:36:24.4291929Z         logger.go:146: 2024-04-11T19:28:05.468Z	INFO	starting server...	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-1"}
2024-04-11T19:36:24.4311285Z         logger.go:146: 2024-04-11T19:28:05.468Z	INFO	spawning process	{"args": ["/home/runner/actions-runner/_work/etcd/etcd/bin/etcd", "--name=TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-1", "--listen-client-urls=http://localhost:20005", "--advertise-client-urls=http://localhost:20005", "--listen-peer-urls=https://localhost:20006", "--initial-advertise-peer-urls=https://localhost:20006", "--initial-cluster-token=new", "--data-dir", "/tmp/TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS3981728050/002", "--snapshot-count=10000", "--peer-cert-file", "/home/runner/actions-runner/_work/etcd/etcd/tests/fixtures/server.crt", "--peer-key-file", "/home/runner/actions-runner/_work/etcd/etcd/tests/fixtures/server.key.insecure", "--peer-trusted-ca-file", "/home/runner/actions-runner/_work/etcd/etcd/tests/fixtures/ca.crt", "--initial-cluster-token=new", "--initial-cluster=TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-0=https://localhost:20001,TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-1=https://localhost:20006,TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-2=https://localhost:20011", "--initial-cluster-state=new"], "working-dir": "/tmp/TestMemberAdd3833117478/001", "name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-1", "environment-variables": ["ETCD_VERIFY=all", "EXPECT_DEBUG=true", "PATH=/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/bin:/home/runner/go/bin:/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/bin:/home/runner/.dotnet/tools:/home/runner/.cargo/bin:/home/runner/go/bin:/home/runner/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin", "ETCD_UNSUPPORTED_ARCH=arm64"]}
2024-04-11T19:36:24.4329742Z         logger.go:146: 2024-04-11T19:28:05.468Z	INFO	starting server...	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-0"}
2024-04-11T19:36:24.4349421Z         logger.go:146: 2024-04-11T19:28:05.468Z	INFO	spawning process	{"args": ["/home/runner/actions-runner/_work/etcd/etcd/bin/etcd", "--name=TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-2", "--listen-client-urls=http://localhost:20010", "--advertise-client-urls=http://localhost:20010", "--listen-peer-urls=https://localhost:20011", "--initial-advertise-peer-urls=https://localhost:20011", "--initial-cluster-token=new", "--data-dir", "/tmp/TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS3981728050/003", "--snapshot-count=10000", "--peer-cert-file", "/home/runner/actions-runner/_work/etcd/etcd/tests/fixtures/server.crt", "--peer-key-file", "/home/runner/actions-runner/_work/etcd/etcd/tests/fixtures/server.key.insecure", "--peer-trusted-ca-file", "/home/runner/actions-runner/_work/etcd/etcd/tests/fixtures/ca.crt", "--initial-cluster-token=new", "--initial-cluster=TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-0=https://localhost:20001,TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-1=https://localhost:20006,TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-2=https://localhost:20011", "--initial-cluster-state=new"], "working-dir": "/tmp/TestMemberAdd3833117478/001", "name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-2", "environment-variables": ["ETCD_VERIFY=all", "EXPECT_DEBUG=true", "PATH=/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/bin:/home/runner/go/bin:/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/bin:/home/runner/.dotnet/tools:/home/runner/.cargo/bin:/home/runner/go/bin:/home/runner/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin", "ETCD_UNSUPPORTED_ARCH=arm64"]}
2024-04-11T19:36:24.4381103Z         logger.go:146: 2024-04-11T19:28:05.468Z	INFO	spawning process	{"args": ["/home/runner/actions-runner/_work/etcd/etcd/bin/etcd", "--name=TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-0", "--listen-client-urls=http://localhost:20000", "--advertise-client-urls=http://localhost:20000", "--listen-peer-urls=https://localhost:20001", "--initial-advertise-peer-urls=https://localhost:20001", "--initial-cluster-token=new", "--data-dir", "/tmp/TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS3981728050/001", "--snapshot-count=10000", "--peer-cert-file", "/home/runner/actions-runner/_work/etcd/etcd/tests/fixtures/server.crt", "--peer-key-file", "/home/runner/actions-runner/_work/etcd/etcd/tests/fixtures/server.key.insecure", "--peer-trusted-ca-file", "/home/runner/actions-runner/_work/etcd/etcd/tests/fixtures/ca.crt", "--initial-cluster-token=new", "--initial-cluster=TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-0=https://localhost:20001,TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-1=https://localhost:20006,TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-2=https://localhost:20011", "--initial-cluster-state=new"], "working-dir": "/tmp/TestMemberAdd3833117478/001", "name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-0", "environment-variables": ["ETCD_VERIFY=all", "EXPECT_DEBUG=true", "PATH=/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/bin:/home/runner/go/bin:/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/bin:/home/runner/.dotnet/tools:/home/runner/.cargo/bin:/home/runner/go/bin:/home/runner/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin", "ETCD_UNSUPPORTED_ARCH=arm64"]}
2024-04-11T19:36:24.4395954Z         logger.go:146: 2024-04-11T19:28:12.203Z	INFO	started server.	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-2", "pid": 81155}
2024-04-11T19:36:24.4398802Z         logger.go:146: 2024-04-11T19:28:12.203Z	INFO	started server.	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-1", "pid": 81153}
2024-04-11T19:36:24.4401651Z         logger.go:146: 2024-04-11T19:28:12.203Z	INFO	started server.	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-0", "pid": 81154}
2024-04-11T19:36:24.4404025Z         testutil.go:56: ---> Test failed: test timed out after 3.26223988s, err: context deadline exceeded
2024-04-11T19:36:24.4405184Z         testutil.go:57: goroutine 4742 [running]:
2024-04-11T19:36:24.4406714Z             go.etcd.io/etcd/client/pkg/v3/testutil.FatalStack(0x40000c01a0, {0x4000042340, 0x40})
2024-04-11T19:36:24.4408854Z             	/home/runner/actions-runner/_work/etcd/etcd/client/pkg/testutil/testutil.go:55 +0x4c
2024-04-11T19:36:24.4410776Z             go.etcd.io/etcd/tests/v3/framework/testutils.ExecuteUntil({0xbd5ea0, 0x4000160150}, 0x40000c01a0, 0x4000368000)
2024-04-11T19:36:24.4412861Z             	/home/runner/actions-runner/_work/etcd/etcd/tests/framework/testutils/execute.go:47 +0x180
2024-04-11T19:36:24.4414323Z             go.etcd.io/etcd/tests/v3/common.TestMemberAdd.func1(0x40000c01a0)
2024-04-11T19:36:24.4415946Z             	/home/runner/actions-runner/_work/etcd/etcd/tests/common/member_test.go:126 +0x2d8
2024-04-11T19:36:24.4417083Z             testing.tRunner(0x40000c01a0, 0x40001cafc0)
2024-04-11T19:36:24.4418788Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/testing/testing.go:1689 +0xec
2024-04-11T19:36:24.4419992Z             created by testing.(*T).Run in goroutine 4459
2024-04-11T19:36:24.4421545Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/testing/testing.go:1742 +0x318
2024-04-11T19:36:24.4422479Z             
2024-04-11T19:36:24.4426365Z             goroutine 1 [chan receive, 3 minutes]:
2024-04-11T19:36:24.4427552Z             testing.(*T).Run(0x400065a340, {0xa6f912?, 0x4000507ac8?}, 0xaddd38)
2024-04-11T19:36:24.4429268Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/testing/testing.go:1750 +0x32c
2024-04-11T19:36:24.4430407Z             testing.runTests.func1(0x400065a340)
2024-04-11T19:36:24.4431940Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/testing/testing.go:2161 +0x40
2024-04-11T19:36:24.4433116Z             testing.tRunner(0x400065a340, 0x4000507be8)
2024-04-11T19:36:24.4434634Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/testing/testing.go:1689 +0xec
2024-04-11T19:36:24.4436265Z             testing.runTests(0x400012fa28, {0x12d9800, 0x54, 0x54}, {0x9149e0?, 0x40001279b0?, 0x12e4740?})
2024-04-11T19:36:24.4438084Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/testing/testing.go:2159 +0x3b0
2024-04-11T19:36:24.4439167Z             testing.(*M).Run(0x4000369360)
2024-04-11T19:36:24.4440652Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/testing/testing.go:2027 +0x5a4
2024-04-11T19:36:24.4442170Z             go.etcd.io/etcd/tests/v3/framework/e2e.e2eRunner.TestMain({}, 0x4000369360)
2024-04-11T19:36:24.4443833Z             	/home/runner/actions-runner/_work/etcd/etcd/tests/framework/e2e/e2e.go:35 +0x28
2024-04-11T19:36:24.4445296Z             go.etcd.io/etcd/tests/v3/common.TestMain(...)
2024-04-11T19:36:24.4446840Z             	/home/runner/actions-runner/_work/etcd/etcd/tests/common/main_test.go:30
2024-04-11T19:36:24.4447737Z             main.main()
2024-04-11T19:36:24.4448668Z             	_testmain.go:215 +0x190
2024-04-11T19:36:24.4449222Z             
2024-04-11T19:36:24.4449746Z             goroutine 4782 [syscall]:
2024-04-11T19:36:24.4450576Z             syscall.Syscall(0x3f, 0x9, 0x4000456000, 0x1000)
2024-04-11T19:36:24.4452200Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/syscall/syscall_linux.go:69 +0x20
2024-04-11T19:36:24.4453620Z             syscall.read(0x4000475380?, {0x4000456000?, 0x400008db01?, 0x860e0?})
2024-04-11T19:36:24.4455440Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/syscall/zsyscall_linux_arm64.go:736 +0x40
2024-04-11T19:36:24.4459003Z             syscall.Read(...)
2024-04-11T19:36:24.4460525Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/syscall/syscall_unix.go:181
2024-04-11T19:36:24.4461889Z             internal/poll.ignoringEINTRIO(...)
2024-04-11T19:36:24.4463408Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/internal/poll/fd_unix.go:736
2024-04-11T19:36:24.4464806Z             internal/poll.(*FD).Read(0x4000475380, {0x4000456000, 0x1000, 0x1000})
2024-04-11T19:36:24.4466555Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/internal/poll/fd_unix.go:160 +0x224
2024-04-11T19:36:24.4467766Z             os.(*File).read(...)
2024-04-11T19:36:24.4469074Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/file_posix.go:29
2024-04-11T19:36:24.4470422Z             os.(*File).Read(0x400041e1f0, {0x4000456000?, 0x134f0e0?, 0x4000028aa0?})
2024-04-11T19:36:24.4471992Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/file.go:118 +0x70
2024-04-11T19:36:24.4473038Z             bufio.(*Reader).fill(0x400008df18)
2024-04-11T19:36:24.4474464Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/bufio/bufio.go:110 +0xf8
2024-04-11T19:36:24.4475613Z             bufio.(*Reader).ReadSlice(0x400008df18, 0xa)
2024-04-11T19:36:24.4477251Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/bufio/bufio.go:376 +0x30
2024-04-11T19:36:24.4478458Z             bufio.(*Reader).collectFragments(0x400008df18, 0xa)
2024-04-11T19:36:24.4479969Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/bufio/bufio.go:451 +0x64
2024-04-11T19:36:24.4481107Z             bufio.(*Reader).ReadString(0xa6f282?, 0xc?)
2024-04-11T19:36:24.4482574Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/bufio/bufio.go:498 +0x20
2024-04-11T19:36:24.4484194Z             go.etcd.io/etcd/pkg/v3/expect.(*ExpectProcess).tryReadNextLine(0x4000292c00, 0x400008df18)
2024-04-11T19:36:24.4485881Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:135 +0x54
2024-04-11T19:36:24.4487507Z             go.etcd.io/etcd/pkg/v3/expect.(*ExpectProcess).read(0x4000292c00)
2024-04-11T19:36:24.4489256Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:126 +0x144
2024-04-11T19:36:24.4490710Z             created by go.etcd.io/etcd/pkg/v3/expect.NewExpectWithEnv in goroutine 4743
2024-04-11T19:36:24.4494830Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:87 +0x1f8
2024-04-11T19:36:24.4495693Z             
2024-04-11T19:36:24.4496231Z             goroutine 4746 [syscall]:
2024-04-11T19:36:24.4497061Z             syscall.Syscall(0x3f, 0x8, 0x4000506000, 0x1000)
2024-04-11T19:36:24.4498662Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/syscall/syscall_linux.go:69 +0x20
2024-04-11T19:36:24.4500092Z             syscall.read(0x4000250e40?, {0x4000506000?, 0x40004ccb01?, 0x860e0?})
2024-04-11T19:36:24.4501914Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/syscall/zsyscall_linux_arm64.go:736 +0x40
2024-04-11T19:36:24.4503282Z             syscall.Read(...)
2024-04-11T19:36:24.4504364Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/syscall/syscall_unix.go:181
2024-04-11T19:36:24.4504762Z             internal/poll.ignoringEINTRIO(...)
2024-04-11T19:36:24.4505842Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/internal/poll/fd_unix.go:736
2024-04-11T19:36:24.4506498Z             internal/poll.(*FD).Read(0x4000250e40, {0x4000506000, 0x1000, 0x1000})
2024-04-11T19:36:24.4507673Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/internal/poll/fd_unix.go:160 +0x224
2024-04-11T19:36:24.4507955Z             os.(*File).read(...)
2024-04-11T19:36:24.4508927Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/file_posix.go:29
2024-04-11T19:36:24.4509548Z             os.(*File).Read(0x400039c1e0, {0x4000506000?, 0x0?, 0x40001445a0?})
2024-04-11T19:36:24.4510532Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/file.go:118 +0x70
2024-04-11T19:36:24.4511061Z             bufio.(*Reader).fill(0x40004ccf18)
2024-04-11T19:36:24.4512090Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/bufio/bufio.go:110 +0xf8
2024-04-11T19:36:24.4512540Z             bufio.(*Reader).ReadSlice(0x40004ccf18, 0xa)
2024-04-11T19:36:24.4513564Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/bufio/bufio.go:376 +0x30
2024-04-11T19:36:24.4514228Z             bufio.(*Reader).collectFragments(0x40004ccf18, 0xa)
2024-04-11T19:36:24.4515270Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/bufio/bufio.go:451 +0x64
2024-04-11T19:36:24.4515705Z             bufio.(*Reader).ReadString(0xa6f282?, 0xc?)
2024-04-11T19:36:24.4516738Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/bufio/bufio.go:498 +0x20
2024-04-11T19:36:24.4517656Z             go.etcd.io/etcd/pkg/v3/expect.(*ExpectProcess).tryReadNextLine(0x40002366c0, 0x40004ccf18)
2024-04-11T19:36:24.4518583Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:135 +0x54
2024-04-11T19:36:24.4519248Z             go.etcd.io/etcd/pkg/v3/expect.(*ExpectProcess).read(0x40002366c0)
2024-04-11T19:36:24.4520302Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:126 +0x144
2024-04-11T19:36:24.4521090Z             created by go.etcd.io/etcd/pkg/v3/expect.NewExpectWithEnv in goroutine 4745
2024-04-11T19:36:24.4521998Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:87 +0x1f8
2024-04-11T19:36:24.4522186Z             
2024-04-11T19:36:24.4522496Z             goroutine 4729 [syscall]:
2024-04-11T19:36:24.4522966Z             syscall.Syscall(0x3f, 0x7, 0x40004f8000, 0x1000)
2024-04-11T19:36:24.4524100Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/syscall/syscall_linux.go:69 +0x20
2024-04-11T19:36:24.4524758Z             syscall.read(0x40000e0060?, {0x40004f8000?, 0x40004ceb01?, 0x860e0?})
2024-04-11T19:36:24.4526003Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/syscall/zsyscall_linux_arm64.go:736 +0x40
2024-04-11T19:36:24.4528951Z             syscall.Read(...)
2024-04-11T19:36:24.4530160Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/syscall/syscall_unix.go:181
2024-04-11T19:36:24.4530556Z             internal/poll.ignoringEINTRIO(...)
2024-04-11T19:36:24.4531628Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/internal/poll/fd_unix.go:736
2024-04-11T19:36:24.4532292Z             internal/poll.(*FD).Read(0x40000e0060, {0x40004f8000, 0x1000, 0x1000})
2024-04-11T19:36:24.4533460Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/internal/poll/fd_unix.go:160 +0x224
2024-04-11T19:36:24.4533741Z             os.(*File).read(...)
2024-04-11T19:36:24.4534702Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/file_posix.go:29
2024-04-11T19:36:24.4535647Z             os.(*File).Read(0x400050a130, {0x40004f8000?, 0x40004cebd8?, 0x4000216500?})
2024-04-11T19:36:24.4536639Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/file.go:118 +0x70
2024-04-11T19:36:24.4537016Z             bufio.(*Reader).fill(0x40004cef18)
2024-04-11T19:36:24.4538042Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/bufio/bufio.go:110 +0xf8
2024-04-11T19:36:24.4538491Z             bufio.(*Reader).ReadSlice(0x40004cef18, 0xa)
2024-04-11T19:36:24.4539521Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/bufio/bufio.go:376 +0x30
2024-04-11T19:36:24.4540030Z             bufio.(*Reader).collectFragments(0x40004cef18, 0xa)
2024-04-11T19:36:24.4541053Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/bufio/bufio.go:451 +0x64
2024-04-11T19:36:24.4541488Z             bufio.(*Reader).ReadString(0xa6f282?, 0xc?)
2024-04-11T19:36:24.4542517Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/bufio/bufio.go:498 +0x20
2024-04-11T19:36:24.4543443Z             go.etcd.io/etcd/pkg/v3/expect.(*ExpectProcess).tryReadNextLine(0x40004fe600, 0x40004cef18)
2024-04-11T19:36:24.4544516Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:135 +0x54
2024-04-11T19:36:24.4545182Z             go.etcd.io/etcd/pkg/v3/expect.(*ExpectProcess).read(0x40004fe600)
2024-04-11T19:36:24.4546115Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:126 +0x144
2024-04-11T19:36:24.4547026Z             created by go.etcd.io/etcd/pkg/v3/expect.NewExpectWithEnv in goroutine 4744
2024-04-11T19:36:24.4547947Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:87 +0x1f8
2024-04-11T19:36:24.4548136Z             
2024-04-11T19:36:24.4548447Z             goroutine 4747 [syscall]:
2024-04-11T19:36:24.4549124Z             syscall.Syscall6(0x5f, 0x1, 0x13d03, 0x40004a7598, 0x1000004, 0x0, 0x0)
2024-04-11T19:36:24.4550270Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/syscall/syscall_linux.go:91 +0x2c
2024-04-11T19:36:24.4550748Z             os.(*Process).blockUntilWaitable(0x40003c26c0)
2024-04-11T19:36:24.4551796Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/wait_waitid.go:32 +0x6c
2024-04-11T19:36:24.4552273Z             os.(*Process).wait(0x40003c26c0)
2024-04-11T19:36:24.4553302Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/exec_unix.go:22 +0x2c
2024-04-11T19:36:24.4553608Z             os.(*Process).Wait(...)
2024-04-11T19:36:24.4554521Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/exec.go:134
2024-04-11T19:36:24.4555266Z             go.etcd.io/etcd/pkg/v3/expect.(*ExpectProcess).waitProcess(0x40002366c0)
2024-04-11T19:36:24.4556178Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:329 +0x3c
2024-04-11T19:36:24.4556962Z             go.etcd.io/etcd/pkg/v3/expect.(*ExpectProcess).waitSaveExitErr(0x40002366c0)
2024-04-11T19:36:24.4557877Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:154 +0x58
2024-04-11T19:36:24.4558662Z             created by go.etcd.io/etcd/pkg/v3/expect.NewExpectWithEnv in goroutine 4745
2024-04-11T19:36:24.4559570Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:88 +0x238
2024-04-11T19:36:24.4559760Z             
2024-04-11T19:36:24.4560056Z             goroutine 4763 [sleep]:
2024-04-11T19:36:24.4560353Z             time.Sleep(0x12a05f200)
2024-04-11T19:36:24.4561393Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/runtime/time.go:195 +0xfc
2024-04-11T19:36:24.4564132Z             go.etcd.io/etcd/tests/v3/common.TestMemberAdd.func1.1()
2024-04-11T19:36:24.4565250Z             	/home/runner/actions-runner/_work/etcd/etcd/tests/common/member_test.go:130 +0x70
2024-04-11T19:36:24.4565948Z             go.etcd.io/etcd/tests/v3/framework/testutils.ExecuteUntil.func1()
2024-04-11T19:36:24.4567581Z             	/home/runner/actions-runner/_work/etcd/etcd/tests/framework/testutils/execute.go:38 +0x58
2024-04-11T19:36:24.4568715Z             created by go.etcd.io/etcd/tests/v3/framework/testutils.ExecuteUntil in goroutine 4742
2024-04-11T19:36:24.4569865Z             	/home/runner/actions-runner/_work/etcd/etcd/tests/framework/testutils/execute.go:36 +0xa8
2024-04-11T19:36:24.4570049Z             
2024-04-11T19:36:24.4570360Z             goroutine 4730 [syscall]:
2024-04-11T19:36:24.4571033Z             syscall.Syscall6(0x5f, 0x1, 0x13d01, 0x40005d3d98, 0x1000004, 0x0, 0x0)
2024-04-11T19:36:24.4572175Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/syscall/syscall_linux.go:91 +0x2c
2024-04-11T19:36:24.4572649Z             os.(*Process).blockUntilWaitable(0x400026e060)
2024-04-11T19:36:24.4573706Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/wait_waitid.go:32 +0x6c
2024-04-11T19:36:24.4574068Z             os.(*Process).wait(0x400026e060)
2024-04-11T19:36:24.4575102Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/exec_unix.go:22 +0x2c
2024-04-11T19:36:24.4575586Z             os.(*Process).Wait(...)
2024-04-11T19:36:24.4576504Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/exec.go:134
2024-04-11T19:36:24.4577260Z             go.etcd.io/etcd/pkg/v3/expect.(*ExpectProcess).waitProcess(0x40004fe600)
2024-04-11T19:36:24.4578169Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:329 +0x3c
2024-04-11T19:36:24.4579060Z             go.etcd.io/etcd/pkg/v3/expect.(*ExpectProcess).waitSaveExitErr(0x40004fe600)
2024-04-11T19:36:24.4579979Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:154 +0x58
2024-04-11T19:36:24.4580761Z             created by go.etcd.io/etcd/pkg/v3/expect.NewExpectWithEnv in goroutine 4744
2024-04-11T19:36:24.4581679Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:88 +0x238
2024-04-11T19:36:24.4581868Z             
2024-04-11T19:36:24.4582182Z             goroutine 4783 [syscall]:
2024-04-11T19:36:24.4582855Z             syscall.Syscall6(0x5f, 0x1, 0x13d02, 0x40005cd598, 0x1000004, 0x0, 0x0)
2024-04-11T19:36:24.4584114Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/syscall/syscall_linux.go:91 +0x2c
2024-04-11T19:36:24.4584591Z             os.(*Process).blockUntilWaitable(0x400011b6b0)
2024-04-11T19:36:24.4585644Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/wait_waitid.go:32 +0x6c
2024-04-11T19:36:24.4586010Z             os.(*Process).wait(0x400011b6b0)
2024-04-11T19:36:24.4587031Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/exec_unix.go:22 +0x2c
2024-04-11T19:36:24.4587338Z             os.(*Process).Wait(...)
2024-04-11T19:36:24.4588250Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/os/exec.go:134
2024-04-11T19:36:24.4588995Z             go.etcd.io/etcd/pkg/v3/expect.(*ExpectProcess).waitProcess(0x4000292c00)
2024-04-11T19:36:24.4589918Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:329 +0x3c
2024-04-11T19:36:24.4590712Z             go.etcd.io/etcd/pkg/v3/expect.(*ExpectProcess).waitSaveExitErr(0x4000292c00)
2024-04-11T19:36:24.4591629Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:154 +0x58
2024-04-11T19:36:24.4592414Z             created by go.etcd.io/etcd/pkg/v3/expect.NewExpectWithEnv in goroutine 4743
2024-04-11T19:36:24.4593322Z             	/home/runner/actions-runner/_work/etcd/etcd/pkg/expect/expect.go:88 +0x238
2024-04-11T19:36:24.4593503Z             
2024-04-11T19:36:24.4593845Z             goroutine 4459 [chan receive]:
2024-04-11T19:36:24.4594540Z             testing.(*T).Run(0x40008c0000, {0x4000026080?, 0x40008c0000?}, 0x40001cafc0)
2024-04-11T19:36:24.4595627Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/testing/testing.go:1750 +0x32c
2024-04-11T19:36:24.4596403Z             go.etcd.io/etcd/tests/v3/common.TestMemberAdd(0x40008c0000)
2024-04-11T19:36:24.4597420Z             	/home/runner/actions-runner/_work/etcd/etcd/tests/common/member_test.go:117 +0x2c0
2024-04-11T19:36:24.4597826Z             testing.tRunner(0x40008c0000, 0xaddd38)
2024-04-11T19:36:24.4601125Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/testing/testing.go:1689 +0xec
2024-04-11T19:36:24.4601643Z             created by testing.(*T).Run in goroutine 1
2024-04-11T19:36:24.4602774Z             	/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/testing/testing.go:1742 +0x318
2024-04-11T19:36:24.4602968Z             
2024-04-11T19:36:24.4603690Z         testutil.go:58: test timed out after 3.26223988s, err: context deadline exceeded
2024-04-11T19:36:24.4604389Z         logger.go:146: 2024-04-11T19:28:15.475Z	INFO	closing test cluster...
2024-04-11T19:36:24.4605918Z         logger.go:146: 2024-04-11T19:28:15.475Z	INFO	stopping server...	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-0"}
2024-04-11T19:36:24.4607577Z         logger.go:146: 2024-04-11T19:28:16.595Z	INFO	stopped server.	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-0"}
2024-04-11T19:36:24.4609543Z         logger.go:146: 2024-04-11T19:28:16.595Z	INFO	stopping server...	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-1"}
2024-04-11T19:36:24.4609833Z         member_test.go:142: 
2024-04-11T19:36:24.4610915Z             	Error Trace:	/home/runner/actions-runner/_work/etcd/etcd/tests/common/member_test.go:142
2024-04-11T19:36:24.4612628Z             	            				/home/runner/actions-runner/_work/etcd/etcd/tests/framework/testutils/execute.go:38
2024-04-11T19:36:24.4614117Z             	            				/home/runner/actions-runner/_work/_tool/go/1.22.2/arm64/src/runtime/asm_arm64.s:1222
2024-04-11T19:36:24.4614558Z             	Error:      	Received unexpected error:
2024-04-11T19:36:24.4615410Z             	            	failed to find match string: context deadline exceeded
2024-04-11T19:36:24.4616192Z             	Test:       	TestMemberAdd/Learner/StrictReconfigCheck/WaitForQuorum/PeerTLS
2024-04-11T19:36:24.4616546Z             	Messages:   	MemberAdd failed
2024-04-11T19:36:24.4618155Z         logger.go:146: 2024-04-11T19:28:17.619Z	INFO	stopped server.	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-1"}
2024-04-11T19:36:24.4619666Z         logger.go:146: 2024-04-11T19:28:17.619Z	INFO	stopping server...	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-2"}
2024-04-11T19:36:24.4621158Z         logger.go:146: 2024-04-11T19:28:17.634Z	INFO	stopped server.	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-2"}
2024-04-11T19:36:24.4622666Z         logger.go:146: 2024-04-11T19:28:17.634Z	INFO	closing server...	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-0"}
2024-04-11T19:36:24.4624389Z         logger.go:146: 2024-04-11T19:28:17.634Z	INFO	removing directory	{"data-dir": "/tmp/TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS3981728050/001"}
2024-04-11T19:36:24.4625906Z         logger.go:146: 2024-04-11T19:28:17.636Z	INFO	closing server...	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-1"}
2024-04-11T19:36:24.4627621Z         logger.go:146: 2024-04-11T19:28:17.636Z	INFO	removing directory	{"data-dir": "/tmp/TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS3981728050/002"}
2024-04-11T19:36:24.4629128Z         logger.go:146: 2024-04-11T19:28:17.638Z	INFO	closing server...	{"name": "TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS-test-2"}
2024-04-11T19:36:24.4630843Z         logger.go:146: 2024-04-11T19:28:17.638Z	INFO	removing directory	{"data-dir": "/tmp/TestMemberAddLearnerStrictReconfigCheckWaitForQuorumPeerTLS3981728050/003"}
2024-04-11T19:36:24.4631518Z         logger.go:146: 2024-04-11T19:28:17.640Z	INFO	closed test cluster.

Anything else we need to know?

No response

@jmhbnz jmhbnz changed the title Flaking TestMemberAdd e2e test on arm64 Flaking TestMemberAdd e2e test on arm64 and amd64 Apr 11, 2024
@jmhbnz
Copy link
Member Author

jmhbnz commented Apr 11, 2024

Actually this is not limited to arm64 updated title. There are instances in amd64 in testgrid also. For example https://prow.k8s.io/view/gs/kubernetes-jenkins/pr-logs/directory/pull-etcd-e2e-amd64/1776962029186191360

    member_test.go:142: 
        	Error Trace:	/home/prow/go/src/github.com/etcd-io/etcd/tests/common/member_test.go:142
        	            				/home/prow/go/src/github.com/etcd-io/etcd/tests/framework/testutils/execute.go:38
        	            				/usr/local/go/src/runtime/asm_amd64.s:1695
        	Error:      	Received unexpected error:
        	            	failed to find match string: context deadline exceeded
        	Test:       	TestMemberAdd/Learner/StrictReconfigCheck/WaitForQuorum/PeerTLS
        	Messages:   	MemberAdd failed

@mneverov
Copy link
Contributor

Probably related to #17653 as the codepath is the same. I.e. increasing test timeout should help

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

No branches or pull requests

2 participants