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

Test flakes #4653

Closed
6 of 15 tasks
a-palchikov opened this issue Oct 28, 2020 · 2 comments
Closed
6 of 15 tasks

Test flakes #4653

a-palchikov opened this issue Oct 28, 2020 · 2 comments

Comments

@a-palchikov
Copy link
Contributor

a-palchikov commented Oct 28, 2020 •
edited by zmb3

Description

What happened:
There are multiple test flakes on master.
I stumbled on one test when working on an unrelated issue and since then the following failures surfaced:

  • Data race in lib/backend
Logs 
==================
WARNING: DATA RACE
Read at 0x00c000281448 by goroutine 96:
  github.com/gravitational/teleport/lib/backend/test.(*BackendSuite).Locking.func3()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/test/suite.go:568 +0x131

Previous write at 0x00c000281448 by goroutine 72:
  github.com/gravitational/teleport/lib/backend/lite.(*LiteSuite).SetUpTest()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite_test.go:56 +0x149
  runtime.call32()
      /home/deemok/dev/go/go/src/runtime/asm_amd64.s:539 +0x3a
  reflect.Value.Call()
      /home/deemok/dev/go/go/src/reflect/value.go:321 +0xd3
  gopkg.in/check%2ev1.(*suiteRunner).runFixture.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:730 +0x1c3
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:675 +0xd9

Goroutine 96 (running) created at:
  github.com/gravitational/teleport/lib/backend/test.(*BackendSuite).Locking()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/test/suite.go:565 +0xbe3
  github.com/gravitational/teleport/lib/backend/lite.(*LiteSuite).TestLocking()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite_test.go:102 +0x48
  runtime.call32()
      /home/deemok/dev/go/go/src/runtime/asm_amd64.s:539 +0x3a
  reflect.Value.Call()
      /home/deemok/dev/go/go/src/reflect/value.go:321 +0xd3
  gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:781 +0xa0a
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:675 +0xd9

Goroutine 72 (running) created at:
  gopkg.in/check%2ev1.(*suiteRunner).forkCall()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:672 +0x44d
  gopkg.in/check%2ev1.(*suiteRunner).runFunc()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:682 +0x83
  gopkg.in/check%2ev1.(*suiteRunner).runFixture()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:726 +0x3d
  gopkg.in/check%2ev1.(*suiteRunner).runFixtureWithPanic()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:744 +0x82
  gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:769 +0x28c
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:675 +0xd9
==================
==================
WARNING: DATA RACE
Read at 0x00c0001f4d78 by goroutine 96:
  github.com/gravitational/teleport/lib/backend/lite.(*Backend).inTransaction()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite.go:820 +0xd2
  github.com/gravitational/teleport/lib/backend/lite.(*Backend).Delete()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite.go:729 +0x143
  github.com/gravitational/teleport/lib/backend.ReleaseLock()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/helpers.go:59 +0xe8
  github.com/gravitational/teleport/lib/backend/test.(*BackendSuite).Locking.func3()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/test/suite.go:568 +0x182

Previous write at 0x00c0001f4d78 by goroutine 72:
  github.com/gravitational/teleport/lib/backend/lite.NewWithConfig()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite.go:161 +0x567
  github.com/gravitational/teleport/lib/backend/lite.New()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite.go:128 +0x28d
  github.com/gravitational/teleport/lib/backend/lite.(*LiteSuite).SetUpSuite.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite_test.go:44 +0x193
  github.com/gravitational/teleport/lib/backend/lite.(*LiteSuite).SetUpTest()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite_test.go:53 +0x56
  runtime.call32()
      /home/deemok/dev/go/go/src/runtime/asm_amd64.s:539 +0x3a
  reflect.Value.Call()
      /home/deemok/dev/go/go/src/reflect/value.go:321 +0xd3
  gopkg.in/check%2ev1.(*suiteRunner).runFixture.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:730 +0x1c3
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:675 +0xd9

Goroutine 96 (running) created at:
  github.com/gravitational/teleport/lib/backend/test.(*BackendSuite).Locking()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/test/suite.go:565 +0xbe3
  github.com/gravitational/teleport/lib/backend/lite.(*LiteSuite).TestLocking()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite_test.go:102 +0x48
  runtime.call32()
      /home/deemok/dev/go/go/src/runtime/asm_amd64.s:539 +0x3a
  reflect.Value.Call()
      /home/deemok/dev/go/go/src/reflect/value.go:321 +0xd3
  gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:781 +0xa0a
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:675 +0xd9

