logging response content length using bottle and cherrypy

Question

I am using bottle with cherrypy (which provides the WSGI) for a web application. CherryPy does not log web-access in this setup. Currently, I am almost logging everything using bottle's hook plug-in, like so:

import bottle
from bottle import route, static_file, get, post, error, request, template, redirect, response, hook

@hook('after_request')
def log_after_request():
    try:
        length = response.content_length
    except:
        try:
            length = len(response.body)
        except:
            length = '???'
    print '{ip} - - [{time}] "{method} {uri} {protocol}" {status} {length}'.format(
        ip=request.environ.get('REMOTE_ADDR'),
        time=datetime.datetime.now().strftime('%Y-%m-%d %H:%M:%S'),
        method=request.environ.get('REQUEST_METHOD'),
        uri=request.environ.get('REQUEST_URI'),
        protocol=request.environ.get('SERVER_PROTOCOL'),
        status=response.status_code,
        length=length,
    )

@route('/index.html')
def index_handler():
    return '<h1>Hello, world!</h1>'

app = bottle.default_app()
bottle.run(host='0.0.0.0', port='80', app=app, server='cherrypy', request_queue_size=300, debug=True)

This provides log entries to STDOUT, like so:

192.168.1.1 - - [2013-07-23 17:04:04] "GET /index.html HTTP/1.1" 200 0

This is almost correct, except the content-length is always 0. It appears that bottle is unaware of the content-length as returned by cherrypy. Is this a correct assessment, and more importantly, is there a way to retrieve it, so I can log it?

I am open to better ways to obtain access logging using bottle and cherrypy.

Thanks!

Answer 1

I can think of several approaches, but here's the one I think is best: use a middleware app to log the requests.

Here's a complete example based on the code in your question. (I haven't changed log_after_request; most of the action is in AccessLogMiddleware.__call__.)

import datetime
import bottle
from bottle import route, static_file, get, post, error, request, template, redirect, response, hook

# unchanged from OP
@route('/index.html')
def index_handler():
    return '<h1>Hello, world!</h1>'

# unchanged from OP
def log_after_request():
    try:
        length = response.content_length
    except:
        try:
            length = len(response.body)
        except:
            length = '???'
    print 'MYLOG:', '{ip} - - [{time}] "{method} {uri} {protocol}" {status} {length}'.format(
        ip=request.environ.get('REMOTE_ADDR'),
        time=datetime.datetime.now().strftime('%Y-%m-%d %H:%M:%S'),
        method=request.environ.get('REQUEST_METHOD'),
        uri=request.environ.get('REQUEST_URI'),
        protocol=request.environ.get('SERVER_PROTOCOL'),
        status=response.status_code,
        length=length,
    )

# code I've added begins here
class AccessLogMiddleware(object):
    def __init__(self, app):
        self.app = app

    def __call__(self, e, h):
        # call bottle and store the return value
        ret_val = self.app(e, h)

        # log the request
        log_after_request()

        # return bottle's return value
        return ret_val


app = bottle.app()
logged_app = AccessLogMiddleware(app)
bottle.run(host='0.0.0.0', port='8000', app=logged_app)

That should do the trick; if not, let me know and I'll help.

Answer 2

Code in the original question now works when you update to the Bottle 0.13-dev branch which isn't officially released yet. The latest stable 0.12.18 released branch still has this bug and will still return 0 for response content length.

After updating to 0.13 (which you can grab here: https://github.com/bottlepy/bottle), the code now works.