Skip to content

Instantly share code, notes, and snippets.

@prashantv
Created June 17, 2016 16:00
Show Gist options
  • Save prashantv/269a2c2f1242e8e2aff9ae2b201cac96 to your computer and use it in GitHub Desktop.
Save prashantv/269a2c2f1242e8e2aff9ae2b201cac96 to your computer and use it in GitHub Desktop.
TestNoTimeout failure
--- FAIL: TestNoTimeout (0.02s)
<autogenerated>:31: Unexpected log: [Warn]: Failed to add connection to peer [{service relay} {process relay-58154} {hostPort 127.0.0.1:58154} {connID 370} {localAddr 127.0.0.1:58154} {remoteAddr 127.0.0.1:60664} {remoteHostPort 127.0.0.1:56950} {direction inbound} {error tchannel error ErrCodeNetwork: connection is in an invalid state}]
<autogenerated>:29: Debug logs:
01:01:13.311964 [D] NewChannel created at goroutine 1689 [running]:
github.com/uber/tchannel-go.getStacks(0xc82071d300, 0x0, 0x0, 0x0)
/home/travis/gopath/src/github.com/uber/tchannel-go/introspection.go:392 +0xb9
github.com/uber/tchannel-go.registerNewChannel(0xc82071d320)
/home/travis/gopath/src/github.com/uber/tchannel-go/all_channels.go:36 +0x61
github.com/uber/tchannel-go.NewChannel(0xbd29a0, 0xb, 0xc822546a00, 0xbbaa40, 0x0, 0x0)
/home/travis/gopath/src/github.com/uber/tchannel-go/channel.go:234 +0xf89
github.com/uber/tchannel-go/testutils.NewServerChannel(0xc822546a00, 0xc821a942a0, 0x0, 0x0)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/channel.go:51 +0x7dd
github.com/uber/tchannel-go/testutils.newServer(0x2ba67f6886f0, 0xc821a942a0, 0xc822546900, 0xc822546900)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/channel_t.go:71 +0x6c
github.com/uber/tchannel-go/testutils.(*TestServer).addChannel(0xc821a942a0, 0xce6d10, 0xc822546900, 0x2ba67f599000)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/test_server.go:231 +0x81
github.com/uber/tchannel-go/testutils.(*TestServer).NewServer(0xc821a942a0, 0xc820539a08, 0xc822115680)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/test_server.go:199 +0xb8
github.com/uber/tchannel-go/testutils.NewTestServer(0x2ba67f688580, 0xc82056a1b0, 0xc820539a08, 0x0)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/test_server.go:85 +0x2b6
github.com/uber/tchannel-go/testutils.withServer(0x2ba67f688580, 0xc82056a1b0, 0xc820539a08, 0xc820539f30)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/test_server.go:417 +0x56
github.com/uber/tchannel-go/testutils.WithTestServer(0x2ba67f688580, 0xc82056a1b0, 0xc820539de8, 0xc820539f30)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/test_server.go:116 +0x2e6
github.com/uber/tchannel-go_test.TestNoTimeout(0xc82056a1b0)
/home/travis/gopath/src/github.com/uber/tchannel-go/connection_test.go:321 +0xb0
testing.tRunner(0xc82056a1b0, 0xf0b358)
/home/travis/.gimme/versions/go1.6.linux.amd64/src/testing/testing.go:473 +0xdd
created by testing.RunTests
/home/travis/.gimme/versions/go1.6.linux.amd64/src/testing/testing.go:582 +0xae3
[{service testService} {process testService-56950}]
01:01:13.312047 [D] testService-56950 (testService) listening on 127.0.0.1:56950 [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950}]
01:01:13.313425 [D] created for testService (testService-56950) local: 127.0.0.1:60664 remote: 127.0.0.1:58154 [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950} {connID 371} {localAddr 127.0.0.1:60664} {remoteAddr 127.0.0.1:58154}]
01:01:13.313789 [D] Creating new outbound message exchange for [messageTypeInitReq:1] [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950} {connID 371} {localAddr 127.0.0.1:60664} {remoteAddr 127.0.0.1:58154} {exchange outbound}]
01:01:13.314008 [D] Writing frame messageTypeInitReq[1] [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950} {connID 371} {localAddr 127.0.0.1:60664} {remoteAddr 127.0.0.1:58154}]
01:01:13.314775 [D] New active outbound connection for peer 127.0.0.1:58154 [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950} {connID 371} {localAddr 127.0.0.1:60664} {remoteAddr 127.0.0.1:58154}]
01:01:13.314984 [D] forwarding outbound messageTypeInitRes[1] [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950} {connID 371} {localAddr 127.0.0.1:60664} {remoteAddr 127.0.0.1:58154} {exchange outbound}]
01:01:13.315152 [D] Removing outbound message exchange 1 [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950} {connID 371} {localAddr 127.0.0.1:60664} {remoteAddr 127.0.0.1:58154} {exchange outbound}]
01:01:13.315286 [D] TEST: Test function complete [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950}]
01:01:13.316033 [D] TEST: TestServer is closing and verifying channel [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950}]
01:01:13.316067 [I] Channel.Close called [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950}]
01:01:13.316158 [D] Connection Close [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950} {connID 371} {localAddr 127.0.0.1:60664} {remoteAddr 127.0.0.1:58154}]
01:01:13.316336 [D] checkExchanges updated connection state to connectionClosed [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950} {connID 371} {localAddr 127.0.0.1:60664} {remoteAddr 127.0.0.1:58154}]
01:01:13.316481 [D] Closing underlying network connection [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950} {connID 371} {localAddr 127.0.0.1:60664} {remoteAddr 127.0.0.1:58154}]
01:01:13.316745 [I] Removed peer 127.0.0.1:58154 from root peer list [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950}]
01:01:13.316819 [D] ConnectionCloseStateChange channel state = ChannelClosed connection minState = connectionClosed [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950} {connID 371} {localAddr 127.0.0.1:60664} {remoteAddr 127.0.0.1:58154}]
01:01:13.317599 [D] Ignoring error after connection was closed: EOF [{service testService} {process testService-56950} {hostPort 127.0.0.1:56950} {connID 371} {localAddr 127.0.0.1:60664} {remoteAddr 127.0.0.1:58154}]
<autogenerated>:29: Debug logs:
01:01:13.312519 [D] NewChannel created at goroutine 1689 [running]:
github.com/uber/tchannel-go.getStacks(0xc820d22900, 0x0, 0x0, 0x0)
/home/travis/gopath/src/github.com/uber/tchannel-go/introspection.go:392 +0xb9
github.com/uber/tchannel-go.registerNewChannel(0xc820d22900)
/home/travis/gopath/src/github.com/uber/tchannel-go/all_channels.go:36 +0x61
github.com/uber/tchannel-go.NewChannel(0xbbf1a8, 0x5, 0xc822546c00, 0xbbaa40, 0x0, 0x0)
/home/travis/gopath/src/github.com/uber/tchannel-go/channel.go:234 +0xf89
github.com/uber/tchannel-go/testutils.NewServerChannel(0xc822546c00, 0xc821a942a0, 0x0, 0x0)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/channel.go:51 +0x7dd
github.com/uber/tchannel-go/testutils.newServer(0x2ba67f6886f0, 0xc821a942a0, 0xc822546b00, 0xc822546b00)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/channel_t.go:71 +0x6c
github.com/uber/tchannel-go/testutils.(*TestServer).addChannel(0xc821a942a0, 0xce6d10, 0xc822546b00, 0xc820539770)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/test_server.go:231 +0x81
github.com/uber/tchannel-go/testutils.(*TestServer).addRelay(0xc821a942a0, 0x0, 0x0, 0x0, 0x0)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/test_server.go:220 +0x558
github.com/uber/tchannel-go/testutils.NewTestServer(0x2ba67f688580, 0xc82056a1b0, 0xc820539a08, 0x0)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/test_server.go:87 +0x342
github.com/uber/tchannel-go/testutils.withServer(0x2ba67f688580, 0xc82056a1b0, 0xc820539a08, 0xc820539f30)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/test_server.go:417 +0x56
github.com/uber/tchannel-go/testutils.WithTestServer(0x2ba67f688580, 0xc82056a1b0, 0xc820539de8, 0xc820539f30)
/home/travis/gopath/src/github.com/uber/tchannel-go/testutils/test_server.go:116 +0x2e6
github.com/uber/tchannel-go_test.TestNoTimeout(0xc82056a1b0)
/home/travis/gopath/src/github.com/uber/tchannel-go/connection_test.go:321 +0xb0
testing.tRunner(0xc82056a1b0, 0xf0b358)
/home/travis/.gimme/versions/go1.6.linux.amd64/src/testing/testing.go:473 +0xdd
created by testing.RunTests
/home/travis/.gimme/versions/go1.6.linux.amd64/src/testing/testing.go:582 +0xae3
[{service relay} {process relay-58154}]
01:01:13.312606 [D] relay-58154 (relay) listening on 127.0.0.1:58154 [{service relay} {process relay-58154} {hostPort 127.0.0.1:58154}]
01:01:13.313011 [D] created for relay (relay-58154) local: 127.0.0.1:58154 remote: 127.0.0.1:60664 [{service relay} {process relay-58154} {hostPort 127.0.0.1:58154} {connID 370} {localAddr 127.0.0.1:58154} {remoteAddr 127.0.0.1:60664}]
01:01:13.314317 [D] New active inbound connection for peer 127.0.0.1:56950 [{service relay} {process relay-58154} {hostPort 127.0.0.1:58154} {connID 370} {localAddr 127.0.0.1:58154} {remoteAddr 127.0.0.1:60664}]
01:01:13.314540 [D] Writing frame messageTypeInitRes[1] [{service relay} {process relay-58154} {hostPort 127.0.0.1:58154} {connID 370} {localAddr 127.0.0.1:58154} {remoteAddr 127.0.0.1:60664}]
01:01:13.315319 [D] TEST: TestServer is closing and verifying channel [{service relay} {process relay-58154} {hostPort 127.0.0.1:58154}]
01:01:13.315354 [I] Channel.Close called [{service relay} {process relay-58154} {hostPort 127.0.0.1:58154}]
01:01:13.315441 [D] Connection Close [{service relay} {process relay-58154} {hostPort 127.0.0.1:58154} {connID 370} {localAddr 127.0.0.1:58154} {remoteAddr 127.0.0.1:60664}]
01:01:13.315837 [D] checkExchanges updated connection state to connectionClosed [{service relay} {process relay-58154} {hostPort 127.0.0.1:58154} {connID 370} {localAddr 127.0.0.1:58154} {remoteAddr 127.0.0.1:60664}]
01:01:13.315960 [D] ConnectionCloseStateChange channel state = ChannelClosed connection minState = connectionClosed [{service relay} {process relay-58154} {hostPort 127.0.0.1:58154} {connID 370} {localAddr 127.0.0.1:58154} {remoteAddr 127.0.0.1:60664}]
01:01:13.316594 [D] Closing underlying network connection [{service relay} {process relay-58154} {hostPort 127.0.0.1:58154} {connID 370} {localAddr 127.0.0.1:58154} {remoteAddr 127.0.0.1:60664}]
01:01:13.315707 [W] Failed to add connection to peer [{service relay} {process relay-58154} {hostPort 127.0.0.1:58154} {connID 370} {localAddr 127.0.0.1:58154} {remoteAddr 127.0.0.1:60664} {remoteHostPort 127.0.0.1:56950} {direction inbound} {error tchannel error ErrCodeNetwork: connection is in an invalid state}]
01:01:13.317888 [D] Ignoring error after connection was closed: read tcp 127.0.0.1:58154->127.0.0.1:60664: use of closed network connection [{service relay} {process relay-58154} {hostPort 127.0.0.1:58154} {connID 370} {localAddr 127.0.0.1:58154} {remoteAddr 127.0.0.1:60664}]
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment