easy-django-logger 0.1.1

Django logger to log formatted logs parsable via elastic search and visualize via kibana.

Logging

---

Logging is done to remember what your code does in case you forget it someday! Apart from finding bugs/ understanding behaviour/ documentation and better visualization.

~ Sarvadim (Chapter 0, Verse 010)

django_logger

---

django_logger is a Python logging library with super powers. It leverages python logging to log anything and formats it as configured in django settings, which can be parsed via elastic search and visualized in kibana.

The default implementation uses StreamHandler() and sends all messages to stdout. Currently support for Django>=1.9.

With django_logger, you can:

• Setup your own logger format to log all logs in a specific format.
• Log a functions input/ output using just a decorator @FunctionLogger().
• Specify in settings or in decorator, paramater values you wish to hide in logs @FunctionLogger(secure_args=['password']).
• Mail logger can be set up to send log mails to ADMINS configured in django settings file appart from logging to stdout.
• Set params in log format in settings which will always be logged in every log and set their values globally only once when they change .
• and much more...

Change Log

---

0.1.0

• Function logger exit log was breaking for response of object type - FIXED
• Removed dependency on cRequestMiddleware library to keep global logs, Now global log variables can be set anywhere.
• All global log variables can be set at once by passing as {key:value}.
• Added support for Django 1.8
• Solved a minor issue of uploading to pyPi repo.
• Support for Django 1.9
• Added support for python 2.7

Installation

---

pip install django-logger

Quick start

---

1. Add DJANGO_LOGGER in django settings file.

    DJANGO_LOGGER = {
        "APP_NAME": "YOUR_APP_NAME",
        "LOGGER_NAME": "YOUR_LOGGER_NAME",
        "MAIL_LOGGER_NAME": "YOUR_MAIL_LOGGER_NAME",
        "NAMESPACE_KEY": "YOUR_APP_NAME_DATA", # optional, default: <APP_NAME>_DATA
        "SECURE_PARAMS": ('any_secure_param',), # optional, default: ()
        "LOGGING_FORMAT": {} # optional, default: {}
    }
   

2. Add these two lines in the end of settings file.

    import django_logger
   
    LOGGING = django_logger.LOGGING_FORMAT
   

