[19.03 backport] Fix leaking subscription contexts#2927
Merged
Conversation
Fixes leaking subscription contexts, and slightly alters the close procedure for PublishLogs streams. This in turn prevents leaking whole connections, and (hopefully) might be a solution for moby/moby#39916 (All line numbers are in terms of the commit immediately proceeding this one.) From what I can gather, there exists some possibility for a leak if we try to close a gRPC stream without reading any final messages. The documentation for (*grpc.ClientConn).NewStream says: > To ensure resources are not leaked due to the stream returned, one of > the following actions must be performed: > > 1. Call Close on the ClientConn > 2. Cancel the context provided > 3. Call RecvMsg until a non-nil error is returned. A > protobuf-generated client-streaming RPC, for instance, might use > the helper function CloseAndRecv (note that CloseSend does not > Recv, therefore is not guaranteed to release all resources). > 4. Receive a non-nil, non-EOF error from Header or SendMsg. > > If none of the above happen, a goroutine and a context will be leaked, > grpc will not call the optionally-configured stats handler with a > stat.End message. In the agent package, we have a function which is supposed to close the gRPC stream that sends logs to the the manager, agent/agent.go L545-553. It is called when the worker attempt to send logs after the context has been canceled, or when the agent explicitly cancels the log stream. It does not call Recv, which is one possible route for a leak. This means, additionally, that the context is not being canceled. This context is created in the agent's main run loop, agent/agent.go L298-314. A new sub-context is created for each Subscribe call, and this context should be canceled whenever the subscription is closed. The subscription is closed only upon receiving a message from the manager. The logs code is complex, and the manager code is located in ./manager/logbroker. The agent connects to the manager and initiates a server stream, through which the manager sends new log subscriptions (the ListenSubscriptions stream). When a user requests logs, the manager creates a new stream down to the user (the SubscribeLogs stream) and sends a message on the ListenSubscriptions stream of all agents with the desired logs. The agent then creates a third stream (the PublishLogs stream) through which it sends logs to the manager. The stream that is being leaked is this third stream, PublishLogs. These three streams all exist in separate, concurrent goroutines, and communicate over a complex series of channels. The problem, basically, is this: * The ListenSubscriptions stream starts a watch on a queue. It knows a subscription is relevant to the agent if the subscription contains the NodeID of the agent. * When a subscription is finished, it is updated to say that it is closed, and then published to this queue to notify all agents. * When the manager receives a message on the PublishLogs stream that indicates the agent has no more logs to send, it removes the node ID from the subscription. * Therefore, if the PublishLogs call finishes before the Subscription is closed, the Close message is never sent to the agent. This is generally intended behavior, as the Close message is not supposed to clean up dangling streams, it is supposed to notify that a logs request in progress should be stopped. Additionally, the manager may never get the opportunity to send the Close message, if, for example, it crashes. This means it is the agent's responsibility to clean up any completed logs streams. Further, to guarantee that we don't leak resources, we add a Recv call to the function that closes the PublishLogs stream. Signed-off-by: Drew Erny <[email protected]> (cherry picked from commit d12f9f6) Signed-off-by: Sebastiaan van Stijn <[email protected]>
Member
Author
Codecov Report
@@ Coverage Diff @@
## bump_v19.03 #2927 +/- ##
===============================================
- Coverage 62.19% 62.05% -0.14%
===============================================
Files 139 139
Lines 22317 22325 +8
===============================================
- Hits 13880 13854 -26
- Misses 6967 6998 +31
- Partials 1470 1473 +3 |
thaJeztah
added a commit
to thaJeztah/docker
that referenced
this pull request
Jan 29, 2020
full diff: moby/swarmkit@f35d910...062b694 changes: - moby/swarmkit#2927 [19.03 backport] Fix leaking subscription contexts - backport of moby/swarmkit#2926 Fix leaking log subscription contexts - addresses moby#39916 Dockerd eats too much RAM Signed-off-by: Sebastiaan van Stijn <[email protected]>
tiborvass
pushed a commit
to tiborvass/docker
that referenced
this pull request
Feb 4, 2020
full diff: moby/swarmkit@f35d910...062b694 changes: - moby/swarmkit#2927 [19.03 backport] Fix leaking subscription contexts - backport of moby/swarmkit#2926 Fix leaking log subscription contexts - addresses moby#39916 Dockerd eats too much RAM Signed-off-by: Sebastiaan van Stijn <[email protected]>
docker-jenkins
pushed a commit
to docker-archive/docker-ce
that referenced
this pull request
Feb 4, 2020
full diff: moby/swarmkit@f35d910...062b694 changes: - moby/swarmkit#2927 [19.03 backport] Fix leaking subscription contexts - backport of moby/swarmkit#2926 Fix leaking log subscription contexts - addresses moby/moby#39916 Dockerd eats too much RAM Signed-off-by: Sebastiaan van Stijn <[email protected]> Upstream-commit: 0dd0af939f98500daf86f96f3fbd039af397dd8a Component: engine
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
backport of #2926
Fixes leaking subscription contexts, and slightly alters the close
procedure for PublishLogs streams. This in turn prevents leaking whole
connections, and (hopefully) might be a solution for moby/moby#39916
(All line numbers are in terms of the commit immediately proceeding this
one.)
From what I can gather, there exists some possibility for a leak if we
try to close a gRPC stream without reading any final messages.
The documentation for (*grpc.ClientConn).NewStream says:
In the agent package, we have a function which is supposed to close the
gRPC stream that sends logs to the the manager, agent/agent.go L545-553.
It is called when the worker attempt to send logs after the context has
been canceled, or when the agent explicitly cancels the log stream. It
does not call Recv, which is one possible route for a leak.
This means, additionally, that the context is not being canceled. This
context is created in the agent's main run loop, agent/agent.go
L298-314. A new sub-context is created for each Subscribe call, and this
context should be canceled whenever the subscription is closed. The
subscription is closed only upon receiving a message from the manager.
The logs code is complex, and the manager code is located in
./manager/logbroker. The agent connects to the manager and initiates a
server stream, through which the manager sends new log subscriptions
(the ListenSubscriptions stream). When a user requests logs, the manager
creates a new stream down to the user (the SubscribeLogs stream) and
sends a message on the ListenSubscriptions stream of all agents with the
desired logs. The agent then creates a third stream (the PublishLogs
stream) through which it sends logs to the manager. The stream that is
being leaked is this third stream, PublishLogs. These three streams all
exist in separate, concurrent goroutines, and communicate over a complex
series of channels.
The problem, basically, is this:
subscription is relevant to the agent if the subscription contains the
NodeID of the agent.
closed, and then published to this queue to notify all agents.
indicates the agent has no more logs to send, it removes the node ID
from the subscription.
closed, the Close message is never sent to the agent. This is
generally intended behavior, as the Close message is not supposed to
clean up dangling streams, it is supposed to notify that a logs
request in progress should be stopped.
Additionally, the manager may never get the opportunity to send the
Close message, if, for example, it crashes. This means it is the agent's
responsibility to clean up any completed logs streams. Further, to
guarantee that we don't leak resources, we add a Recv call to the
function that closes the PublishLogs stream.