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

net: data race in TestListenCloseListen #65209

Closed
gopherbot opened this issue Jan 22, 2024 · 12 comments
Closed

net: data race in TestListenCloseListen #65209

gopherbot opened this issue Jan 22, 2024 · 12 comments
Assignees
@bcmills
Labels
FixPending Issues that have a fix which has not yet been reviewed or submitted. NeedsFix The path to resolution is known, but the work has not been done. Soon This needs to be done soon. (regressions, serious bugs, outages)
Milestone
Go1.23

Comments

@gopherbot
Copy link

gopherbot commented Jan 22, 2024 •
edited by bcmills 

#!watchflakes
post <- pkg == "net" && (log ~ `WARNING: DATA RACE` || log ~ `race detected during execution of test`) && log ~ `TestListenCloseListen` && date < "2024-01-23"

Issue created automatically to collect these failures.

Example (log):

--- FAIL: TestCloseRead (0.00s)
    --- FAIL: TestCloseRead/tcp (0.00s)
        testing.go:1398: race detected during execution of test

— watchflakes
@gopherbot gopherbot added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jan 22, 2024
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
default <- pkg == "net" && test == "TestCloseRead"
2024-01-22 16:54 linux-arm64-race go@4ca1caf4 net.TestCloseRead (log) 
--- FAIL: TestCloseRead (0.00s)
    --- FAIL: TestCloseRead/tcp (0.00s)
        testing.go:1398: race detected during execution of test

— watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net" && log ~ `WARNING: DATA RACE` && log ~ `\s+net\.TestListenCloseListen`
2024-01-22 16:30 windows-amd64-race go@41c05ea4 net.TestListenCloseListen (log) 
==================
WARNING: DATA RACE
Write at 0x00c0000248c0 by goroutine 409:
  net.TestListenCloseListen()
      C:/workdir/go/src/net/net_test.go:357 +0x644
  testing.tRunner()
      C:/workdir/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      C:/workdir/go/src/testing/testing.go:1742 +0x44

...
Goroutine 1510 (finished) created at:
  net.TestListenCloseListen()
      C:/workdir/go/src/net/net_test.go:307 +0x29e
  testing.tRunner()
      C:/workdir/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      C:/workdir/go/src/testing/testing.go:1742 +0x44