3. Test - open shell python manage.py shell

    import logging
    logger = logging.getLogger('YOUR_LOGGER_NAME')
    mail_logger = logging.getLogger('YOUR_MAIL_LOGGER_NAME')
   
    logger.info('It worked..') # should print log in screen 
    mail_logger.info('It's working..') # print log and ADMINS defined in settings should get a mail too 
                                       # provided proper mail settings are in django
   

4. Happy logging. Dive deeper for better understanding.

Configuration

---

Lets see each 'key' from our DJANGO_LOGGER configuration below one by one:

DJANGO_LOGGER = {
    "APP_NAME": "APP_EX",
    "LOGGER_NAME": "LOGGER_EX",
    "MAIL_LOGGER_NAME": "MAIL_LOGGER_EX",
    "NAMESPACE_KEY": "APP_DATA_EX",
    "SECURE_PARAMS": ('password_ex',),
    "LOGGING_FORMAT": {
        # TWO DIFFERENT KEYS WITH SAME NAME BUT DIFFERENT CASE CAN ALSO BE SET
        # AVOID DOING THAT FOR CONSISTENCY BUT YES YOU HAVE FREEDOM TO DO THAT
        # FOR EX. `C` IN BELOW FORMAT

        "INT_KEY": int,
        "FLOAT_KEY": float,
        "C": str,
        "f": {
            'a': str,
            'b': int,
            'c': {
                'c': {},  # for storing dict, if you will give `dict`
                          # it will be assumed as <str>
                'd': dict, # will be assumed as <str>
            }
        },

    }
}

Now lets print this log:

import logging
logger = logging.getLogger('LOGGER_EX')
logger.info("Just an example.")

And this will be printed on console as:

{"FUNCTION":"<module>","TRACE":"","LEVEL":"INFO","APP":"APP_EX","TIME":"2018-03-09T17:06:45.975+05:30","PATH":"<ipython-input-3-6017132af706>","LOGGER":"LOGGER_EX","LINE":1,"APP_DATA_EX":{"C":"","FLOAT_KEY":"0.00","INT_KEY":"0","MESSAGE":{"TEXT": "Just an example."},"f":{"a":"","c":{"c":"{}","d":""},"b":0}}}

• APP_NAME : Name of your application which will be used in logs - APP_EX
• LOGGER_NAME : Name of logger which we have used to get this logger config - LOGGER_EX
• MAIL_LOGGER_NAME : Name of mail logger.
• NAMESPACE_KEY : Key name to be used to throw all logs data. - APP_DATA_EX
• SECURE_PARAMS : This is used while using function decorator to log input output of a function and so to just hide (log '***" instead of actual value) the params given here in tuple. see [example]
• LOGGING_FORMAT : This defines the actual log format in which its going to be logged, in key <NAMESPACE_KEY> for ex. APP_DATA_EX

LOGGING_FORMAT

---

This needs to be a dict, and should contain keys which you want in all logs (format <key_name>: type) Let's consider a use case -

You have an application service which takes a person's details, verifies it and sends it to another service to book a loan and throws error if any validation fails.

Now in your validation service you have many validator functions (Name, Aadhar, Cibil, DOB, etc. ). You would want to log some unique detail of person in every log in order to filter logs based on request or if a validation fails then to find which validator failed.

You can do this either logging 'pan_number' everytime and passing it in every function or configure this in DJANGO_LOGGER settings in LOGGING_FORMAT as:

    DJANGO_LOGGER = {
        "APP_NAME": "APP_EX",
        "LOGGER_NAME": "LOGGER_EX",
        "MAIL_LOGGER_NAME": "MAIL_LOGGER_EX",
        "NAMESPACE_KEY": "APP_DATA_EX",
        "SECURE_PARAMS": ('password_ex',),
        "LOGGING_FORMAT": {
                "PAN": <str>
            }
    }

Now everytime to log anything you will have a key PAN with default to "" as this is a string.

logger = logging.getLogger('LOGGER_EX')
logger.info("Validating aadhar..")

it logs, check key APP_DATA_EX

{"FUNCTION":"<module>","TRACE":"","LEVEL":"INFO","APP":"APP_EX","TIME":"2018-03-09T18:43:47.235+05:30","PATH":"<ipython-input-4-f0f6d8e36d79>","LOGGER":"LOGGER_EX","LINE":1,"APP_DATA_EX":{"MESSAGE":{"TEXT": "Validating aadhar.."},"PAN":""}}

Note: float, int, dict (to be given as {}) types will have default values as 0.0, 0 and {} respectively.

Now to set this PAN globally when it arrives so that by default whenever there is a log statement it will pick up value of PAN which has been set globally. It can be set as:

import django_logger
django_logger.set_global_logs({'PAN':'default_pan'})

Note: While setting this global logs as these are stored under a current thread key, make sure to clean global log before and after exit point of a request/ process as:

import django_logger
django_logger.clean_global_log()

django_logger.set_global_logs({'PAN':'TYUPS7658K'})

django_logger.clean_global_log()

So what it does is clean global log so that it doesn't pick up global log variables from previous process just to be safe. It also helps in keeping global log clean. In case your entry points are celery tasks then you can write a pre and post celery signals which cleans global log before and after executing any task. For ex:

import django_logger
from celery.signals import task_prerun, task_postrun

@task_prerun.connect()
def task_clean__global_log():
    django_logger.clean_global_log()

@task_postrun.connect()
def task_clean__global_log():
    django_logger.clean_global_log()

Now when you will log anything, after this has been set it will always log PAN.

logger = logging.getLogger('LOGGER_EX')
logger.info("Validating aadhar..")

it logs, check key APP_DATA_EX

{"FUNCTION":"<module>","TRACE":"","LEVEL":"INFO","APP":"APP_EX","TIME":"2018-03-09T18:43:47.235+05:30","PATH":"<ipython-input-4-f0f6d8e36d79>","LOGGER":"LOGGER_EX","LINE":1,"APP_DATA_EX":{"MESSAGE":{"TEXT": "Validating aadhar.."},"PAN":"default_pan"}}

Simmilarly, there can be complex configurations set in LOGGER_FORMAT to log complex data. Normal text logs goes in APP_DATA_EX['MESSAGE']['TEXT'] key.

Decorator

---

It is often the case when we want to know the behaviour of our code when it entered any function the parameters passed and what it returned. To do exactly this just put decorator @FunctionLogger() above function.

Note: Put this decorator in the end among other decorators, for ex.

@staticmethod
@FunctionLogger()
def some_static_method():
    # do some boring stuff
    pass

Now, you may not want to log values of some parameters such as password, username, api_key, third_party_key, oauth_key etc. To do this either set parameter name in settings under SECURE_PARAMS in a tuple or pass parameter name in decorator as @FunctionLogger(secure_args=['password']) and that parameter value will be logged as "****"

for example:

# configuration
DJANGO_LOGGER = {
    "APP_NAME": "APP_EX",
    "LOGGER_NAME": "LOGGER_EX",
    "MAIL_LOGGER_NAME": "MAIL_LOGGER_EX",
    "NAMESPACE_KEY": "APP_DATA_EX",
    "SECURE_PARAMS": ('password_ex',),
    "LOGGING_FORMAT": {}
}

# sample function 
from django_logger import FunctionLogger

@FunctionLogger(secure_args=['username'])
def func_args(text, username, password_ex): # name of parameter should be exactly same as in configuration
    return text + " Username - " + password_ex

# call this function
func_args("Hello",'testing','test123')

# this will log
{"FUNCTION":"func_args","TRACE":"","LEVEL":"INFO","APP":"APP_EX","TIME":"2018-03-12T12:26:38.122+05:30","PATH":"<ipython-input-4-fb5235935e60>","LOGGER":"LOGGER_EX","LINE":1,"APP_DATA_EX":{"MESSAGE":{"TEXT": "Entering func_args", "ARGS": "NamedArgs(text='Hello', username='*******', password_ex='*******')", "KWARGS": ""}}}
{"FUNCTION":"func_args","TRACE":"","LEVEL":"INFO","APP":"APP_EX","TIME":"2018-03-12T12:26:38.122+05:30","PATH":"<ipython-input-4-fb5235935e60>","LOGGER":"LOGGER_EX","LINE":1,"APP_DATA_EX":{"MESSAGE":{"TEXT": "Exiting func_args", "ARGS": "Hello Username - test123", "KWARGS": ""}}}


# Outputs
'Hello Username - test123'

As you can see in logs, it logged username and password as "*****" but not text.

Examples:

---

Configuration:

# put this in django settings file
DJANGO_LOGGER = {
    "APP_NAME": "APP_EX",
    "LOGGER_NAME": "LOGGER_EX",
    "MAIL_LOGGER_NAME": "MAIL_LOGGER_EX",
    "NAMESPACE_KEY": "APP_DATA_EX",
    "SECURE_PARAMS": ('password_ex',),
    "LOGGING_FORMAT": {
        # TWO DIFFERENT KEYS WITH SAME NAME BUT DIFFERENT CASE CAN ALSO BE SET
        # AVOID DOING THAT FOR CONSISTENCY BUT YES YOU HAVE FREEDOM TO DO THAT
        # FOR EX. `C` IN BELOW FORMAT

        "INT_KEY": int,
        "FLOAT_KEY": float,
        "C": str,
        "f": {
            'a': str,
            'b': int,
            'c': {
                'c': {},  # for storing dict, if you will give `dict`
                          # it will be assumed as <str>
                'd': dict, # will be assumed as <str>
            }
        },

    }
}

import django_logger
LOGGING = django_logger.LOGGING_FORMAT

Executing all this in python manage.py shell :

import logging
logger = logging.getLogger('LOGGER_EX')

1. Log simple warning:

    logger.warning("Validation failed for loan {} .".format('loan_id'))
    {"FUNCTION":"<module>","TRACE":"","LEVEL":"WARNING","APP":"APP_EX","TIME":"2018-03-12T12:49:18.205+05:30","PATH":"<ipython-input-3-b18d0a456c9e>","LOGGER":"LOGGER_EX","LINE":1,"APP_DATA_EX":{"C":"","FLOAT_KEY":"0.00","INT_KEY":"0","MESSAGE":{"TEXT": "Validation failed for loan loan_id ."},"f":{"a":"","c":{"c":"{}","d":""},"b":0}}}
   

2. Log with some arguments:

   Note: key MESSAGE AND KWARGS must be there else they will not be logged.

    logger.info({
        "MESSAGE": "API request invoked by client {}.".format("some client"),
   
        # It's better to give same key names inside `kwargs` in all logs, as they can be used later to visualize too for ex. api request data as `DATA` and response as `RESPONSE`.
        # so all api logs will have same signature in `kwargs`
        "KWARGS": {
            "CLIENT_ID": "123",
            "DATA": {"name":"abc","loan_id":"1234"} # it can be request.data but if that is too much data then try to put only required information
            }
    })
   
   
    {"FUNCTION":"<module>","TRACE":"","LEVEL":"INFO","APP":"APP_EX","TIME":"2018-03-12T12:56:18.489+05:30","PATH":"<ipython-input-6-6cc8d5e6eaa6>","LOGGER":"LOGGER_EX","LINE":5,"APP_DATA_EX":{"C":"","FLOAT_KEY":"0.00","INT_KEY":"0","MESSAGE":{"TEXT": "API request invoked by client some client.", "ARGS": "", "KWARGS": "{'DATA': {'loan_id': '1234', 'name': 'abc'}, 'CLIENT_ID': '123'}"},"f":{"a":"","c":{"c":"{}","d":""},"b":0}}}
   

3. Log entry-exit for a function having args and kwargs.

    from django_logger import FunctionLogger
    @FunctionLogger()
    def my_func(a,b=2,c=0,d="hello"):
        return a,b,c,d
   
    print my_func(1,2,c=3,d="Namaste")
   

   Note: As argument b was not passed as kwargs so it will be treated as args only.

        {"FUNCTION":"my_func","TRACE":"","LEVEL":"INFO","APP":"APP_EX","TIME":"2018-03-12T13:05:38.638+05:30","PATH":"<ipython-input-9-33c4f49cceb9>","LOGGER":"LOGGER_EX","LINE":2,"APP_DATA_EX":{"C":"","FLOAT_KEY":"0.00","INT_KEY":"0","MESSAGE":{"TEXT": "Entering my_func", "ARGS": "NamedArgs(a=1, b=2)", "KWARGS": "{'c': 3, 'd': 'Namaste'}"},"f":{"a":"","c":{"c":"{}","d":""},"b":0}}}
        {"FUNCTION":"my_func","TRACE":"","LEVEL":"INFO","APP":"APP_EX","TIME":"2018-03-12T13:05:38.638+05:30","PATH":"<ipython-input-9-33c4f49cceb9>","LOGGER":"LOGGER_EX","LINE":2,"APP_DATA_EX":{"C":"","FLOAT_KEY":"0.00","INT_KEY":"0","MESSAGE":{"TEXT": "Exiting my_func", "ARGS": "(1, 2, 3, 'Namaste')", "KWARGS": ""},"f":{"a":"","c":{"c":"{}","d":""},"b":0}}}
   
        # output
        (1, 2, 3, 'Namaste')
   

Contribution guidelines

---

• Writing tests - Always welcome to improve on this, at this time its greater than 90%.

• Other guidelines - Feel free to suggest any more feature or raise a pull request.

Who do I talk to?

---

• Author - Niranjan Singh