Memory leak when thread is terminated after using logger.with_level
Nobody has claimed this yet.
- Dominant language
- Ruby
- Stars
- 161
- Forks
- 71
- Avg merge
- 3d 22h
- Merged PRs (30d)
- 2
Description
Hello. We were debugging a memory leak that appeared in our rails app after we started using with_level method to adjust visibility of some logs. How to reproduce:
require "logger"
require "memory_profiler"
logger = Logger.new $stdout
MemoryProfiler.report do
100.times { Thread.new { Thread.current[:data] = Array.new(200); logger.with_level(Logger::ERROR) { logger.debug("test") } }.join }
GC.start
end.pretty_print
# Total allocated: 336800 bytes (400 objects)
# Total retained: 336800 bytes (400 objects)
# ...
# retained memory by class
-----------------------------------
164000 Array
114400 Fiber
50400 Thread
8000 Proc
All memory is freed if logger.with_level is removed. My guess is that it happens because Logger uses Fiber.current as key in level_override hash to track log level for current fiber. This reference to Fiber.current is never cleared so GC cannot free connected terminated threads.
For more context this is why it happened in our rails application - we are deployed in kubernetes and have small plugin in puma to process liveness and readiness probes (simple http requests to specific endpoints). One of these requests checks connection to database via simple query. We hide these queries from logs via logger.with_level(Logger::Error) .... Problem was that our puma plugin options had min_threads: 0, max_threads: 1 so puma terminated (and later created again) its thread from time to time, which lead to level_override filling up with old Fiber.current for terminated threads.
When we eventually figured this out the fix was to just keep min_threads same as max_threads in puma.
I am not sure what would be the best way to prevent it (Fiber local variable instead of hash?) or if even something should be changed in Logger, because I realize that our problem was most likely quite unusual. If you think that this should be fixed I would be happy to prepare the change if you point me to the right direction. If not then this could at least help someone who is searching for similar problem.
Contributor guide
No contributing guide indexed for this repository
First steps
- Read the whole issue, then the project's contributing guide.
- Comment on the issue to say you are picking it up — it saves two people doing the same work.
- Fork the repository and make your change on a branch.
- Open a pull request that references the issue number.
Research direction
Start by running the reported MemoryProfiler reproduction and inspect Logger#with_level, the level_override hash, and its Fiber.current keys. Determine whether terminated threads or fibers can be released, then add a regression test if a Logger change is warranted; done means the retained memory no longer grows after the threads terminate.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- ruby
- Domain
- tooling
- Issue type
- Bug
- Difficulty
- 5/5
- Estimated time
- Over a week
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 30/100