==================
--- FAIL: TestListenCloseListen (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 16:30 windows-amd64-race go@41c05ea4 net.TestDialTimeout (log) 
--- FAIL: TestDialTimeout (0.01s)
    --- FAIL: TestDialTimeout/0s/-5s (0.00s)
        testing.go:1398: race detected during execution of test
2024-01-22 16:30 windows-amd64-race go@41c05ea4 net.TestWriteTimeout (log) 
--- FAIL: TestWriteTimeout (0.01s)
    testing.go:1398: race detected during execution of test
2024-01-22 16:50 windows-amd64-race go@846bb475 net.TestListenCloseListen (log) 
==================
WARNING: DATA RACE
Write at 0x00c000598b40 by goroutine 408:
  net.TestListenCloseListen()
      C:/workdir/go/src/net/net_test.go:357 +0x644
  testing.tRunner()
      C:/workdir/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      C:/workdir/go/src/testing/testing.go:1742 +0x44

...
Goroutine 1539 (finished) created at:
  net.TestListenCloseListen()
      C:/workdir/go/src/net/net_test.go:307 +0x29e
  testing.tRunner()
      C:/workdir/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      C:/workdir/go/src/testing/testing.go:1742 +0x44
==================
--- FAIL: TestListenCloseListen (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 16:50 windows-amd64-race go@846bb475 net.TestPacketConnClose (log) 
--- FAIL: TestPacketConnClose (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 16:50 windows-amd64-race go@846bb475 net.TestListenerClose (log) 
--- FAIL: TestListenerClose (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 17:00 linux-amd64-race go@558919b4 net.TestListenCloseListen (log) 
2024/01/22 17:12:04 killing splice client after 5 second shutdown timeout
==================
WARNING: DATA RACE
Write at 0x00c000694200 by goroutine 864:
  net.TestListenCloseListen()
      /workdir/go/src/net/net_test.go:357 +0x644
  testing.tRunner()
      /workdir/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /workdir/go/src/testing/testing.go:1742 +0x44
...
Goroutine 2285 (finished) created at:
  net.TestListenCloseListen()
      /workdir/go/src/net/net_test.go:307 +0x29e
  testing.tRunner()
      /workdir/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /workdir/go/src/testing/testing.go:1742 +0x44
==================
--- FAIL: TestListenCloseListen (0.01s)
    testing.go:1398: race detected during execution of test
2024-01-22 17:00 linux-amd64-race go@558919b4 net.TestReadWriteDeadlineRace (log) 
--- FAIL: TestReadWriteDeadlineRace (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 17:00 linux-amd64-race go@558919b4 net.TestParseNSSConf (log) 
--- FAIL: TestParseNSSConf (0.01s)
    testing.go:1398: race detected during execution of test

— watchflakes

@bcmills bcmills changed the title net: TestCloseRead failures net: data race in TestListenCloseListen Jan 22, 2024
This was referenced Jan 22, 2024
Closed
Closed
Closed
Closed
@bcmills bcmills self-assigned this Jan 22, 2024
@bcmills bcmills added the Soon This needs to be done soon. (regressions, serious bugs, outages) label Jan 22, 2024
@bcmills bcmills added this to the Go1.23 milestone Jan 22, 2024
@bcmills bcmills added the NeedsFix The path to resolution is known, but the work has not been done. label Jan 22, 2024
@gopherbot gopherbot removed the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jan 22, 2024
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net" && log ~ `WARNING: DATA RACE` && log ~ `\s+net\.TestListenCloseListen`
2024-01-22 17:00 windows-amd64-race go@558919b4 net.TestWriteTimeout (log) 
==================
WARNING: DATA RACE
Write at 0x00c000374a10 by goroutine 406:
  net.TestListenCloseListen()
      C:/workdir/go/src/net/net_test.go:357 +0x644
  testing.tRunner()
      C:/workdir/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      C:/workdir/go/src/testing/testing.go:1742 +0x44

...
Goroutine 1530 (finished) created at:
  net.TestListenCloseListen()
      C:/workdir/go/src/net/net_test.go:307 +0x29e
  testing.tRunner()
      C:/workdir/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      C:/workdir/go/src/testing/testing.go:1742 +0x44
==================
--- FAIL: TestWriteTimeout (0.01s)
    testing.go:1398: race detected during execution of test
2024-01-22 17:00 windows-amd64-race go@558919b4 net.TestListenCloseListen (log) 
--- FAIL: TestListenCloseListen (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 17:00 windows-amd64-race go@558919b4 net.TestWriteToTimeout (log) 
--- FAIL: TestWriteToTimeout (0.02s)
    --- FAIL: TestWriteToTimeout/10ms (0.01s)
        timeout_test.go:633: #0: WriteTo: 20, <nil>
        timeout_test.go:637: WriteTo succeeded; sleeping 3.333333ms
        timeout_test.go:633: #1: WriteTo: 20, <nil>
        timeout_test.go:637: WriteTo succeeded; sleeping 3.333333ms
        timeout_test.go:633: #2: WriteTo: 20, <nil>
        timeout_test.go:637: WriteTo succeeded; sleeping 3.333333ms
        timeout_test.go:633: #3: WriteTo: 0, write udp 127.0.0.1:61238->127.0.0.1:61236: i/o timeout
        testing.go:1398: race detected during execution of test
        timeout_test.go:633: #4: WriteTo: 0, write udp 127.0.0.1:61238->127.0.0.1:61236: i/o timeout

— watchflakes

@gopherbot
Copy link
Author

Change https://go.dev/cl/557536 mentions this issue: net: delete TestListenCloseListen

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net" && log ~ `WARNING: DATA RACE` && log ~ `\s+net\.TestListenCloseListen`
2024-01-22 17:32 linux-s390x-ibm-race go@b16a1e3a net.TestWriteToTimeout (log) 
2024/01/22 12:46:14 killing splice client after 5 second shutdown timeout
==================
WARNING: DATA RACE
Write at 0x00c0001461e0 by goroutine 842:
  net.TestListenCloseListen()
      /data/golang/workdir/go/src/net/net_test.go:357 +0x7bf
  testing.tRunner()
      /data/golang/workdir/go/src/testing/testing.go:1689 +0x255
  testing.(*T).Run.gowrap1()
      /data/golang/workdir/go/src/testing/testing.go:1742 +0x8d
...
--- FAIL: TestWriteToTimeout (0.03s)
    --- FAIL: TestWriteToTimeout/10ms (0.01s)
        timeout_test.go:633: #0: WriteTo: 20, <nil>
        timeout_test.go:637: WriteTo succeeded; sleeping 3.333333ms
        timeout_test.go:633: #1: WriteTo: 20, <nil>
        timeout_test.go:637: WriteTo succeeded; sleeping 3.333333ms
        timeout_test.go:633: #2: WriteTo: 20, <nil>
        timeout_test.go:637: WriteTo succeeded; sleeping 3.333333ms
        timeout_test.go:633: #3: WriteTo: 0, write udp 127.0.0.1:50250->127.0.0.1:43360: i/o timeout
        testing.go:1398: race detected during execution of test
        timeout_test.go:633: #4: WriteTo: 0, write udp 127.0.0.1:50250->127.0.0.1:43360: i/o timeout
2024-01-22 17:32 linux-s390x-ibm-race go@b16a1e3a net.TestListenCloseListen (log) 
--- FAIL: TestListenCloseListen (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 17:32 linux-s390x-ibm-race go@b16a1e3a net.TestZeroByteRead (log) 
--- FAIL: TestZeroByteRead (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 18:07 linux-arm64-race go@d29980cd net.TestPacketConnClose (log) 
2024/01/22 18:16:37 killing splice client after 5 second shutdown timeout
==================
WARNING: DATA RACE
Write at 0x00c00009e390 by goroutine 818:
  net.TestListenCloseListen()
      /tmp/workdir/go/src/net/net_test.go:357 +0x4a0
  testing.tRunner()
      /tmp/workdir/go/src/testing/testing.go:1689 +0x180
  testing.(*T).Run.gowrap1()
      /tmp/workdir/go/src/testing/testing.go:1742 +0x40
...
  testing.tRunner()
      /tmp/workdir/go/src/testing/testing.go:1689 +0x180
  testing.(*T).Run.gowrap1()
      /tmp/workdir/go/src/testing/testing.go:1742 +0x40
==================
--- FAIL: TestPacketConnClose (0.00s)
    --- FAIL: TestPacketConnClose/udp (0.00s)
        testing.go:1398: race detected during execution of test
    --- FAIL: TestPacketConnClose/unixgram (0.00s)
        testing.go:1398: race detected during execution of test
2024-01-22 18:07 linux-arm64-race go@d29980cd net.TestListenCloseListen (log) 
--- FAIL: TestListenCloseListen (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 18:07 linux-arm64-race go@d29980cd net.TestParseNSSConf (log) 
--- FAIL: TestParseNSSConf (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 18:07 linux-s390x-ibm-race go@d29980cd net.TestListenCloseListen (log) 
2024/01/22 13:30:55 killing splice client after 5 second shutdown timeout
==================
WARNING: DATA RACE
Write at 0x00c000022b20 by goroutine 847:
  net.TestListenCloseListen()
      /data/golang/workdir/go/src/net/net_test.go:357 +0x7bf
  testing.tRunner()
      /data/golang/workdir/go/src/testing/testing.go:1689 +0x255
  testing.(*T).Run.gowrap1()
      /data/golang/workdir/go/src/testing/testing.go:1742 +0x8d
...
Goroutine 2237 (finished) created at:
  net.TestListenCloseListen()
      /data/golang/workdir/go/src/net/net_test.go:307 +0x381
  testing.tRunner()
      /data/golang/workdir/go/src/testing/testing.go:1689 +0x255
  testing.(*T).Run.gowrap1()
      /data/golang/workdir/go/src/testing/testing.go:1742 +0x8d
==================
--- FAIL: TestListenCloseListen (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 18:07 linux-s390x-ibm-race go@d29980cd net.TestReadWriteDeadlineRace (log) 
--- FAIL: TestReadWriteDeadlineRace (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 18:07 linux-s390x-ibm-race go@d29980cd net.TestCloseRead (log) 
--- FAIL: TestCloseRead (0.00s)
    testing.go:1398: race detected during execution of test

— watchflakes

@bcmills bcmills added the FixPending Issues that have a fix which has not yet been reviewed or submitted. label Jan 22, 2024
@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net" && log ~ `WARNING: DATA RACE` && log ~ `\s+net\.TestListenCloseListen`
2024-01-22 19:00 freebsd-amd64-race go@3e54329c net.TestListenCloseListen (log) 
==================
WARNING: DATA RACE
Write at 0x00c00007a930 by goroutine 969:
  net.TestListenCloseListen()
      /tmp/workdir/go/src/net/net_test.go:357 +0x644
  testing.tRunner()
      /tmp/workdir/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /tmp/workdir/go/src/testing/testing.go:1742 +0x44

...
Goroutine 2236 (finished) created at:
  net.TestListenCloseListen()
      /tmp/workdir/go/src/net/net_test.go:307 +0x29e
  testing.tRunner()
      /tmp/workdir/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /tmp/workdir/go/src/testing/testing.go:1742 +0x44
==================
--- FAIL: TestListenCloseListen (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 19:00 freebsd-amd64-race go@3e54329c net.TestAcceptTimeoutMustReturn (log) 
--- FAIL: TestAcceptTimeoutMustReturn (0.01s)
    testing.go:1398: race detected during execution of test
2024-01-22 19:00 freebsd-amd64-race go@3e54329c net.TestWriteToTimeout (log) 
--- FAIL: TestWriteToTimeout (0.01s)
    --- FAIL: TestWriteToTimeout/10ms (0.01s)
        timeout_test.go:633: #0: WriteTo: 20, <nil>
        timeout_test.go:637: WriteTo succeeded; sleeping 3.333333ms
        timeout_test.go:633: #1: WriteTo: 20, <nil>
        timeout_test.go:637: WriteTo succeeded; sleeping 3.333333ms
        timeout_test.go:633: #2: WriteTo: 20, <nil>
        timeout_test.go:637: WriteTo succeeded; sleeping 3.333333ms
        timeout_test.go:633: #3: WriteTo: 0, write udp 127.0.0.1:56043->127.0.0.1:28547: i/o timeout
        testing.go:1398: race detected during execution of test
        timeout_test.go:633: #4: WriteTo: 0, write udp 127.0.0.1:56043->127.0.0.1:28547: i/o timeout

— watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net" && log ~ `WARNING: DATA RACE` && log ~ `\s+net\.TestListenCloseListen`
2024-01-22 19:00 darwin-amd64-race go@3e54329c net.TestListenCloseListen (log) 
==================
WARNING: DATA RACE
Write at 0x00c00009a340 by goroutine 930:
  net.TestListenCloseListen()
      /tmp/buildlet/go/src/net/net_test.go:357 +0x644
  testing.tRunner()
      /tmp/buildlet/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /tmp/buildlet/go/src/testing/testing.go:1742 +0x44

...
Goroutine 2172 (finished) created at:
  net.TestListenCloseListen()
      /tmp/buildlet/go/src/net/net_test.go:307 +0x29e
  testing.tRunner()
      /tmp/buildlet/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /tmp/buildlet/go/src/testing/testing.go:1742 +0x44
==================
--- FAIL: TestListenCloseListen (0.01s)
    testing.go:1398: race detected during execution of test
2024-01-22 19:00 darwin-amd64-race go@3e54329c net.TestDialTimeout (log) 
--- FAIL: TestDialTimeout (0.02s)
    --- FAIL: TestDialTimeout/1ms/0s (0.01s)
        timeout_test.go:104: closing spurious connection from Dial
        timeout_test.go:116: reducing Timeout to 500µs
        timeout_test.go:104: closing spurious connection from Dial
        timeout_test.go:116: reducing Timeout to 250µs
        testing.go:1398: race detected during execution of test
2024-01-22 19:00 darwin-amd64-race go@3e54329c net.TestReadWriteProlongedTimeout (log) 
--- FAIL: TestReadWriteProlongedTimeout (0.03s)
    testing.go:1398: race detected during execution of test

— watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net" && log ~ `WARNING: DATA RACE` && log ~ `\s+net\.TestListenCloseListen`
2024-01-22 20:28 linux-s390x-ibm-race go@e5eeadb2 net.TestListenCloseListen (log) 
2024/01/22 15:43:10 killing splice client after 5 second shutdown timeout
==================
WARNING: DATA RACE
Write at 0x00c0005a82a0 by goroutine 845:
  net.TestListenCloseListen()
      /data/golang/workdir/go/src/net/net_test.go:357 +0x7bf
  testing.tRunner()
      /data/golang/workdir/go/src/testing/testing.go:1689 +0x255
  testing.(*T).Run.gowrap1()
      /data/golang/workdir/go/src/testing/testing.go:1742 +0x8d
...
Goroutine 2304 (finished) created at:
  net.TestListenCloseListen()
      /data/golang/workdir/go/src/net/net_test.go:307 +0x381
  testing.tRunner()
      /data/golang/workdir/go/src/testing/testing.go:1689 +0x255
  testing.(*T).Run.gowrap1()
      /data/golang/workdir/go/src/testing/testing.go:1742 +0x8d
==================
--- FAIL: TestListenCloseListen (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 20:28 linux-s390x-ibm-race go@e5eeadb2 net.TestZeroByteRead (log) 
--- FAIL: TestZeroByteRead (0.00s)
    --- FAIL: TestZeroByteRead/unixpacket (0.00s)
        testing.go:1398: race detected during execution of test
    --- FAIL: TestZeroByteRead/unix (0.00s)
        testing.go:1398: race detected during execution of test
2024-01-22 20:28 linux-s390x-ibm-race go@e5eeadb2 net.TestConnClose (log) 
--- FAIL: TestConnClose (0.00s)
    testing.go:1398: race detected during execution of test

— watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net" && log ~ `WARNING: DATA RACE` && log ~ `\s+net\.TestListenCloseListen`
2024-01-22 20:28 darwin-amd64-race go@e5eeadb2 net.TestListenCloseListen (log) 
==================
WARNING: DATA RACE
Write at 0x00c000260320 by goroutine 931:
  net.TestListenCloseListen()
      /tmp/buildlet/go/src/net/net_test.go:357 +0x644
  testing.tRunner()
      /tmp/buildlet/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /tmp/buildlet/go/src/testing/testing.go:1742 +0x44

...
Goroutine 2166 (finished) created at:
  net.TestListenCloseListen()
      /tmp/buildlet/go/src/net/net_test.go:307 +0x29e
  testing.tRunner()
      /tmp/buildlet/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /tmp/buildlet/go/src/testing/testing.go:1742 +0x44
==================
--- FAIL: TestListenCloseListen (0.01s)
    testing.go:1398: race detected during execution of test
2024-01-22 20:28 darwin-amd64-race go@e5eeadb2 net.TestCloseUnblocksRead (log) 
--- FAIL: TestCloseUnblocksRead (0.02s)
    testing.go:1398: race detected during execution of test
2024-01-22 20:28 darwin-amd64-race go@e5eeadb2 net.TestWriteTimeout (log) 
--- FAIL: TestWriteTimeout (0.02s)
    testing.go:1398: race detected during execution of test

— watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net" && (log ~ `WARNING: DATA RACE` || log ~ `race detected during execution of test`) && log ~ `TestListenCloseListen`
2024-01-22 16:54 linux-s390x-ibm-race go@29cea658 net.TestListenCloseListen (log) 
2024/01/23 04:40:51 killing splice client after 5 second shutdown timeout
==================
WARNING: DATA RACE
Write at 0x00c0001206e0 by goroutine 844:
  net.TestListenCloseListen()
      /data/golang/workdir/go/src/net/net_test.go:357 +0x7bf
  testing.tRunner()
      /data/golang/workdir/go/src/testing/testing.go:1689 +0x255
  testing.(*T).Run.gowrap1()
      /data/golang/workdir/go/src/testing/testing.go:1742 +0x8d
...
Goroutine 2268 (finished) created at:
  net.TestListenCloseListen()
      /data/golang/workdir/go/src/net/net_test.go:307 +0x381
  testing.tRunner()
      /data/golang/workdir/go/src/testing/testing.go:1689 +0x255
  testing.(*T).Run.gowrap1()
      /data/golang/workdir/go/src/testing/testing.go:1742 +0x8d
==================
--- FAIL: TestListenCloseListen (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 16:54 linux-s390x-ibm-race go@29cea658 net.TestReadWriteDeadlineRace (log) 
--- FAIL: TestReadWriteDeadlineRace (0.00s)
    testing.go:1398: race detected during execution of test
2024-01-22 16:54 linux-s390x-ibm-race go@29cea658 net.TestNotTemporaryRead (log) 
--- FAIL: TestNotTemporaryRead (0.00s)
    testing.go:1398: race detected during execution of test

— watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net" && (log ~ `WARNING: DATA RACE` || log ~ `race detected during execution of test`) && log ~ `TestListenCloseListen` && date < "2024-01-23"
2023-12-30 00:23 gotip-linux-amd64-longtest go@3233542e net.TestLookupDotsWithRemoteSource (log) 
=== RUN   TestLookupDotsWithRemoteSource
    lookup_test.go:664: LookupAddr(8.8.8.8): lookup 8.8.8.8.in-addr.arpa. on 169.254.169.254:53: server misbehaving (mode=go)
    lookup_test.go:664: LookupAddr(8.8.8.8): lookup 8.8.8.8: Temporary failure in name resolution (mode=cgo)
--- FAIL: TestLookupDotsWithRemoteSource (0.60s)
2023-12-30 00:23 gotip-linux-amd64-longtest-race go@3233542e net.TestLookupDotsWithRemoteSource (log) 
=== RUN   TestLookupDotsWithRemoteSource
    lookup_test.go:664: LookupAddr(8.8.8.8): lookup 8.8.8.8.in-addr.arpa. on 169.254.169.254:53: server misbehaving (mode=go)
    lookup_test.go:664: LookupAddr(8.8.8.8): lookup 8.8.8.8: Temporary failure in name resolution (mode=cgo)
--- FAIL: TestLookupDotsWithRemoteSource (0.63s)
2023-12-30 00:23 gotip-windows-amd64-longtest go@3233542e net.TestLookupDotsWithRemoteSource (log) 
=== RUN   TestLookupDotsWithRemoteSource
    lookup_test.go:664: LookupAddr(8.8.8.8): lookup 8.8.8.8.in-addr.arpa. on 10.128.0.1:53: server misbehaving (mode=go)
    lookup_test.go:664: LookupAddr(8.8.8.8): lookup 8.8.8.8: dnsquery: DNS server failure. (mode=cgo)
--- FAIL: TestLookupDotsWithRemoteSource (0.58s)
2023-12-30 00:24 gotip-linux-amd64-longtest go@b25f5558 net.TestLookupDotsWithRemoteSource (log) 
=== RUN   TestLookupDotsWithRemoteSource
    lookup_test.go:664: LookupAddr(8.8.8.8): lookup 8.8.8.8.in-addr.arpa. on 169.254.169.254:53: server misbehaving (mode=go)
    lookup_test.go:664: LookupAddr(8.8.8.8): lookup 8.8.8.8: Temporary failure in name resolution (mode=cgo)
--- FAIL: TestLookupDotsWithRemoteSource (0.59s)
2023-12-30 00:24 gotip-linux-amd64-longtest-race go@b25f5558 net.TestLookupDotsWithRemoteSource (log) 
=== RUN   TestLookupDotsWithRemoteSource
    lookup_test.go:664: LookupAddr(8.8.8.8): lookup 8.8.8.8.in-addr.arpa. on 169.254.169.254:53: server misbehaving (mode=go)
    lookup_test.go:664: LookupAddr(8.8.8.8): lookup 8.8.8.8: Temporary failure in name resolution (mode=cgo)
--- FAIL: TestLookupDotsWithRemoteSource (0.66s)
2023-12-30 00:24 gotip-windows-amd64-longtest go@b25f5558 net.TestLookupDotsWithRemoteSource (log) 
=== RUN   TestLookupDotsWithRemoteSource
    lookup_test.go:664: LookupAddr(8.8.8.8): lookup 8.8.8.8.in-addr.arpa. on 10.128.0.1:53: server misbehaving (mode=go)
    lookup_test.go:664: LookupAddr(8.8.8.8): lookup 8.8.8.8: dnsquery: DNS server failure. (mode=cgo)
--- FAIL: TestLookupDotsWithRemoteSource (0.63s)
2024-01-22 16:50 gotip-linux-amd64-race go@846bb475 net.TestVariousDeadlines (log) 
=== RUN   TestVariousDeadlines
=== PAUSE TestVariousDeadlines
=== CONT  TestVariousDeadlines
    timeout_test.go:988: 1ns 0/1
==================
WARNING: DATA RACE
Write at 0x00c00040c8d0 by goroutine 827:
  net.TestListenCloseListen()
      /home/swarming/.swarming/w/ir/x/w/goroot/src/net/net_test.go:357 +0x644
  testing.tRunner()
...
    timeout_test.go:988: 5µs 0/1
    timeout_test.go:1004: 5µs 0/1: good timeout after 31.508µs; 0 bytes
    timeout_test.go:988: 25µs 0/1
    timeout_test.go:1004: 25µs 0/1: good timeout after 36.428µs; 0 bytes
    timeout_test.go:988: 250µs 0/1
    timeout_test.go:1004: 250µs 0/1: good timeout after 376.188µs; 0 bytes
    timeout_test.go:988: 500µs 0/1
    timeout_test.go:1004: 500µs 0/1: good timeout after 543.535µs; 0 bytes
    testing.go:1398: race detected during execution of test
--- FAIL: TestVariousDeadlines (0.01s)
2024-01-22 16:50 gotip-windows-amd64-race go@846bb475 net.TestVariousDeadlines (log) 
=== RUN   TestVariousDeadlines
=== PAUSE TestVariousDeadlines
=== CONT  TestVariousDeadlines
    timeout_test.go:988: 1ns 0/1
==================
WARNING: DATA RACE
Write at 0x00c000088d50 by goroutine 418:
  net.TestListenCloseListen()
      C:/b/s/w/ir/x/w/goroot/src/net/net_test.go:357 +0x644
  testing.tRunner()
...
    timeout_test.go:988: 5µs 0/1
    timeout_test.go:1004: 5µs 0/1: good timeout after 512.2µs; 0 bytes
    timeout_test.go:988: 25µs 0/1
    timeout_test.go:1004: 25µs 0/1: good timeout after 1.0273ms; 0 bytes
    timeout_test.go:988: 250µs 0/1
    timeout_test.go:1004: 250µs 0/1: good timeout after 824.5µs; 0 bytes
    timeout_test.go:988: 500µs 0/1
    timeout_test.go:1004: 500µs 0/1: good timeout after 3.4297ms; 0 bytes
    testing.go:1398: race detected during execution of test
--- FAIL: TestVariousDeadlines (0.03s)
2024-01-22 16:54 gotip-linux-amd64-race go@29cea658 net.TestVariousDeadlines (log) 
=== RUN   TestVariousDeadlines
=== PAUSE TestVariousDeadlines
=== CONT  TestVariousDeadlines
    timeout_test.go:988: 1ns 0/1
    timeout_test.go:1004: 1ns 0/1: good timeout after 43.905µs; 0 bytes
    timeout_test.go:988: 2ns 0/1
    timeout_test.go:1004: 2ns 0/1: good timeout after 32.218µs; 0 bytes
    timeout_test.go:988: 5ns 0/1
    timeout_test.go:1004: 5ns 0/1: good timeout after 79.459µs; 0 bytes
    timeout_test.go:988: 50ns 0/1
...
    timeout_test.go:988: 5µs 0/1
    timeout_test.go:1004: 5µs 0/1: good timeout after 58.017µs; 0 bytes
    timeout_test.go:988: 25µs 0/1
    timeout_test.go:1004: 25µs 0/1: good timeout after 67.498µs; 0 bytes
    timeout_test.go:988: 250µs 0/1
    timeout_test.go:1004: 250µs 0/1: good timeout after 313.348µs; 0 bytes
    timeout_test.go:988: 500µs 0/1
    timeout_test.go:1004: 500µs 0/1: good timeout after 526.851µs; 0 bytes
    testing.go:1398: race detected during execution of test
--- FAIL: TestVariousDeadlines (0.01s)
2024-01-22 17:28 gotip-linux-amd64-race go@b3cfb24f net.TestVariousDeadlines (log) 
=== RUN   TestVariousDeadlines
=== PAUSE TestVariousDeadlines
=== CONT  TestVariousDeadlines
    timeout_test.go:988: 1ns 0/1
    timeout_test.go:1004: 1ns 0/1: good timeout after 35.526µs; 0 bytes
    timeout_test.go:988: 2ns 0/1
    timeout_test.go:1004: 2ns 0/1: good timeout after 36.466µs; 0 bytes
    timeout_test.go:988: 5ns 0/1
    timeout_test.go:1004: 5ns 0/1: good timeout after 46.91µs; 0 bytes
    timeout_test.go:988: 50ns 0/1
...
    timeout_test.go:988: 5µs 0/1
    timeout_test.go:1004: 5µs 0/1: good timeout after 85.446µs; 0 bytes
    timeout_test.go:988: 25µs 0/1
    timeout_test.go:1004: 25µs 0/1: good timeout after 58.712µs; 0 bytes
    timeout_test.go:988: 250µs 0/1
    timeout_test.go:1004: 250µs 0/1: good timeout after 270.541µs; 0 bytes
    timeout_test.go:988: 500µs 0/1
    timeout_test.go:1004: 500µs 0/1: good timeout after 525.079µs; 0 bytes
    testing.go:1398: race detected during execution of test
--- FAIL: TestVariousDeadlines (0.02s)
2024-01-22 18:07 gotip-linux-amd64-race go@d29980cd net.TestVariousDeadlines (log) 
=== RUN   TestVariousDeadlines
=== PAUSE TestVariousDeadlines
=== CONT  TestVariousDeadlines
    timeout_test.go:988: 1ns 0/1
    timeout_test.go:1004: 1ns 0/1: good timeout after 51.192µs; 0 bytes
    timeout_test.go:988: 2ns 0/1
    timeout_test.go:1004: 2ns 0/1: good timeout after 15.32µs; 0 bytes
    timeout_test.go:988: 5ns 0/1
    timeout_test.go:1004: 5ns 0/1: good timeout after 13.886µs; 0 bytes
    timeout_test.go:988: 50ns 0/1
...
    timeout_test.go:988: 5µs 0/1
    timeout_test.go:1004: 5µs 0/1: good timeout after 17.999µs; 0 bytes
    timeout_test.go:988: 25µs 0/1
    timeout_test.go:1004: 25µs 0/1: good timeout after 54.814µs; 0 bytes
    timeout_test.go:988: 250µs 0/1
    timeout_test.go:1004: 250µs 0/1: good timeout after 472.949µs; 0 bytes
    timeout_test.go:988: 500µs 0/1
    timeout_test.go:1004: 500µs 0/1: good timeout after 552.709µs; 0 bytes
    testing.go:1398: race detected during execution of test
--- FAIL: TestVariousDeadlines (0.01s)
2024-01-22 19:00 gotip-linux-amd64-race go@3e54329c net.TestEndlessWrite (log) 
=== RUN   TestEndlessWrite
=== PAUSE TestEndlessWrite
=== CONT  TestEndlessWrite
    write_unix_test.go:55: client WaitWrite: i/o timeout
    testing.go:1398: race detected during execution of test
--- FAIL: TestEndlessWrite (0.02s)
2024-01-22 20:28 gotip-linux-amd64-race go@e5eeadb2 net.TestCloseUnblocksRead (log) 
=== RUN   TestCloseUnblocksRead
=== PAUSE TestCloseUnblocksRead
=== CONT  TestCloseUnblocksRead
    testing.go:1398: race detected during execution of test
--- FAIL: TestCloseUnblocksRead (0.02s)

— watchflakes

@gopherbot
Copy link
Author

Found new dashboard test flakes for:

#!watchflakes
post <- pkg == "net" && (log ~ `WARNING: DATA RACE` || log ~ `race detected during execution of test`) && log ~ `TestListenCloseListen` && date < "2024-01-23"
2024-01-09 18:15 go1.20-windows-amd64-longtest release-branch.go1.20@a95136a8 net.TestLookupLocalPTR (log) 
=== RUN   TestLookupLocalPTR
    lookup_windows_test.go:148: failed to get local ip: dial udp: lookup golang.org: getaddrinfow: This is usually a temporary error during hostname resolution and means that the local server did not receive a response from an authoritative server.
    lookup_windows_test.go:152: failed <nil>: lookup <nil>: unrecognized address
    lookup_windows_test.go:155: no results
    lookup_windows_test.go:159: skipping failed lookup <nil> test: exit status 1: Ping request could not find host <nil>. Please check the name and try again.
--- FAIL: TestLookupLocalPTR (0.06s)

— watchflakes

ezz-no pushed a commit to ezz-no/go-ezzno that referenced this issue Feb 18, 2024
@ezz-no
net: delete TestListenCloseListen
01c58b7 
In CL 557177, I attempted to fix a logical race in this test (golang#65175).
However, I introduced a data race in the process (golang#65209).

The race was reported on the windows-amd64-race builder. When I tried
to reproduce it on linux/amd64, I added a time.Sleep in the Accept
loop. However, that Sleep causes the test to fail outright with
EADDRINUSE, which suggests that my earlier guess about the open Conn
preventing reuse of the port was, in fact, incorrect.

On some platforms we could instead use SO_REUSEPORT and avoid closing
the first Listener entirely, but that wouldn't be even remotely in the
spirit of the original test.

Since I don't see a way to preserve the test in a way that is not
inherently flaky / racy, I suggest that we just delete it. It was
originally added as a regression test for a bug in the nacl port,
which no longer exists anyway. (Some of that code may live on in the
wasm port, but it doesn't seem worth maintaining a flaky
port-independent test to maintain a regression test for a bug specific
to secondary platforms.)

Fixes golang#65209.
Updates golang#65175.

Change-Id: I32f9da779d24f2e133571f0971ec460cebe7820a
Cq-Include-Trybots: luci.golang.try:gotip-windows-amd64-race
Reviewed-on: https://go-review.googlesource.com/c/go/+/557536
Run-TryBot: Bryan Mills <bcmills@google.com>
Auto-Submit: Bryan Mills <bcmills@google.com>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Reviewed-by: Jonathan Amsterdam <jba@google.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@bcmills bcmills

Labels
FixPending Issues that have a fix which has not yet been reviewed or submitted. NeedsFix The path to resolution is known, but the work has not been done. Soon This needs to be done soon. (regressions, serious bugs, outages)
Projects
Test Flakes
Status: Done
Milestone
Go1.23
Development

No branches or pull requests
2 participants
@bcmills @gopherbot