You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tinkerpop.apache.org by "Cole Greer (Jira)" <ji...@apache.org> on 2023/03/13 19:26:00 UTC
[jira] [Commented] (TINKERPOP-2845) Race conditions in Go GLV
[ https://issues.apache.org/jira/browse/TINKERPOP-2845?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17699808#comment-17699808 ]
Cole Greer commented on TINKERPOP-2845:
---------------------------------------
Additional race conditions have been reported on the [tinkerpop discord|[https://discord.com/channels/838910279550238720/894915500709117972/1084907998536794132].]
{panel}
DriverRemoteConnection.CreateSession (and session.Close()) and especially in the external i18n library used for logging (weird spot) which become apparent if you're doing any kind of parallel work... luckily they can be worked around by having a mutex protect your library accesses and if you to call Iterate() in parallel, setting log verbosity to Off (unfortunately)
{panel}
> Race conditions in Go GLV
> -------------------------
>
> Key: TINKERPOP-2845
> URL: https://issues.apache.org/jira/browse/TINKERPOP-2845
> Project: TinkerPop
> Issue Type: Bug
> Components: go
> Affects Versions: 3.7.0
> Reporter: Cole Greer
> Priority: Major
>
> While working on writing tests for the Go GLV using [gremlin-socket-server|https://issues.apache.org/jira/browse/TINKERPOP-2819], 2 possible race conditions were detected by go test -race. The provided test code I will include is relying on configuration and docker setup which has not yet been merged to tinkerpop and is being included for reference only. I will update this ticket once the relevant supporting code is included in Tinkerpop and these tests can be run.
>
> Race condition 1:
> {code:java}
> func TestClientAgainstSocketServer(t *testing.T) {
> // Integration test variables.
> testNoAuthEnable := getEnvOrDefaultBool("RUN_INTEGRATION_TESTS", true)
> settings := FromYaml(getEnvOrDefaultString("GREMLIN_SOCKET_SERVER_CONFIG_PATH", "../../gremlin-tools/gremlin-socket-server/conf/test-ws-gremlin.yaml"))
> testSocketServerUrl := getEnvOrDefaultString("GREMLIN_SOCKET_SERVER_URL", "ws://localhost")
> testSocketServerUrl = fmt.Sprintf("%s:%v/gremlin", testSocketServerUrl, settings.PORT)
> t.Run("Should try create new connection if closed by server", func(t *testing.T) {
> skipTestsIfNotEnabled(t, integrationTestSuiteName, testNoAuthEnable)
> client, _ := NewClient(testSocketServerUrl)
> //The server will immediately close the connection upon receiving this request creating a 1005 error
> resultSet, _ := client.Submit("1", map[string]interface{}{"requestId": settings.CLOSE_CONNECTION_REQUEST_ID})
> resultSet.One()
> client.Close()
> })
> } {code}
> {code:java}
> === RUN TestClientAgainstSocketServer === CONT TestClientAgainstSocketServer testing.go:1319: race detected during execution of test --- FAIL: TestClientAgainstSocketServer (1.04s) === RUN TestClientAgainstSocketServer/Should_try_create_new_connection_if_closed_by_server 2022/12/16 10:43:37 Connecting. 2022/12/16 10:43:38 Read loop error 'websocket: close 1005 (no status)', closing read loop. 2022/12/16 10:43:38 Read loop error 'websocket: close 1005 (no status)', closing read loop. ================== WARNING: DATA RACE Write at 0x00c000358040 by goroutine 15: github.com/apache/tinkerpop/gremlin-go/v3/driver.(*channelResultSet).setError() /Users/coleg/tinkerpop/gremlin-go/driver/resultSet.go:79 +0x80 github.com/apache/tinkerpop/gremlin-go/v3/driver.(*synchronizedMap).closeAll() /Users/coleg/tinkerpop/gremlin-go/driver/connection.go:154 +0xfc github.com/apache/tinkerpop/gremlin-go/v3/driver.readErrorHandler() /Users/coleg/tinkerpop/gremlin-go/driver/protocol.go:93 +0xd8 github.com/apache/tinkerpop/gremlin-go/v3/driver.(*gremlinServerWSProtocol).readLoop() /Users/coleg/tinkerpop/gremlin-go/driver/protocol.go:70 +0x448 github.com/apache/tinkerpop/gremlin-go/v3/driver.newGremlinServerWSProtocol.func1() /Users/coleg/tinkerpop/gremlin-go/driver/protocol.go:200 +0x4cPrevious read at 0x00c000358040 by goroutine 8: github.com/apache/tinkerpop/gremlin-go/v3/driver.(*channelResultSet).One() /Users/coleg/tinkerpop/gremlin-go/driver/resultSet.go:171 +0x34 github.com/apache/tinkerpop/gremlin-go/v3/driver.TestClientAgainstSocketServer.func1() /Users/coleg/tinkerpop/gremlin-go/driver/client_test.go:122 +0x1a4 testing.tRunner() /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1446 +0x188 testing.(*T).Run.func1() /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1493 +0x40Goroutine 15 (running) created at: github.com/apache/tinkerpop/gremlin-go/v3/driver.newGremlinServerWSProtocol() /Users/coleg/tinkerpop/gremlin-go/driver/protocol.go:200 +0x398 github.com/apache/tinkerpop/gremlin-go/v3/driver.createConnection() /Users/coleg/tinkerpop/gremlin-go/driver/connection.go:110 +0x204 github.com/apache/tinkerpop/gremlin-go/v3/driver.newLoadBalancingPool.func1() /Users/coleg/tinkerpop/gremlin-go/driver/connectionPool.go:150 +0xa8Goroutine 8 (running) created at: testing.(*T).Run() /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1493 +0x55c github.com/apache/tinkerpop/gremlin-go/v3/driver.TestClientAgainstSocketServer() /Users/coleg/tinkerpop/gremlin-go/driver/client_test.go:115 +0x1cc testing.tRunner() /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1446 +0x188 testing.(*T).Run.func1() /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1493 +0x40 ================== 2022/12/16 10:43:38 Connection error callback invoked, closing protocol. 2022/12/16 10:43:38 Closing Client with url 'ws://localhost:45943/gremlin' ================== WARNING: DATA RACE Read at 0x00c00027dc10 by goroutine 8: github.com/apache/tinkerpop/gremlin-go/v3/driver.(*connection).close() /Users/coleg/tinkerpop/gremlin-go/driver/connection.go:68 +0x34 github.com/apache/tinkerpop/gremlin-go/v3/driver.(*loadBalancingPool).close() /Users/coleg/tinkerpop/gremlin-go/driver/connectionPool.go:57 +0x10c github.com/apache/tinkerpop/gremlin-go/v3/driver.(*Client).Close() /Users/coleg/tinkerpop/gremlin-go/driver/client.go:147 +0x2d0 github.com/apache/tinkerpop/gremlin-go/v3/driver.TestClientAgainstSocketServer.func1() /Users/coleg/tinkerpop/gremlin-go/driver/client_test.go:124 +0x1ac testing.tRunner() /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1446 +0x188 testing.(*T).Run.func1() /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1493 +0x40Previous write at 0x00c00027dc10 by goroutine 15: github.com/apache/tinkerpop/gremlin-go/v3/driver.(*connection).errorCallback() /Users/coleg/tinkerpop/gremlin-go/driver/connection.go:58 +0x60 github.com/apache/tinkerpop/gremlin-go/v3/driver.(*connection).errorCallback-fm() <autogenerated>:1 +0x34 github.com/apache/tinkerpop/gremlin-go/v3/driver.readErrorHandler() /Users/coleg/tinkerpop/gremlin-go/driver/protocol.go:94 +0xe4 github.com/apache/tinkerpop/gremlin-go/v3/driver.(*gremlinServerWSProtocol).readLoop() /Users/coleg/tinkerpop/gremlin-go/driver/protocol.go:70 +0x448 github.com/apache/tinkerpop/gremlin-go/v3/driver.newGremlinServerWSProtocol.func1() /Users/coleg/tinkerpop/gremlin-go/driver/protocol.go:200 +0x4cGoroutine 8 (running) created at: testing.(*T).Run() /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1493 +0x55c github.com/apache/tinkerpop/gremlin-go/v3/driver.TestClientAgainstSocketServer() /Users/coleg/tinkerpop/gremlin-go/driver/client_test.go:115 +0x1cc testing.tRunner() /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1446 +0x188 testing.(*T).Run.func1() /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1493 +0x40Goroutine 15 (finished) created at: github.com/apache/tinkerpop/gremlin-go/v3/driver.newGremlinServerWSProtocol() /Users/coleg/tinkerpop/gremlin-go/driver/protocol.go:200 +0x398 github.com/apache/tinkerpop/gremlin-go/v3/driver.createConnection() /Users/coleg/tinkerpop/gremlin-go/driver/connection.go:110 +0x204 github.com/apache/tinkerpop/gremlin-go/v3/driver.newLoadBalancingPool.func1() /Users/coleg/tinkerpop/gremlin-go/driver/connectionPool.go:150 +0xa8 ================== 2022/12/16 10:43:38 Ignoring error closing connection: E0101: cannot close connection that has already been closed or has not been connected testing.go:1319: race detected during execution of test --- FAIL: TestClientAgainstSocketServer/Should_try_create_new_connection_if_closed_by_server (1.03s) === CONT testing.go:1319: race detected during execution of test FAILProcess finished with the exit code 1
> {code}
> Race condition 2:
> {code:java}
> func TestClientAgainstSocketServer(t *testing.T) {
> // Integration test variables.
> testNoAuthEnable := getEnvOrDefaultBool("RUN_INTEGRATION_TESTS", true)
> settings := FromYaml(getEnvOrDefaultString("GREMLIN_SOCKET_SERVER_CONFIG_PATH", "../../gremlin-tools/gremlin-socket-server/conf/test-ws-gremlin.yaml"))
> testSocketServerUrl := getEnvOrDefaultString("GREMLIN_SOCKET_SERVER_URL", "ws://localhost")
> testSocketServerUrl = fmt.Sprintf("%s:%v/gremlin", testSocketServerUrl, settings.PORT)
> t.Run("Should try create new connection if closed by server", func(t *testing.T) {
> skipTestsIfNotEnabled(t, integrationTestSuiteName, testNoAuthEnable)
> client, _ := NewClient(testSocketServerUrl)
>
> //The server will immediately close the connection upon receiving this request creating a 1005 error
> resultSet, _ := client.Submit("1", map[string]interface{}{"requestId": settings.CLOSE_CONNECTION_REQUEST_ID})
> //Synchronization added to avoid race condition #1
> time.Sleep(5 * time.Second)
> chResultSet := resultSet.(*channelResultSet)
> chResultSet.channelMutex.Lock()
> resultSet.One()
> chResultSet.channelMutex.Unlock()
> resultSet, _ = client.Submit("1", map[string]interface{}{"requestId": settings.SINGLE_VERTEX_REQUEST_ID})
> resultSet.One()
> client.Close()
> })
> }{code}
> {code:java}
> === RUN TestClientAgainstSocketServer
> === CONT TestClientAgainstSocketServer
> testing.go:1319: race detected during execution of test
> --- FAIL: TestClientAgainstSocketServer (5.10s)
> === RUN TestClientAgainstSocketServer/Should_try_create_new_connection_if_closed_by_server
> 2022/12/16 10:36:03 Connecting.
> 2022/12/16 10:36:04 Read loop error 'websocket: close 1005 (no status)', closing read loop.
> 2022/12/16 10:36:04 Read loop error 'websocket: close 1005 (no status)', closing read loop.
> 2022/12/16 10:36:04 Connection error callback invoked, closing protocol.
> ==================
> WARNING: DATA RACE
> Read at 0x00c0002fdc10 by goroutine 8:
> github.com/apache/tinkerpop/gremlin-go/v3/driver.(*loadBalancingPool).getLeastUsedConnection()
> /Users/coleg/tinkerpop/gremlin-go/driver/connectionPool.go:102 +0x154
> github.com/apache/tinkerpop/gremlin-go/v3/driver.(*loadBalancingPool).write()
> /Users/coleg/tinkerpop/gremlin-go/driver/connectionPool.go:74 +0x90
> github.com/apache/tinkerpop/gremlin-go/v3/driver.(*Client).Submit()
> /Users/coleg/tinkerpop/gremlin-go/driver/client.go:154 +0x1d4
> github.com/apache/tinkerpop/gremlin-go/v3/driver.TestClientAgainstSocketServer.func1()
> /Users/coleg/tinkerpop/gremlin-go/driver/client_test.go:129 +0x29c
> testing.tRunner()
> /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1446 +0x188
> testing.(*T).Run.func1()
> /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1493 +0x40Previous write at 0x00c0002fdc10 by goroutine 15:
> github.com/apache/tinkerpop/gremlin-go/v3/driver.(*connection).errorCallback()
> /Users/coleg/tinkerpop/gremlin-go/driver/connection.go:58 +0x60
> github.com/apache/tinkerpop/gremlin-go/v3/driver.(*connection).errorCallback-fm()
> <autogenerated>:1 +0x34
> github.com/apache/tinkerpop/gremlin-go/v3/driver.readErrorHandler()
> /Users/coleg/tinkerpop/gremlin-go/driver/protocol.go:94 +0xe4
> github.com/apache/tinkerpop/gremlin-go/v3/driver.(*gremlinServerWSProtocol).readLoop()
> /Users/coleg/tinkerpop/gremlin-go/driver/protocol.go:70 +0x448
> github.com/apache/tinkerpop/gremlin-go/v3/driver.newGremlinServerWSProtocol.func1()
> /Users/coleg/tinkerpop/gremlin-go/driver/protocol.go:200 +0x4cGoroutine 8 (running) created at:
> testing.(*T).Run()
> /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1493 +0x55c
> github.com/apache/tinkerpop/gremlin-go/v3/driver.TestClientAgainstSocketServer()
> /Users/coleg/tinkerpop/gremlin-go/driver/client_test.go:116 +0x1cc
> testing.tRunner()
> /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1446 +0x188
> testing.(*T).Run.func1()
> /opt/homebrew/Cellar/go/1.19.1/libexec/src/testing/testing.go:1493 +0x40Goroutine 15 (finished) created at:
> github.com/apache/tinkerpop/gremlin-go/v3/driver.newGremlinServerWSProtocol()
> /Users/coleg/tinkerpop/gremlin-go/driver/protocol.go:200 +0x398
> github.com/apache/tinkerpop/gremlin-go/v3/driver.createConnection()
> /Users/coleg/tinkerpop/gremlin-go/driver/connection.go:110 +0x204
> github.com/apache/tinkerpop/gremlin-go/v3/driver.newLoadBalancingPool.func1()
> /Users/coleg/tinkerpop/gremlin-go/driver/connectionPool.go:150 +0xa8
> ==================
> 2022/12/16 10:36:08 Connecting.
> 2022/12/16 10:36:08 Closing Client with url 'ws://localhost:45943/gremlin'
> 2022/12/16 10:36:08 Closing the connection.
> testing.go:1319: race detected during execution of test
> --- FAIL: TestClientAgainstSocketServer/Should_try_create_new_connection_if_closed_by_server (5.09s)
> === CONT
> testing.go:1319: race detected during execution of test
> FAILProcess finished with the exit code 1 {code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)