Goroutine 72 (running) created at:
  gopkg.in/check%2ev1.(*suiteRunner).forkCall()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:672 +0x44d
  gopkg.in/check%2ev1.(*suiteRunner).runFunc()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:682 +0x83
  gopkg.in/check%2ev1.(*suiteRunner).runFixture()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:726 +0x3d
  gopkg.in/check%2ev1.(*suiteRunner).runFixtureWithPanic()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:744 +0x82
  gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:769 +0x28c
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:675 +0xd9
==================
==================
WARNING: DATA RACE
Write at 0x00c0002749e0 by goroutine 96:
  sync/atomic.CompareAndSwapInt32()
      /home/deemok/dev/go/go/src/runtime/race_amd64.s:293 +0xb
  sync.(*Mutex).Lock()
      /home/deemok/dev/go/go/src/sync/mutex.go:74 +0x49
  database/sql.(*DB).conn()
      /home/deemok/dev/go/go/src/database/sql/sql.go:1134 +0x61
  database/sql.(*DB).begin()
      /home/deemok/dev/go/go/src/database/sql/sql.go:1681 +0x68
  database/sql.(*DB).BeginTx()
      /home/deemok/dev/go/go/src/database/sql/sql.go:1663 +0x9f
  github.com/gravitational/teleport/lib/backend/lite.(*Backend).inTransaction()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite.go:820 +0x10a
  github.com/gravitational/teleport/lib/backend/lite.(*Backend).Delete()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite.go:729 +0x143
  github.com/gravitational/teleport/lib/backend.ReleaseLock()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/helpers.go:59 +0xe8
  github.com/gravitational/teleport/lib/backend/test.(*BackendSuite).Locking.func3()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/test/suite.go:568 +0x182

Previous write at 0x00c0002749e0 by goroutine 72:
  database/sql.OpenDB()
      /home/deemok/dev/go/go/src/database/sql/sql.go:734 +0x107
  database/sql.Open()
      /home/deemok/dev/go/go/src/database/sql/sql.go:780 +0x279
  github.com/gravitational/teleport/lib/backend/lite.NewWithConfig()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite.go:149 +0x12b
  github.com/gravitational/teleport/lib/backend/lite.New()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite.go:128 +0x28d
  github.com/gravitational/teleport/lib/backend/lite.(*LiteSuite).SetUpSuite.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite_test.go:44 +0x193
  github.com/gravitational/teleport/lib/backend/lite.(*LiteSuite).SetUpTest()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite_test.go:53 +0x56
  runtime.call32()
      /home/deemok/dev/go/go/src/runtime/asm_amd64.s:539 +0x3a
  reflect.Value.Call()
      /home/deemok/dev/go/go/src/reflect/value.go:321 +0xd3
  gopkg.in/check%2ev1.(*suiteRunner).runFixture.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:730 +0x1c3
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:675 +0xd9

Goroutine 96 (running) created at:
  github.com/gravitational/teleport/lib/backend/test.(*BackendSuite).Locking()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/test/suite.go:565 +0xbe3
  github.com/gravitational/teleport/lib/backend/lite.(*LiteSuite).TestLocking()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/backend/lite/lite_test.go:102 +0x48
  runtime.call32()
      /home/deemok/dev/go/go/src/runtime/asm_amd64.s:539 +0x3a
  reflect.Value.Call()
      /home/deemok/dev/go/go/src/reflect/value.go:321 +0xd3
  gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:781 +0xa0a
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:675 +0xd9

Goroutine 72 (running) created at:
  gopkg.in/check%2ev1.(*suiteRunner).forkCall()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:672 +0x44d
  gopkg.in/check%2ev1.(*suiteRunner).runFunc()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:682 +0x83
  gopkg.in/check%2ev1.(*suiteRunner).runFixture()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:726 +0x3d
  gopkg.in/check%2ev1.(*suiteRunner).runFixtureWithPanic()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:744 +0x82
  gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:769 +0x28c
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:675 +0xd9
==================
  • Time-sensitive polling
Logs 
FAIL: sshserver_test.go:371: SrvSuite.TestAgentForward

sshserver_test.go:456:
    c.Fatalf("expected socket to be closed, still could dial after 150 ms")
... Error: expected socket to be closed, still could dial after 150 ms

OOPS: 23 passed, 1 skipped, 1 FAILED
--- FAIL: TestRegular (16.19s)
FAIL
coverage: 61.1% of statements
FAIL	github.com/gravitational/teleport/lib/srv/regular	16.285s
  • Semaphore contention
