Logger issue

[Ian Ryder]

Hi, we're just getting logging running on an app we're building and have a what I hope is a bit of noob issue.

It seems every time a request comes in a new file handle is opened and not released when the request is finished. Eventually we get an error with too many open files and everything stops working.

Are we missing something simple? There doesn't seem to be anyone else having such an issue so hopefully we're doing something wrong. The logger initialisation looks like this:

# configure logging
logger_format = '%(asctime)s - %(funcName)s():%(lineno)d [%(levelname)s]: %(message)s'
logging.basicConfig(
    format=logger_format,
    level=int(session.logging_level) if session.logging_level else logging.INFO
)
logger = logging.getLogger(cfg.global_app_name)
handler = logging.FileHandler('test.log')
handler.setLevel(logging.DEBUG)
logger.addHandler(handler)
current.logger = logger

Thanks

[Kiran Subbaraman]

configuring the logger for every thread (`current.logger = logger`), and this seems unnecessary.
Take a look at this logging configuration: https://github.com/web2py/web2py/blob/0d646fa5e7c731cb5c392adf6a885351e77e4903/examples/logging.example.conf, and set one up for your app.

________________________________________
Kiran Subbaraman
http://subbaraman.wordpress.com/about/

--
Resources:
- http://web2py.com
- http://web2py.com/book (Documentation)
- http://github.com/web2py/web2py (Source code)
- https://code.google.com/p/web2py/issues/list (Report Issues)
---
You received this message because you are subscribed to the Google Groups "web2py-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to web2py+un...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Dave S]

On Sunday, October 22, 2017 at 9:19:02 PM UTC-7, Kiran Subbaraman wrote:

configuring the logger for every thread (`current.logger = logger`), and this seems unnecessary.
Take a look at this logging configuration: https://github.com/web2py/web2py/blob/0d646fa5e7c731cb5c392adf6a885351e77e4903/examples/logging.example.conf, and set one up for your app.

Doesn't the OP already have that file as part of the web2py distribution?  It ships in the example app, no?

/dps

 

[Kiran Subbaraman]

Yes, I suggested the OP configure one for their specific app, using the example app's config as a template.
Need not configure this in the code, for every request ... as they are doing so now.

________________________________________
Kiran Subbaraman
http://subbaraman.wordpress.com/about/

[Alex]

I've got a similar problem. I have a model file where I initialize the logger:

import logging, logging.handlers

def get_configured_logger(name):
    logger = logging.getLogger(name)
    if (len(logger.handlers) == 0):
        # This logger has no handlers, so we can assume it hasn't yet been configured
        # (Configure logger)

        # Create RotatingFileHandler
        import os
        formatter = "%(asctime)s %(levelname)s %(process)s %(thread)s %(funcName)s():%(lineno)d %(message)s"
        # rotate log file when it reaches 10MB
        handler = logging.handlers.RotatingFileHandler(os.path.join(request.folder,'private/myapp.log'),maxBytes=10485760,backupCount=2)
        handler.setFormatter(logging.Formatter(formatter))

        handler.setLevel(logging.DEBUG)

        logger.addHandler(handler)
        logger.setLevel(logging.DEBUG)

    if len(logger.handlers) > 1:
        logger.debug('handler: ' + str(len(logger.handlers)))
    return logger

# Assign application logger to a global var
logger = get_configured_logger(request.application)

sometimes it happens that an additional handler is added. After a few days sometimes there are 2 or even more handlers attached. Every log message is then printed multiple times in the log file.

The application is internal and has only few users. Therefor I'm using the integrated Rocket webserver (Linux). Has anyone an idea why this is happening?

Would rewriting the logger configuration with the logging.conf file help in this case? It's not that easy to simply rewrite and test it because the application is auto-deployed to different machines and it would be necessary to adapt the deployment process as well.

Alex

[Dave S]

On Wednesday, November 15, 2017 at 10:38:09 AM UTC-8, Alex wrote:

I've got a similar problem. I have a model file where I initialize the logger:

What did you find missing in using logging.conf?

/dps

 

[Alex]

I'm not missing anything with logging.conf. As I mentioned above it is not just simply rewriting the logging configuration because I have to adapt the deployment process as well. Therefor I'd like to know in advance if you think that rewriting the logger would solve this issue.

And I'd like to know how this is possible at all in first place. I've other applications with much more users (but using Apache instead of Rocket) without this problem.

Alex

[Dave S]

On Wednesday, November 22, 2017 at 2:50:45 AM UTC-8, Alex wrote:

I'm not missing anything with logging.conf. As I mentioned above it is not just simply rewriting the logging configuration because I have to adapt the deployment process as well. Therefor I'd like to know in advance if you think that rewriting the logger would solve this issue.

If the deployment process is A Separate Piece Of Code (Chef, Salt, fabfiles, BASH scripts, etc), I would put logging into that,copy the log file into the web2py/logs directory if you want, and just use logging.conf for web2py.  Adding an app to the logging of an existing installation just requires appending about 4 lines to logging.conf.

 

And I'd like to know how this is possible at all in first place. I've other applications with much more users (but using Apache instead of Rocket) without this problem.

Alex

I have no experience with logs other than logging.conf, so I don't know.  In my experience, Rocket doesn't introduce any funnies in logging.

/dps