Picologging leaks memory when used in an ASGI Framework about picologging HOT 9 OPEN

thanks for the report. Sorry I haven't replied earlier, I'll repro this and fix the leak. Hopefully its one of the ones we're tackling in #137

from picologging.

s/Starlite/Litestar 😄

from picologging.

Also had a leak with picologging, all is good when swapped back to std logging.
The leak manifested when i passed a logger object deep into threaded + asyncio code. The leak only happened when i called a log function deep down, it didn't leak when the loglevel was higher than the message, or when i didn't call the log function.
Bashed my head against it for a few hours but couldn't crack it, probably leaking fd's and the gc can't collect it or something. Migrating back to std logging for now.

from picologging.

For the original sample, I was able to get it running, but I wasn't able to reproduce a memory leak. I wonder if it's the versions that are running? picologging 0.9.2 came with some memory fixes.

To be sure, I've written a minimal sample to use the Litestar queue logger handler (similar to the OP's sample). lite star has changed some of the APIs.

Under Memray for 100,000 HTTP calls, memory usage is stable--

from litestar import  Litestar, get, Request
from litestar.logging import LoggingConfig
from litestar.testing import TestClient


logging_config = LoggingConfig(
    loggers={
        "app": {
            "level": "DEBUG",
            "handlers": ["queue_listener"],
            "propagate": False,
        }
    }
)


@get("/")
def hello_world(request: Request) -> dict[str, str]:
    """Handler function that returns a greeting dictionary."""
    request.logger.info("No results in response")
    request.logger.debug("doing things...")
    return {"hello": "world"}


app = Litestar(
    route_handlers=[hello_world],
    logging_config=logging_config,
    debug=True,
)

if __name__ == "__main__":
    with TestClient(app=app) as client:
        for _ in range(100_000):
            response = client.get("/")

@dkull

The leak manifested when i passed a logger object deep into threaded + asyncio code. The leak only happened when i called a log function deep down, it didn't leak when the loglevel was higher than the message, or when i didn't call the log function.

Please could you give me some more detail? I believe everyone, I just can't reproduce a leak to identify where it's coming from.

from picologging.

Hey @tonybaloney thanks for looking into this. I'm not 100% certain what version of picologging I was using when I submitted this ticket, but I'm pretty sure it was 0.9.2. I don't think starlite (now called Litestar) had any version constraints on picologging, and I found this in an old requirements.txt file: picologging==0.9.2 for a starlite project I had.

No one else from the litestar project reported this issue with picologging, so there must be something unique about my usage. I was requesting large JSON responses in background tasks... 2-5MB or more, generally. Passing around the data and logging in each function exacerbated the leak.

Are you able to repro with the example I provided? That was made using starlite==1.51.12. You'll have to update the endpoint, it's been migrated since I reported this issue. Try this URL to get large JSON responses: https://fcd.terraclassic.community/v1/staking/validators

Let me know if you have any issues running it.

from picologging.

Try updating to 0.9.3, that has a few bug fixes.

Also, there was a memory leak in Litestar/Starlite related to the storage of large responses, but like you pointed out this only occurs when using picologging and not normal logging. Probably worth the update anyway. litestar-org/litestar#1137

from picologging.

@tonybaloney I just ran my original script with pico 0.9.3. I didn't have time to set up memray, but looking at activity monitor in macos, you can see memory consumption is pretty high after ~5 minutes of requests.

And for comparison, here's memory consumption with regular logging lib... I turned it on, ate dinner and came back after 30 minutes or so.

For reference, Starlite normally consumes around 90-125mb of memory at idle.

from picologging.

What version of python are you using for tests?
I noticed a leak after switching from python 3.8 to python 3.11. I am using piccologging with other web framework.

from picologging.

I've observed the memory leak on 3.10 and 3.11, I haven't tried earlier Python versions

from picologging.