Logs 
FAIL: services_test.go:176: ServicesSuite.TestSemaphoreContention

/go/src/github.com/gravitational/teleport/lib/services/suite/suite.go:1105:
    c.Assert(err, check.IsNil)
... value *trace.TraceErr = 
ERROR REPORT:
Original Error: *trace.LimitExceededError too much contention on semaphore connection/alice
Stack Trace:
	/go/src/github.com/gravitational/teleport/lib/services/local/presence.go:750 github.com/gravitational/teleport/lib/services/local.(*PresenceService).AcquireSemaphore
	/go/src/github.com/gravitational/teleport/lib/services/semaphore.go:240 github.com/gravitational/teleport/lib/services.AcquireSemaphoreLock
	/go/src/github.com/gravitational/teleport/lib/services/suite/suite.go:1104 github.com/gravitational/teleport/lib/services/suite.(*ServicesTestSuite).SemaphoreContention.func1
	/opt/go/src/runtime/asm_amd64.s:1374 runtime.goexit
User Message: too much contention on semaphore connection/alice
 ("too much contention on semaphore connection/alice")

OOPS: 33 passed, 1 FAILED
--- FAIL: Test (21.34s)
FAIL
coverage: 48.6% of statements
FAIL	github.com/gravitational/teleport/lib/services/local	21.387s
  • Etcd backend keep alive test
Logs 
FAIL: etcd_test.go:127: EtcdSuite.TestKeepAlive

etcd_test.go:128:
    s.suite.KeepAlive(c)
/go/src/github.com/gravitational/teleport/lib/backend/test/suite.go:345:
    c.Assert(err, check.IsNil)
... value *trace.TraceErr = 
ERROR REPORT:
Original Error: *trace.NotFoundError item "/139c4d9e-f330-4d01-8be8-c67fff830403key" is not found
Stack Trace:
	/go/src/github.com/gravitational/teleport/lib/backend/etcdbk/etcd.go:581 github.com/gravitational/teleport/lib/backend/etcdbk.(*EtcdBackend).Get
	/go/src/github.com/gravitational/teleport/lib/backend/test/suite.go:344 github.com/gravitational/teleport/lib/backend/test.(*BackendSuite).KeepAlive
	/go/src/github.com/gravitational/teleport/lib/backend/etcdbk/etcd_test.go:129 github.com/gravitational/teleport/lib/backend/etcdbk.(*EtcdSuite).TestKeepAlive
	/opt/go/src/reflect/value.go:463 reflect.Value.call
	/opt/go/src/reflect/value.go:321 reflect.Value.Call
	/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:782 gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1
	/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:676 gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1
	/opt/go/src/runtime/asm_amd64.s:1374 runtime.goexit
User Message: item "/139c4d9e-f330-4d01-8be8-c67fff830403key" is not found
 ("item \"/139c4d9e-f330-4d01-8be8-c67fff830403key\" is not found")

OOPS: 10 passed, 1 FAILED
--- FAIL: TestEtcd (10.40s)
FAIL
coverage: 75.1% of statements
FAIL	github.com/gravitational/teleport/lib/backend/etcdbk	10.504s
  • Stop service timeout
Logs 
----------------------------------------------------------------------
FAIL: integration_test.go:3173: IntSuite.TestRotateSuccess

integration_test.go:3241:
    c.Assert(err, check.IsNil)
... value *trace.TraceErr = 
ERROR REPORT:
Original Error: *trace.BadParameterError timeout waiting for old service to stop
Stack Trace:
	/go/src/github.com/gravitational/teleport/integration/integration_test.go:3879 github.com/gravitational/teleport/integration.waitForReload
	/go/src/github.com/gravitational/teleport/integration/integration_test.go:3240 github.com/gravitational/teleport/integration.(*IntSuite).TestRotateSuccess
	/opt/go/src/reflect/value.go:463 reflect.Value.call
	/opt/go/src/reflect/value.go:321 reflect.Value.Call
	/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:782 gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1
	/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:676 gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1
	/opt/go/src/runtime/asm_amd64.s:1374 runtime.goexit
User Message: timeout waiting for old service to stop
 ("timeout waiting for old service to stop")
  • Lite backend keep alive test
Logs 
----------------------------------------------------------------------
FAIL: lite_test.go:81: LiteSuite.TestKeepAlive

lite_test.go:82:
    s.suite.KeepAlive(c)
/go/src/github.com/gravitational/teleport/lib/backend/test/suite.go:345:
    c.Assert(err, check.IsNil)
