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.

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

Fix a logmon goroutine and memory leak #11261

Merged
merged 4 commits into from Oct 5, 2021
Merged

Fix a logmon goroutine and memory leak #11261

merged 4 commits into from Oct 5, 2021

Conversation

notnoop
Copy link
Contributor

@notnoop notnoop commented Oct 5, 2021

Fix a logmon leak causing high goroutine and memory usage when a task
restarts.

Logmon FileRotator buffers the task stdout/stderr streams and
periodically flushing them to log files. Logmon creates a new
FileRotator for each stream for each task run. However, the
flushPeriodically goroutine is leaked when a task restarts,
holding a reference to a no-longer-needed FileRotator instance
along with its 64kb buffer.

The cause is that the code assumed time.Ticker.Stop() closes the
ticker channel, thereby terminating the goroutine, but the documentation
says otherwise:

Stop turns off a ticker. After Stop, no more ticks will be sent. Stop does not close the channel, to prevent a concurrent goroutine reading from the channel from seeing an erroneous "tick".
https://pkg.go.dev/time#Ticker.Stop

The PR adds https://github.com/uber-go/goleak dependency for detecting leaked goroutines. You can see the failures in CI about leaked goroutines in https://app.circleci.com/pipelines/github/hashicorp/nomad/17716/workflows/8fde2a15-09ae-4e21-b9a5-8e5de326f3f4/jobs/175847 but succeed with the fix commit in https://app.circleci.com/pipelines/github/hashicorp/nomad/17717/workflows/58804f90-428e-4c99-91f9-8d857b6fb979/jobs/175864.

Note, that I refactored the tests as well to use testify and ensure that file and rotator resources are closed properly for each test.

Fixes #9858

Mahmood Ali added 3 commits October 5, 2021 12:10
Mostly to use testify assertions and close open resources
Fix a logmon leak causing high goroutine and memory usage when a task
restarts.

Logmon `FileRotator` buffers the task stdout/stderr streams and
periodically flushing them to log files. Logmon creates a new
FileRotator for each stream for each task run. However, the
`flushPeriodically` goroutine is leaked when a task restarts,
holding a reference to a no-longer-needed `FileRotator` instance
along with its 64kb buffer.

The cause is that the code assumed `time.Ticker.Stop()` closes the
ticker channel, thereby terminating the goroutine, but the documentation
says otherwise:

> Stop turns off a ticker. After Stop, no more ticks will be sent. Stop does not close the channel, to prevent a concurrent goroutine reading from the channel from seeing an erroneous "tick".
https://pkg.go.dev/time#Ticker.Stop
@notnoop notnoop self-assigned this Oct 5, 2021
Copy link
Member

@schmichael schmichael left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Great find and super excited to have goleak handy!

@github-actions
Copy link

I'm going to lock this pull request because it has been closed for 120 days ⏳. This helps our maintainers find and focus on the active contributions.
If you have found a problem that seems related to this change, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Oct 20, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

high memory usage in logmon
3 participants