winstonjs / winston

A logger for just about everything.
http://github.com/winstonjs/winston
MIT License
22.79k stars 1.81k forks source link

jest is detecting memory leaks when creating a logger with a `File` transport #1445

Open shusson opened 6 years ago

shusson commented 6 years ago

Please tell us about your environment:

What is the problem?

Jest --detectLeaks (experimental flag) is reporting that winston is leaking when using the File transport.

import winston from "winston";

describe("winston", () => {
    it(`should not leak memory with a file transport`, async () => {
        const logger = winston.createLogger({
            transports: [
                new winston.transports.File({
                    filename: "logs/error.log",
                    level: "error"
                })
            ]
        });
        logger.close();
        expect(logger).toBeTruthy();
    });
});
jest --detectLeaks
 FAIL  ./file-transport.spec.ts
  ● Test suite failed to run
EXPERIMENTAL FEATURE!
    Your test suite is leaking memory. Please ensure all references are cleaned.

    There is a number of things that can leak memory:
      - Async operations that have not finished (e.g. fs.readFile).
init
      - Timers not properly mocked (e.g. setInterval, setTimeout).
      - Keeping references to the global scope.

      at node_modules/jest-cli/build/TestScheduler.js:275:22

Test Suites: 1 failed, 1 passed, 2 total
Tests:       1 passed, 1 total
Snapshots:   0 total
Time:        1.654s

Other information

Can be reproduced on this repository: https://github.com/shusson/winston-leak

DABH commented 6 years ago

Interesting! Are there any clues at all as to where the leaks might be coming from? (The file transport has a lot going on…)

shusson commented 6 years ago

no unfortunately I didn't have time to investigate further. At the moment it doesn't actually increase the heap significantly during our test runs. So maybe it's not actually leaking? but yeah needs more investigation.

mherger commented 6 years ago

We have experienced "random" memory leaks in production. Unfortunately we're not able to reproduce it, nor do we know what exactly is triggering it. But at some point heap usage would go insane and the bufferedRequestCount would increase in parallel.

bildschirmfoto 2018-09-26 um 16 33 44

But we're using an http transport.

Is there anything you've figured out to investigate this problem?

christiankiller commented 5 years ago
gonziesc commented 5 years ago

Hello everyone! We were also experimenting memory leaks issues with Winston, especially with file rotation.

I leave this repository: https://github.com/gonziesc/winston-leaks where you can reproduce this behaviour. If the test is not correct, please let me know. We did the same thing with another logger and did not move from ~10mb of memory.

In the repository i left a screenshot where the app stopped before crashing leaving the stack trace.

If i can help to fix this or someone needs me to provide more information, i have no problem!

Thank you.

dcs3spp commented 5 years ago

Hi, think I am getting a memory leak with a winston logger instance using transport console. I am using nestjs and getting the message:

MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 uncaughtException listeners added. Use emitter.setMaxListeners() to increase limit

A winston logger instance is contained within a nestjs service class that serves as a wrapper. When the module goes of scope the service class invokes it's onModuleDestroy method, which in turn invokes close on the wrapped winston logger instance.

The memory leak is triggered when running an [e2e test suite] (https://github.com/dcs3spp/nestjs-example/blob/master/test/e2e/course.e2e-spec.ts). Each test creates a service instance and when it ends triggers the dispose event on the service to close the logger.

Note sure if this a winston issue, e.g. could this be related to issue #213 or is it user developer error?

karlsnyder0 commented 4 years ago

We are also seeing leaks in the File Transport. I had to turn the transport off for our app to stop crashing.

gagan-bansal commented 4 years ago

I also observed memory burst with Winston File Transport.

I am writing a log to monitor a remote server process. So some time remote server transmit a lot of logs around 25k lines (~10 MB) per second I write it file and rotate that file on 100mb size. My system memory on the log server was just 2GB and usually free only ~1 GB. So whenever there was remote server log burst this log server used to crashed because of no memory left.

There are cases when log received are high but not very much, in this case system memory consumption goes up but comes down after some time.

So it does not seam like a memory leak but some thing else.

I went through File Transport code. Though it's using PassThrough stream to pipe source (log/info) to destination file, but at time of file rotation, info (string to write to transport) is buffered up and down

If Winston developers can explain in more detail the code, if really something is buffered up or correct behaviour of Winston transport then things related to memory leak would be resolved to many users.

Best practice code example using Winston to write high volume of log may also help here.

wbt commented 4 years ago

FYI: This may have been duplicated by issue #1706, for which I have posted a workaround and PR. If anyone's willing to test and see if they can (a) reliably reproduce the example on Winston without the patch using the examples above, (b) see whether or not the issue still reproduces with the patch applied, and (c) report back here, that'd be helpful!

uka17 commented 2 years ago

Any news on this? I faced the same issue on file transport.

wbt commented 2 years ago

My patch was merged into master on July 11, 2020 but there hasn't been a release since then and @DABH has not responded in discussion there about when a release might happen. I suggest switching any further discussion over to that thread (click here to access) where you can find multiple workaround options such as updating to a Git ref and/or updating code to include a manual workaround.

I would recommend posting in this thread below ONLY to report results if someone verifies that the fix works for the linked likely-duplicate issue and tests whether or not it also fixes this one.

DABH commented 2 years ago

Hi @wbt, I would love to help but I have been perpetually behind on everything every day for quite some time :( In a perfect world I would like to get back to this and e.g. do a release over the holidays, but it’s difficult for me to promise anything due to everything going on in my life these days. Winston would greatly benefit from a large pool of maintainers…