... value *trace.TraceErr = 
ERROR REPORT:
Original Error: *trace.NotFoundError key /ad471fbf-5b6e-465f-afc9-2978ac70227ckey is not found
Stack Trace:
	/go/src/github.com/gravitational/teleport/lib/backend/lite/lite.go:596 github.com/gravitational/teleport/lib/backend/lite.(*Backend).getInTransaction
	/go/src/github.com/gravitational/teleport/lib/backend/lite/lite.go:570 github.com/gravitational/teleport/lib/backend/lite.(*Backend).Get.func1
	/go/src/github.com/gravitational/teleport/lib/backend/lite/lite.go:867 github.com/gravitational/teleport/lib/backend/lite.(*Backend).inTransaction
	/go/src/github.com/gravitational/teleport/lib/backend/lite/lite.go:569 github.com/gravitational/teleport/lib/backend/lite.(*Backend).Get
	/go/src/github.com/gravitational/teleport/lib/backend/test/suite.go:344 github.com/gravitational/teleport/lib/backend/test.(*BackendSuite).KeepAlive
	/go/src/github.com/gravitational/teleport/lib/backend/lite/lite_test.go:83 github.com/gravitational/teleport/lib/backend/lite.(*LiteSuite).TestKeepAlive
	/opt/go/src/reflect/value.go:463 reflect.Value.call
	/opt/go/src/reflect/value.go:321 reflect.Value.Call
	/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:782 gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1
	/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:676 gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1
	/opt/go/src/runtime/asm_amd64.s:1374 runtime.goexit
User Message: key /ad471fbf-5b6e-465f-afc9-2978ac70227ckey is not found
 ("key /ad471fbf-5b6e-465f-afc9-2978ac70227ckey is not found")
  • Access denied
Logs 
----------------------------------------------------------------------
FAIL: integration_test.go:3174: IntSuite.TestRotateSuccess

integration_test.go:3303:
    c.Assert(err, check.IsNil)
... value *trace.TraceErr = 
ERROR REPORT:
Original Error: *trace.AccessDeniedError access denied to ci connecting to 127.0.0.1 on cluster local-site
Stack Trace:
	/go/src/github.com/gravitational/teleport/lib/client/client.go:580 github.com/gravitational/teleport/lib/client.(*ProxyClient).ConnectToNode
	/go/src/github.com/gravitational/teleport/lib/client/api.go:962 github.com/gravitational/teleport/lib/client.(*TeleportClient).SSH
	/go/src/github.com/gravitational/teleport/integration/integration_test.go:3895 github.com/gravitational/teleport/integration.runAndMatch
	/go/src/github.com/gravitational/teleport/integration/integration_test.go:3302 github.com/gravitational/teleport/integration.(*IntSuite).TestRotateSuccess
	/opt/go/src/reflect/value.go:463 reflect.Value.call
	/opt/go/src/reflect/value.go:321 reflect.Value.Call
	/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:782 gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1
	/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:676 gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1
	/opt/go/src/runtime/asm_amd64.s:1374 runtime.goexit
User Message: access denied to ci connecting to 127.0.0.1 on cluster local-site
 ("access denied to ci connecting to 127.0.0.1 on cluster local-site")
  • Another data race
Logs 
==================
WARNING: DATA RACE
Read at 0x00c000979258 by goroutine 472:
  github.com/gravitational/teleport/lib/srv.emitExecAuditEvent()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/srv/exec.go:364 +0x15a
  github.com/gravitational/teleport/lib/srv.(*localExec).Wait()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/srv/exec.go:201 +0x1e7
  github.com/gravitational/teleport/lib/srv.(*session).startExec.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/srv/sess.go:950 +0x7c

Previous write at 0x00c000979258 by goroutine 443:
  github.com/gravitational/teleport/lib/srv.(*ServerContext).CreateOrJoinSession()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/srv/ctx.go:420 +0x124
  github.com/gravitational/teleport/lib/srv/regular.(*Server).handleSessionRequests()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/srv/regular/sshserver.go:1215 +0x11f7
  github.com/gravitational/teleport/lib/srv/regular.(*Server).HandleNewChan.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/srv/regular/sshserver.go:1022 +0x123

