Django query logging

Recently I had to optimise some piece of legacy code that worked slow. Among other refactoring procedures I wanted to check what queries gets invoked exactly. Having dug Django Docs and internets I came up with solution.

Using this, you'll get all executed queries in the console

For example:

2016-02-25 15:57:47 DEBUG    utils.py:89 (0.055) SET SQL_AUTO_IS_NULL = 0; args=None
2016-02-25 15:57:47 DEBUG    utils.py:89 (0.435) SELECT `table`.`id` FROM `table` ORDER BY `table`.`id` ASC LIMIT 10000; args=()

Add the code below to your local_settings.py (or whatever it's called in your project), make sure the include of this code is AFTER defining LOGGING variable.

DB_LOG = True

from settings import LOGGING
if DB_LOG:
    import logging, re

    class QueryFilter(logging.Filter):
        def filter(self, record):
            # exclude PyCharm debug window queries
            return 'LIMIT 21' not in getattr(record, 'sql', '')


    class SqlFormatter(logging.Formatter):
        def format(self, record):
            record.msg = re.sub(r"((?:u?')?\d+(?:u?')?)"
                                r"(?:,\s*(?:u?')?\d+(?:u?')?)+",
                                r'\1, ...', record.msg)
            return super(SqlFormatter, self).format(record)

    params = {
        'filters': {
            'db_query_filter': {
                '()': QueryFilter,
            },
        },
        'formatters': {
            'debugging': {
                '()': SqlFormatter,
                'format': '%(asctime)s %(levelname)-8s %(filename)s:%(lineno)d %(message)s',
                'datefmt' : '%Y-%m-%d %H:%M:%S',
            },
        },
        'handlers': {
            'db_console': {
                'level': 'DEBUG',
                'filters': ['require_debug_true', 'db_query_filter'],
                'class': 'logging.StreamHandler',
                'formatter': 'debugging',
            },
        },
        'loggers': {
            'django.db': {
                'level': 'DEBUG',
                'handlers': ['db_console'],
                'propagate': False,
            },
        }
    }
    for key, param in params.items():
        try:
            LOGGING[key].update(param)
        except KeyError:
            LOGGING[key] = params

No more commits with debugging code

Most of you have certainly found yourself in the situation when after committing and pushing you realise you've forgotten to delete some code you added for debugging purpose? I am prone to it and after yet another doing it I decided to let git itself monitor my commits and prevent me from wrongdoing. From me does it require to put a comment in the file I do not want to be committed before all the junk is gone.

To do so, you need to create .git/hooks/pre-commit file (or append to the existing one):

#!/bin/sh

if git rev-parse --verify HEAD >/dev/null 2>&1
then
 against=HEAD
else
 # Initial commit: diff against an empty tree object
 against=4b825dc642cb6eb9a060e54bf8d69288fbee4904
fi

# Redirect output to stderr.
exec 1>&2

for F in $(git status --short -uno --porcelain | egrep -v '^D' | awk '{ printf $2"\n"; }')
do
 if grep -iq nocommit "$F"; then
  cat <<EOF
Error: '$F' containts "no commit" comment.
You must delete it before it can be committed.
EOF
  exit 1
 fi
done

And add NOCOMMIT (case insensetive) somewhere in your file that you don't want to commit, i.e.

# NOCOMMIT
import pdb
a = foo(1, 4)
pdb.set_trace()

Hope it'll save some nerves for you.