logger.info not working in Django logging

Question

Following is the logging snippet I have used in my django settings.py file. All the GET,POST requests are getting written to log but when i wrote logger.info("print something"), its not getting printed/captured in console as well as the log file

Please suggest a workaround to capture logger.info() logs

views.py

import logging

logger = logging.getLogger(__name__)

def custom_data_generator(request):
    logger.info("print somethig") # NOT GETTING CAPTURED IN LOG FILE
    return somethig

settings.py (DEBUG = True and DEBUG_MODE = False in settings.py file)

LOGGING = {
'version': 1,
'disable_existing_loggers': False,
'formatters': {
    'simple': {
        'format': '[%(asctime)s] %(levelname)s|%(name)s|%(message)s',
        'datefmt': '%Y-%m-%d %H:%M:%S',
    },
},
'handlers': {
    'applogfile': {
        'level': 'DEBUG',
        'class': 'logging.handlers.RotatingFileHandler',
        'filename': '/home/mahesh/Documents/refactor/unityapp/unity/media/myproject.log',
        'backupCount': 10,
        'formatter': 'simple',
    },
    'console': {
        'level': 'DEBUG',
        'class': 'logging.StreamHandler',
        'formatter': 'simple'
    }
},
'loggers': {
    'django': {
        'handlers': ['applogfile', 'console'],
        'level': os.getenv('DJANGO_LOG_LEVEL', 'INFO'),
    }
}
}

log data generated as follows

[2020-07-07 11:43:25] ERROR|django.server|"GET /a11y/project-dashboard/?

refnum=ACGLOBAL&env_id=4 HTTP/1.1" 500 92016
[2020-07-07 12:05:21] INFO|django.server|"GET /admin/ HTTP/1.1" 200 59501
[2020-07-07 12:05:21] INFO|django.server|"GET /admin/ HTTP/1.1" 200 59501
[2020-07-07 12:05:21] INFO|django.server|"GET /static/admin/fonts/Roboto-Light-webfont.woff HTTP/1.1" 200 85692
[2020-07-07 12:05:21] INFO|django.server|"GET /static/admin/fonts/Roboto-Bold-webfont.woff HTTP/1.1" 200 86184
[2020-07-07 12:05:21] INFO|django.server|"GET /static/admin/fonts/Roboto-Regular-webfont.woff HTTP/1.1" 200 85876
[2020-07-07 12:05:26] INFO|django.server|"GET /admin/accessibility/axe_json/ HTTP/1.1" 200 1886434
[2020-07-07 12:05:27] INFO|django.server|"GET /admin/jsi18n/ HTTP/1.1" 200 3223
[2020-07-07 12:05:27] INFO|django.server|"GET /static/admin/js/vendor/jquery/jquery.js HTTP/1.1" 200 280364
[2020-07-07 12:05:27] INFO|django.server|"GET /static/admin/js/vendor/xregexp/xregexp.js HTTP/1.1" 200 128820
[2020-07-07 12:05:34] INFO|django.server|"GET /admin/accessibility/axe_json/?page_id=https%3A%2F%2Fjobs.chegg.com%2Fapplythankyou HTTP/1.1" 200 1868950
[2020-07-07 12:05:35] INFO|django.server|"GET /admin/jsi18n/ HTTP/1.1" 200 3223

score 5 · Accepted Answer · answered Jul 07 '20 at 22:41

5

It's probably because your views module doesn't have a logging level set, so it will inherit the root logger's default level of WARNING. If you add a root entry with a level of INFO, similarly to the documented examples, you should see messages from other modules. Alternatively you can specify logger names under the loggers key for your specific module hierarchy, whatever that is. (Your example only overrides the WARNING level for modules in the django hierarchy, i.e. code in Django itself.)

answered Jul 07 '20 at 22:41

Vinay Sajip

95,872
14
179
191

After doing above step, every log is being captured twice in my log file. Can you please tell where am i doing wrong? here is the logging snippet https://slack-files.com/T04MYU6C6-F0176Q8PJEQ-30938e3c8b – Mahesh Jul 13 '20 at 19:04
2

@Mahesh it's because you've added a handler in two places. You can remove the `applogfile` handler from the `django` logger. The handler added in the root logger is also used by the `django` logger automatically. – Vinay Sajip Jul 15 '20 at 16:05

score 2 · Answer 2 · answered Dec 14 '21 at 03:39

In the example you provided, you are only setting the log level for the 'django' logger. That logger controls the log level for django.request, django.server, django.templateetc. If you are looking to set the log level for your own apps, you need to set the log level for that particular app's logger, or set it for all apps using a configuration like below

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'console_handler': {
            'class': 'logging.StreamHandler',
        },
    },
    'loggers': {
        # More info on '' (unnamed) loggers at the end of this comment
        '': {
            'level': 'INFO',
            'handlers': ['console_handler'],
        },
    },

}

The '' (unnamed) logger will process records from all loggers. More info here: https://docs.djangoproject.com/en/dev/howto/logging/#configure-a-logger-mapping

If setting an unnamed logger also does not work (no logs in console or file), what else can be done to fix this? How does one debug the case where Django apparently ignores settings or seems to simply "fail silently"? — Derek, May 13 '22 at 08:36

logger.info not working in Django logging

2 Answers2