Goroutine 472 (running) created at:
  github.com/gravitational/teleport/lib/srv.(*session).startExec()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/srv/sess.go:949 +0xf91
  github.com/gravitational/teleport/lib/srv.(*SessionRegistry).OpenExecSession()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/srv/sess.go:233 +0x1ad
  github.com/gravitational/teleport/lib/srv.(*TermHandlers).HandleExec()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/srv/termhandlers.go:51 +0x181
  github.com/gravitational/teleport/lib/srv/regular.(*Server).dispatch()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/srv/regular/sshserver.go:1298 +0x898
  github.com/gravitational/teleport/lib/srv/regular.(*Server).handleSessionRequests()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/srv/regular/sshserver.go:1241 +0xa29
  github.com/gravitational/teleport/lib/srv/regular.(*Server).HandleNewChan.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/srv/regular/sshserver.go:1022 +0x123

Goroutine 443 (running) created at:
  github.com/gravitational/teleport/lib/srv/regular.(*Server).HandleNewChan()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/srv/regular/sshserver.go:1021 +0xf96
==================
OK: 1 passed
--- FAIL: TestIntegrations (5.15s)
    testing.go:965: race detected during execution of test
  • Data race: lib/srv/regular
Logs 
==================
WARNING: DATA RACE
Read at 0x00c0004dc860 by goroutine 288:
  github.com/gravitational/teleport/lib/utils.UTC()
      /go/src/github.com/gravitational/teleport/lib/utils/time.go:40 +0x4e
  github.com/gravitational/teleport/lib/services.(*Metadata).CheckAndSetDefaults()
      /go/src/github.com/gravitational/teleport/lib/services/resource.go:728 +0x28c
  github.com/gravitational/teleport/lib/services.(*ServerV2).CheckAndSetDefaults()
      /go/src/github.com/gravitational/teleport/lib/services/server.go:340 +0x56
  github.com/gravitational/teleport/lib/services.(*TeleportServerMarshaler).MarshalServer()
      /go/src/github.com/gravitational/teleport/lib/services/server.go:866 +0x59
  github.com/gravitational/teleport/lib/reversetunnel.marshalDiscoveryRequest()
      /go/src/github.com/gravitational/teleport/lib/reversetunnel/discovery.go:64 +0x112
  github.com/gravitational/teleport/lib/reversetunnel.(*remoteConn).sendDiscoveryRequest()
      /go/src/github.com/gravitational/teleport/lib/reversetunnel/conn.go:238 +0xb1
  github.com/gravitational/teleport/lib/reversetunnel.(*localSite).handleHeartbeat()
      /go/src/github.com/gravitational/teleport/lib/reversetunnel/localsite.go:372 +0xf7b

Previous write at 0x00c0004dc860 by goroutine 170:
  github.com/gravitational/teleport/lib/utils.UTC()
      /go/src/github.com/gravitational/teleport/lib/utils/time.go:45 +0x158
  github.com/gravitational/teleport/lib/services.(*Metadata).CheckAndSetDefaults()
      /go/src/github.com/gravitational/teleport/lib/services/resource.go:728 +0x28c
  github.com/gravitational/teleport/lib/services.(*ServerV2).CheckAndSetDefaults()
      /go/src/github.com/gravitational/teleport/lib/services/server.go:340 +0x56
  github.com/gravitational/teleport/lib/services.(*TeleportServerMarshaler).MarshalServer()
      /go/src/github.com/gravitational/teleport/lib/services/server.go:866 +0x59
  github.com/gravitational/teleport/lib/reversetunnel.marshalDiscoveryRequest()
      /go/src/github.com/gravitational/teleport/lib/reversetunnel/discovery.go:64 +0x112
  github.com/gravitational/teleport/lib/reversetunnel.(*remoteConn).sendDiscoveryRequest()
      /go/src/github.com/gravitational/teleport/lib/reversetunnel/conn.go:238 +0xb1
  github.com/gravitational/teleport/lib/reversetunnel.(*localSite).handleHeartbeat()
      /go/src/github.com/gravitational/teleport/lib/reversetunnel/localsite.go:372 +0xf7b

Goroutine 288 (running) created at:
  github.com/gravitational/teleport/lib/reversetunnel.(*server).handleNewService()
      /go/src/github.com/gravitational/teleport/lib/reversetunnel/srv.go:652 +0x343
  github.com/gravitational/teleport/lib/reversetunnel.(*server).handleHeartbeat()
      /go/src/github.com/gravitational/teleport/lib/reversetunnel/srv.go:620 +0x5c3
  github.com/gravitational/teleport/lib/reversetunnel.(*server).HandleNewChan()
      /go/src/github.com/gravitational/teleport/lib/reversetunnel/srv.go:557 +0x3e0

