Improve API logging

[Mark Nottingham]

Nova's API logging (in nova.api.openstack.wsgi) has a few problems:

1) It mixes in error information with what's traditionally thought of as "access" logging, making it hard to parse. It also puts a lot of english into the responses (e.g., "returned with HTTP 200").

2) Requests are double-logged, once with the request method, once with the status code.

3) Complete information isn't always logged. E.g., if any of the various returns are hit in _process_stack, the response status isn't logged.

4) Other useful information isn't captured.

I think we need to move the debug data to a separate log channel (e.g., "nova.api.openstack.wsgi.error"), normalise the access log format and capture, and add the following :

  - User-Agent request header (so we can start to understand what tools are using the API)
  - Request body size in bytes
  - Request Content-Type
  - Response body size in bytes
  - Response Content-Type
  - time to service request (for performance metrics)

I'm willing to do this work.

[Mark Nottingham (mnot)]

Actually, I've done this work, just waiting to get approved for the openstack-cla group to do the git review.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/6340

[Mark Nottingham (mnot)]

I've updated the patch to default the method and URL to "-"; I'm seeing cases where a method isn't logged, which messes up parsing.

[Mark Nottingham (mnot)]

In gerrit, Devin Carlen said:

"""
I would prefer that you didn't submit this
Not sure I understand the use for this, specifically if we were going to change this, I'm not sure why we would only change it in one place.
"""

See rationale for changes in the description of this bug. Devin, when you say "one place", do you mean to imply that API logging formats should be coordinated across OpenStack projects, or...?

[Mark Nottingham (mnot)]

Matt D said:

"""
I would rather this be configurable rather than just arbitrarily put in one place in the code. If nothing else, you're mucking with existing logging setups in established openstack clusters. With something like this, I'd rather it be opt-in.
"""

So, if I were to not muck with the existing logging code, but instead add a new logger (say, __name__ + "common", as it's similar to common log file format), would that work?

Thanks,

[Mark Nottingham (mnot)]

Trey Morris said:

"""
Patch Set 4: Do not merge
"""

Trey, could you please review the above and tell me if I'm on the right track?

Thanks,

[Thierry Carrez (ttx)]

Looks like you're not working on that anymore. Please set back to InProgress and reassign to you if you're working on proposing a change for merging.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/23639

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/23639
Committed: http://github.com/openstack/nova/commit/08906450601b502aaf36d07d56ce03d4f2270c13
Submitter: Jenkins
Branch: master

commit 08906450601b502aaf36d07d56ce03d4f2270c13
Author: Joe Gordon <email address hidden>
Date: Wed Mar 6 01:38:01 2013 +0000

    Remove duplicate API logging.

    Before each API call logged the same data three times on INFO level. We only need to log the information once.

    Fix bug 975589

    Change-Id: I24131cf9f1c27030ecc99e638e9f4126096a0b96