Handle SetReadDeadline error for websocket connections (#1292) #1310

aaithal · 2018-03-21T15:19:40Z

Summary

Added error handling for SetReadDeadline(). This should take care or scenarios where stale websocket connections linger (#1292)

Implementation details

Forcefully terminate connection if there's any error with the
SetReadDeadline() call. Not doing this leads to unpredictable behavior
with stale websocket connections.

Since SetWriteDeadline always returns nil, errors from that are not
handled.
Move WebsocketConn to its own package. This allows us to mock it
out in the "wsclient" package and write unit tests on it.

Testing

Builds on Linux (make release)
Builds on Windows (go build -out amazon-ecs-agent.exe ./agent)
Unit tests on Linux (make test) pass
Unit tests on Windows (go test -timeout=25s ./agent/...) pass
Integration tests on Linux (make run-integ-tests) pass
Integration tests on Windows (.\scripts\run-integ-tests.ps1) pass
Functional tests on Linux (make run-functional-tests) pass
Functional tests on Windows (.\scripts\run-functional-tests.ps1) pass

New tests cover the changes: Yes

Description for the changelog

Licensing

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

4.9 reached EOL in 2016 and is not available on Dockerhub anymore. Update the base image to 6.4 to fix this.

We're at least 2 years behind in this repo. Updated gomock to latest commit.

[1] Forcefully terminate connection if there's any error with the SetReadDeadline() call. Not doing this leads to unpredictable behavior with stale websocket connections. Since SetWriteDeadline always returns `nil`, errors from that are not handled. [2] Move WebsocketConn to its own package. This allows us to mock it out in the "wsclient" package and write unit tests on it.

Invoke 'goimports' while generating sdk artifacts. Generated targets were missing some imports and this fixes that issue. Also, refactored the code a bit to reduce duplication.

Added changelog entry for stale websocket connection bug fix

adnxn

code lgtm, just few questions.

adnxn · 2018-03-21T16:36:18Z

agent/wsclient/client.go

+	}
+	// An unhandled error has occurred while trying to extend read deadline.
+	// Try asynchronously closing the connection. We don't want to be blocked on stale connections
+	// taking too long to close. The flip side is that we might start accumulating stale connections.


mainly for my understanding - what exactly happens if we "start accumulating stale connections"?

at some point of time, the OS is going to stop the ECS agent from creating new connections if there's a chronic issue because of file descriptor limits.

How do we know that? Do we have a test that ensures that the expected behavior happens when we hit the limit?

adnxn · 2018-03-21T16:38:51Z

agent/wsclient/client.go

+				seelog.Warnf("Unable to close websocket connection: %v for %s",
+					closeErr, cs.URL)
+			}
+			return err


again, mainly for my understanding. what exactly happens if we're "unable to close websocket connection" here? seems like we just move along. what side effects in the agent should we expect if we're unable to close lots of these websocket connections here?

same as above. lmk if you have more questions.

yhlee-aws · 2018-03-21T21:07:39Z

agent/acs/handler/acs_handler.go