Goroutine 170 (running) created at:
  github.com/gravitational/teleport/lib/reversetunnel.(*server).handleNewService()
      /go/src/github.com/gravitational/teleport/lib/reversetunnel/srv.go:652 +0x343
  github.com/gravitational/teleport/lib/reversetunnel.(*server).handleHeartbeat()
      /go/src/github.com/gravitational/teleport/lib/reversetunnel/srv.go:620 +0x5c3
  github.com/gravitational/teleport/lib/reversetunnel.(*server).HandleNewChan()
      /go/src/github.com/gravitational/teleport/lib/reversetunnel/srv.go:557 +0x3e0
==================
OK: 24 passed, 1 skipped
--- FAIL: TestRegular (54.63s)
    testing.go:906: race detected during execution of test
FAIL
coverage: 60.1% of statements
FAIL	github.com/gravitational/teleport/lib/srv/regular	54.967s
  • Data race: lib/utils.LoadBalancer
Logs 
==================
WARNING: DATA RACE
Write at 0x00c0021f08d0 by goroutine 94:
  github.com/gravitational/teleport/lib/utils.(*LoadBalancer).AddBackend()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/utils/loadbalancer.go:109 +0x10f
  github.com/gravitational/teleport/integration.(*IntSuite).TestDiscovery()
      /home/deemok/go/src/github.com/gravitational/teleport/integration/integration_test.go:2528 +0x1de5
  runtime.call32()
      /home/deemok/dev/go/go/src/runtime/asm_amd64.s:540 +0x3d
  reflect.Value.Call()
      /home/deemok/dev/go/go/src/reflect/value.go:337 +0xd8
  gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:781 +0xabb
  gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:675 +0xe1

Previous read at 0x00c0021f08d0 by goroutine 337:
  github.com/gravitational/teleport/lib/utils.(*LoadBalancer).forward()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/utils/loadbalancer.go:236 +0x3f3
  github.com/gravitational/teleport/lib/utils.(*LoadBalancer).forwardConnection()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/utils/loadbalancer.go:206 +0x53

Goroutine 94 (running) created at:
  gopkg.in/check%2ev1.(*suiteRunner).forkCall()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:672 +0x459
  gopkg.in/check%2ev1.(*suiteRunner).forkTest()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:763 +0x1c4
  gopkg.in/check%2ev1.(*suiteRunner).runTest()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:818 +0x23e
  gopkg.in/check%2ev1.(*suiteRunner).run()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:624 +0x1dc
  gopkg.in/check%2ev1.Run()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/run.go:92 +0x5a
  gopkg.in/check%2ev1.RunAll()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/run.go:84 +0x136
  gopkg.in/check%2ev1.TestingT()
      /home/deemok/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/run.go:72 +0x5ef
  github.com/gravitational/teleport/integration.TestIntegrations()
      /home/deemok/go/src/github.com/gravitational/teleport/integration/integration_test.go:85 +0x38
  testing.tRunner()
      /home/deemok/dev/go/go/src/testing/testing.go:1123 +0x202

Goroutine 337 (running) created at:
  github.com/gravitational/teleport/lib/utils.(*LoadBalancer).Serve()
      /home/deemok/go/src/github.com/gravitational/teleport/lib/utils/loadbalancer.go:200 +0x172
==================
  • Unknown prefix type c
Logs 
----------------------------------------------------------------------
FAIL: apiserver_test.go:1157: WebSuite.TestCloseConnectionsOnLogout

apiserver_test.go:1199:
    c.Assert(err, Equals, io.EOF)
... obtained *trace.TraceErr = 
ERROR REPORT:
Original Error: *trace.BadParameterError unknown prefix type: c
Stack Trace:
	/go/src/github.com/gravitational/teleport/lib/web/terminal.go:594 github.com/gravitational/teleport/lib/web.(*TerminalHandler).read
	/go/src/github.com/gravitational/teleport/lib/web/terminal.go:621 github.com/gravitational/teleport/lib/web.(*terminalStream).Read
	/go/src/github.com/gravitational/teleport/lib/web/apiserver_test.go:1188 github.com/gravitational/teleport/lib/web.(*WebSuite).TestCloseConnectionsOnLogout.func1
	/opt/go/src/runtime/asm_amd64.s:1375 runtime.goexit
User Message: unknown prefix type: c
 ("unknown prefix type: c")
... expected *errors.errorString = &errors.errorString{s:"EOF"} ("EOF")
... Difference:
...     *trace.TraceErr != *errors.errorString
  • Context canceled in lib/srv/app#TestHandleConnection

Happens because HandleConnection in a goroutine does not always complete before
suite's TearDownTest which receives another context cancelled from appServer.Close as the listener has not been removed yet.

Logs 
----------------------------------------------------------------------
FAIL: server_test.go:207: Suite.TearDownTest

server_test.go:212:
    c.Assert(err, check.IsNil)
... value *trace.TraceErr = 
ERROR REPORT:
Original Error: trace.aggregate context canceled
Stack Trace:
	/go/src/github.com/gravitational/teleport/lib/srv/app/server.go:293 github.com/gravitational/teleport/lib/srv/app.(*Server).Close
	/go/src/github.com/gravitational/teleport/lib/srv/app/server_test.go:211 github.com/gravitational/teleport/lib/srv/app.(*Suite).TearDownTest
	/opt/go/src/reflect/value.go:479 reflect.Value.call
	/opt/go/src/reflect/value.go:337 reflect.Value.Call
	/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:731 gopkg.in/check%2ev1.(*suiteRunner).runFixture.func1
	/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:676 gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1
	/opt/go/src/runtime/asm_amd64.s:1375 runtime.goexit
User Message: 
 ("context canceled")


----------------------------------------------------------------------
PANIC: server_test.go:271: Suite.TestHandleConnection

... Panic: Fixture has panicked (see related PANIC)
OOPS: 2 passed, 1 FAILED, 6 MISSED
--- FAIL: TestApp (4.03s)
FAIL
coverage: 64.5% of statements
FAIL	github.com/gravitational/teleport/lib/srv/app	4.198s
  • Expected AccessDenied, got context canceled (fe7f582)
Logs 
----------------------------------------------------------------------
FAIL: tls_test.go:2660: TLSSuite.TestEventsPermissions

tls_test.go:2765:
    tryWatch(tc)
/go/src/github.com/gravitational/teleport/lib/fixtures/fixtures.go:31:
    c.Assert(trace.IsAccessDenied(err), check.Equals, true, check.Commentf("expected AccessDenied, got %T %v at %v", trace.Unwrap(err), err, string(debug.Stack())))
... obtained bool = false
... expected bool = true
... expected AccessDenied, got *errors.errorString context canceled at goroutine 22240 [running]:
runtime/debug.Stack(0xc0003fcd40, 0x2e42ce0, 0xc00019a270)
	/opt/go/src/runtime/debug/stack.go:24 +0xab
github.com/gravitational/teleport/lib/fixtures.ExpectAccessDenied(0xc0002f0780, 0x2e438e0, 0xc0003fcd40)
	/go/src/github.com/gravitational/teleport/lib/fixtures/fixtures.go:31 +0xcd