@@ -429,6 +429,7 @@ func newDisconnectionTimer(client wsclient.ClientServer, timeout time.Duration,
 		if err := client.Close(); err != nil {
 			seelog.Warnf("Error disconnecting: %v", err)
 		}
+		seelog.Info("Disconnected from ACS")


nit: I think copyright line in this file needs updating too.

richardpen · 2018-03-21T21:07:54Z

misc/testnnp/Dockerfile

@@ -11,7 +11,7 @@
 # express or implied. See the License for the specific language governing
 # permissions and limitations under the License.

-FROM gcc:4.9
+FROM gcc:6.4


Can we just use the latest here, in case we will need to update again in the future?

I don't want to use latest as it makes it hard to audit and track changes

richardpen · 2018-03-21T21:14:56Z

agent/wsclient/client.go

+	}()
+	ctx, cancel := context.WithTimeout(context.TODO(), wsConnectTimeout)
+	defer cancel()
+	for {


looks like this doesn't need to be in the for loop, as both of the cases will return?

you're right. will modify that

richardpen · 2018-03-21T21:18:37Z

agent/wsclient/client_test.go

@@ -36,6 +40,11 @@ import (

 const dockerEndpoint = "/var/run/docker.sock"

+// Close closes the underlying connection
+func (cs *ClientServerImpl) Close() error {


Why is this implemented in the test file?

ClientServerImpl is a partial implementation of the interface, which lacks the Close method. If this is not there, there'll be NPEs. I can document that to make it more clear.

petderek

Awesome, and good improvement to the test structure!

petderek · 2018-03-21T21:18:46Z

agent/wsclient/client.go

+	}()
+	ctx, cancel := context.WithTimeout(context.TODO(), wsConnectTimeout)
+	defer cancel()
+	for {


Why do we need a loop if this only runs once? Select blocks forever and both of the cases return.

petderek · 2018-03-21T21:26:39Z

agent/wsclient/client.go

+		seelog.Errorf("Stopping redundant reads on closed network connection: %s", cs.URL)
+		return opErr
+	}
+	// An unhandled error has occurred while trying to extend read deadline.


Two things stick out to me here. They're stylistic things, so FFTI:

This doesn't follow the standard err != nil pattern where only good things happen on the left side.

In my opinion, all of the second half of this should be in a separate method from SetReadDeadline.

Lets say you extracted the server close logic into closeCSAsync. I'd maybe go with a structure like this:

err := cs.Conn.SetReadDeadline() if err != nil { // check for opErr // return opErr servErr := closeCSAsync() // check for servErr }

petderek · 2018-03-21T21:37:37Z

agent/wsclient/client.go

+				seelog.Warnf("Context canceled waiting for termination of websocket connection: %v for %s",
+					ctx.Err(), cs.URL)
+			}
+			return err


nit:
Its a bit annoying to figure out what err is all the way down here. Maybe make it clear which err is getting returned in a comment? (Its the original deadline err, right?)

Added changelog entry for stale websocket connection bug fix

sharanyad

+1 for mock updates!

sharanyad · 2018-03-21T21:29:55Z

agent/wsclient/client.go

@@ -60,6 +63,8 @@ const (

 	// Default NO_PROXY env var IP addresses
 	defaultNoProxyIP = "169.254.169.254,169.254.170.2"
+
+	errClosed = "use of closed network connection"


Can we have the error name more descriptive like errClosedConnection or similar?

errClosed is pretty descriptive, no? I can change it you have a strong preference

sharanyad · 2018-03-21T21:53:22Z

agent/wsclient/client.go

+	seelog.Warnf("Unable to set read deadline for websocket connection: %v for %s", err, cs.URL)
+	// If we get connection closed error from SetReadDeadline, break out of the for loop and
+	// return an error
+	if opErr, ok := err.(*net.OpError); ok && strings.Contains(opErr.Err.Error(), errClosed) {


Should we do a cs.Close() somewhere in this case too?

I don't think so since it's already closed.

Added missing copyright headers for a couple of files

tehshwann · 2018-03-21T23:14:00Z

agent/acs/update_handler/os/mock/filesystem.go


 	gomock "github.com/golang/mock/gomock"
 )

-// Mock of FileSystem interface
+// MockFileSystem is a mock of FileSystem interface


Nit: // MockFileSystem is a mock of the FileSystem interface

tehshwann · 2018-03-21T23:15:19Z

agent/api/mocks/api_mocks.go

 	api "github.com/aws/amazon-ecs-agent/agent/api"
 	ecs "github.com/aws/amazon-ecs-agent/agent/ecs_client/model/ecs"
 	gomock "github.com/golang/mock/gomock"
 )

-// Mock of ECSSDK interface
+// MockECSSDK is a mock of ECSSDK interface


Nit: *the ECSSDK interface

tehshwann · 2018-03-21T23:17:17Z

agent/wsclient/client.go

+	}
+	// An unhandled error has occurred while trying to extend read deadline.
+	// Try asynchronously closing the connection. We don't want to be blocked on stale connections
+	// taking too long to close. The flip side is that we might start accumulating stale connections.


How do we know that? Do we have a test that ensures that the expected behavior happens when we hit the limit?

aaithal added 5 commits March 21, 2018 08:08

misc: update gcc base image to 6.4

6c35069

4.9 reached EOL in 2016 and is not available on Dockerhub anymore. Update the base image to 6.4 to fix this.

deps: update gomock

abe0ac2

We're at least 2 years behind in this repo. Updated gomock to latest commit.

gogenerate/awssdk: add an import step

1d7f4cf

Invoke 'goimports' while generating sdk artifacts. Generated targets were missing some imports and this fixes that issue. Also, refactored the code a bit to reduce duplication.

regenerate mocks based on the gomock update.

1b8948f

aaithal added a commit to aaithal/amazon-ecs-agent that referenced this pull request Mar 21, 2018

changelog: entry for aws#1310

58b68d2

Added changelog entry for stale websocket connection bug fix

adnxn reviewed Mar 21, 2018

View reviewed changes

jhaynes added this to the 1.17.3 milestone Mar 21, 2018

yhlee-aws reviewed Mar 21, 2018

View reviewed changes

richardpen reviewed Mar 21, 2018

View reviewed changes

petderek reviewed Mar 21, 2018

View reviewed changes

aaithal force-pushed the websocketDeadlineErrors branch from 58b68d2 to 4e527e0 Compare March 21, 2018 21:49

aaithal added a commit to aaithal/amazon-ecs-agent that referenced this pull request Mar 21, 2018

changelog: entry for aws#1310

4e527e0

Added changelog entry for stale websocket connection bug fix

sharanyad reviewed Mar 21, 2018

View reviewed changes

wsclient: add copyright header for new files

3eb58cb

Added missing copyright headers for a couple of files

aaithal force-pushed the websocketDeadlineErrors branch from 4e527e0 to 8d11bdb Compare March 21, 2018 23:00

changelog: add entry for aws#1310

8d11bdb

yhlee-aws approved these changes Mar 21, 2018

View reviewed changes

richardpen approved these changes Mar 21, 2018

View reviewed changes

petderek approved these changes Mar 21, 2018

View reviewed changes

aaithal merged commit 3f2fecc into aws:dev Mar 21, 2018

tehshwann reviewed Mar 21, 2018

View reviewed changes

aaithal mentioned this pull request Mar 21, 2018

Error getting message from ws backend #1292

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Handle SetReadDeadline error for websocket connections (#1292) #1310

Handle SetReadDeadline error for websocket connections (#1292) #1310

aaithal commented Mar 21, 2018 •

edited

Loading

adnxn left a comment

adnxn Mar 21, 2018

aaithal Mar 21, 2018

tehshwann Mar 21, 2018

adnxn Mar 21, 2018

aaithal Mar 21, 2018

yhlee-aws Mar 21, 2018

richardpen Mar 21, 2018

aaithal Mar 21, 2018

richardpen Mar 21, 2018

aaithal Mar 21, 2018

richardpen Mar 21, 2018

aaithal Mar 21, 2018

petderek left a comment

petderek Mar 21, 2018

petderek Mar 21, 2018

petderek Mar 21, 2018

sharanyad left a comment

sharanyad Mar 21, 2018

aaithal Mar 21, 2018

sharanyad Mar 21, 2018

aaithal Mar 21, 2018

tehshwann Mar 21, 2018

tehshwann Mar 21, 2018

tehshwann Mar 21, 2018

Handle SetReadDeadline error for websocket connections (#1292) #1310

Handle SetReadDeadline error for websocket connections (#1292) #1310

Conversation

aaithal commented Mar 21, 2018 • edited Loading

Summary

Implementation details

Testing

Description for the changelog

Licensing

adnxn left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

petderek left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

sharanyad left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

aaithal commented Mar 21, 2018 •

edited

Loading