github.com/gravitational/teleport/lib/auth.(*TLSSuite).TestEventsPermissions.func1(0x2b443ef, 0x33, 0x29e11e0, 0xc001400dc0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
	/go/src/github.com/gravitational/teleport/lib/auth/tls_test.go:2761 +0x51b
github.com/gravitational/teleport/lib/auth.(*TLSSuite).TestEventsPermissions(0xc000349740, 0xc0002f0780)
	/go/src/github.com/gravitational/teleport/lib/auth/tls_test.go:2765 +0x19d1
reflect.Value.call(0x2ab62c0, 0xc000349740, 0x5213, 0x2aec734, 0x4, 0xc00101df18, 0x1, 0x1, 0xc00101dd40, 0xe8035e, ...)
	/opt/go/src/reflect/value.go:476 +0x9aa
reflect.Value.Call(0x2ab62c0, 0xc000349740, 0x5213, 0xc00101df18, 0x1, 0x1, 0xc0002f0870, 0xc0009fa040, 0xc0007ff5c8)
	/opt/go/src/reflect/value.go:337 +0xd9
gopkg.in/check%2ev1.(*suiteRunner).forkTest.func1(0xc0002f0780)
	/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:781 +0xabc
gopkg.in/check%2ev1.(*suiteRunner).forkCall.func1(0xc00014ec80, 0xc0002f0780, 0xc0008c0620)
	/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:675 +0xe2
created by gopkg.in/check%2ev1.(*suiteRunner).forkCall
	/go/src/github.com/gravitational/teleport/vendor/gopkg.in/check.v1/check.go:672 +0x45a


OOPS: 84 passed, 1 FAILED
--- FAIL: TestAPI (207.57s)
FAIL
coverage: 44.9% of statements
FAIL	github.com/gravitational/teleport/lib/auth	207.841s
  • Timing failure in lib/auth
Logs 
----------------------------------------------------------------------
FAIL: password_test.go:104: PasswordSuite.TestTiming

password_test.go:169:
    c.Assert(diffFraction < 0.1, Equals, true, comment)
... obtained bool = false
... expected bool = true
... elapsed difference (11.867287784100021%) greater than 10%

OOPS: 84 passed, 1 FAILED
--- FAIL: TestAPI (63.60s)
FAIL
FAIL	github.com/gravitational/teleport/lib/auth	63.649s
  • Expiration timestamp mismatch in lib/auth#TestReadIdentity (0d5aff7)
Logs 
----------------------------------------------------------------------
FAIL: init_test.go:63: AuthInitSuite.TestReadIdentity

init_test.go:105:
    c.Assert(uint64(expiryDate.Unix()), Equals, copy.ValidBefore)
... obtained uint64 = 0x60077359
... expected uint64 = 0x6007735a

OOPS: 83 passed, 1 FAILED
--- FAIL: TestAPI (182.65s)
FAIL
coverage: 43.7% of statements
FAIL	github.com/gravitational/teleport/lib/auth	182.881s

What you expected to happen:
Tests pass

How to reproduce it (as minimally and precisely as possible):
Not consistently reproducible
@a-palchikov a-palchikov mentioned this issue Oct 28, 2020
Closed
@webvictim
Copy link
Contributor

There’s also some that fail often in #4460

a-palchikov added a commit that referenced this issue Oct 30, 2020
@a-palchikov
Fix a data race in the locking test.
1bda23b 
Bump the timeout on AgentForward test.

Updates #4653.
a-palchikov added a commit that referenced this issue Oct 30, 2020
@a-palchikov
Fix a data race in the locking test.
c608b9f 
Bump the timeout on AgentForward test.

Updates #4653.
a-palchikov added a commit that referenced this issue Nov 5, 2020
@a-palchikov
Fix a data race in the locking test.
bc73d6c 
Bump the timeout on AgentForward test.

Updates #4653.
a-palchikov added a commit that referenced this issue Nov 11, 2020
@a-palchikov
Fix a data race in the locking test.
5a888c7 
Bump the timeout on AgentForward test.

Updates #4653.
a-palchikov added a commit that referenced this issue Nov 11, 2020
@a-palchikov
Fix a data race in the locking test.
c8f9c0a 
Bump the timeout on AgentForward test.

Updates #4653.
a-palchikov added a commit that referenced this issue Nov 16, 2020
@a-palchikov
Fix a data race in the locking test.
5e8c7c0 
Bump the timeout on AgentForward test.

Updates #4653.
a-palchikov added a commit that referenced this issue Nov 25, 2020
@a-palchikov
Fix a data race in the locking test.
3863de9 
Bump the timeout on AgentForward test.

Updates #4653.
a-palchikov added a commit that referenced this issue Dec 1, 2020
@a-palchikov
Fix a data race in the locking test.
674c56e 
Bump the timeout on AgentForward test.

Updates #4653.
a-palchikov added a commit that referenced this issue Dec 2, 2020
@a-palchikov
Fix a data race in the locking test.
8e34486 
Bump the timeout on AgentForward test.

Updates #4653.
a-palchikov added a commit that referenced this issue Dec 7, 2020
@a-palchikov
Fix a data race in the locking test.
f1a05ed 
Bump the timeout on AgentForward test.

Updates #4653.
a-palchikov added a commit that referenced this issue Dec 8, 2020
@a-palchikov
Fix a data race in the locking test.
cb5459f 
Bump the timeout on AgentForward test.

Updates #4653.
@a-palchikov a-palchikov mentioned this issue Dec 8, 2020
Merged
a-palchikov added a commit that referenced this issue Dec 17, 2020
@a-palchikov
Fix a data race in the locking test.
777f6c2 
Bump the timeout on AgentForward test.

Updates #4653.
a-palchikov added a commit that referenced this issue Dec 18, 2020
@a-palchikov
Fix a data race in the locking test.
199b3fa 
Bump the timeout on AgentForward test.

Updates #4653.
a-palchikov added a commit that referenced this issue Jan 15, 2021
@a-palchikov
Fix a data race in the locking test.
caa695e 
Bump the timeout on AgentForward test.

Updates #4653.
@a-palchikov a-palchikov mentioned this issue Jan 18, 2021
Closed
@zmb3 zmb3 mentioned this issue Dec 21, 2021
Closed
@zmb3 zmb3 mentioned this issue Dec 28, 2021
Closed
@strideynet
Copy link
Contributor

Closed in favour of #9492

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@webvictim @a-palchikov @strideynet