Solum/Logging

In order to prevent accidental leakage of confidential information to unauthorized Solum users, there are some guidelines to assist in isolating this confidential data for easy/accurate filtering on the back end log management tools. Why is this important? There have been several OpenStack security issues around logging recently:

(Ceilometer) Log contains DB password in plain text (CVE-2013-6384) [OSSA 2013-031]
(Keystone) Plaintext passwords are logged
(Nova) Clear text password has been print in log by some API call

etc...

Logs should have a format that enables grouping of confidential data especially when logging data such as:

Exceptions: Unless the developer is sure that an exception will never contain confidential information, exceptions should be identified as confidential. This has historically been especially problematic with database exceptions which may contain real field data.
- Recommend parsing the specific exception or error and providing an abstracted/safe version back to the user
Passwords: Never log plain text passwords
Private Keys: Never log plain text private keys
PII: Minimize Personally Identifiable Information (PII) logging where possible
Local Server State: Avoid logging local server state which may provide hints to attackers (examples: file paths, code file names, user account names, PRNG state)
Tenant/Project ID Checking: If a user identifier (tenant/project ID) is not present in the log record or does not match the current authenticated user, do not show this log data to the user
Log Insecure Configurations: If a Solum configuration option causes the system to enter a potentially less secure state, log a message to this effect for operators to see

OpenStack's Oslo Log is capable of creating formatted logs with a section for confidential data. The following example contains two pieces of variable data: key_name which is not confidential data (and will equal 'ssh') and key_value which is a confidential key that should not be visible to anyone but Solum admins/operators.

Note: This is a contrived example for simplicity. If the key_value is a public ssh key, it probably isn't critical to hide it in the logs from the authorized user that it belongs to. If the key_value is a private ssh key, it shouldn't be logged to begin with.

Bad Example:

LOG.debug("User set %s key to value %s" % [key_name, key_value])

Revised/Good Example:

LOG.debug("User set %s key" % [key_name], extra={private={value=key_value}})

Note that the extra->private structure is used to hold all confidential data within logs so that it may be filtered out later before a user views logs. In this example, the key value is moved to a 'private' dictionary which makes filtering out confidential data from logs easier as there will be a single keyword to locate in log entries if Solum adheres to these guidelines. An authenticated user may see that an ssh key has been changed but a Solum operator may see the actual ssh key value in the logs.

Log level definitions: http://stackoverflow.com/questions/2031163/when-to-use-log-level-warn-vs-error This is a nice writeup about when to use each log level. Here is a brief description:

Debug: Shows everything and is likely not suitable for normal production operation due to the sheer size of logs generated
Info: Usually indicates successful service start/stop, versions and such non-error related data
Warning: Indicates that there might be a systemic issue; potential predictive failure notice
Error: An error has occurred and an administrator should research the event
Critical: An error has occurred and the system might be unstable; immediately get administrator assistance

Example of Oslo Log and Oslo Context:

This is an example of the combination of Oslo log and Oslo context

This demonstrates the ability to manipulate the context data which is logged and modify the format. This enables the ability to filter certain private data based on the log format used. When new context is added into RequestContext (or rather the inheriting class in most cases) the log format may be changed to add the new context into logs.

from oslo.config import cfg
from solum.openstack.common import context
from solum.openstack.common import log

LOG = log.getLogger(__name__)
log.setup('solum')
CONTEXT = context.RequestContext(user='John Doe', tenant='test tenant')
LOG.error('Standard context log output', context=CONTEXT)

CONF = cfg.CONF
CONF.logging_context_format_string = (
    "%(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s "
    "{'private': {'user': %(user)s, 'tenant': %(tenant)s}} "
    "%(instance)s%(message)s]}")
LOG.error('Modified context log output', context=CONTEXT)

Output:

2014-01-23 20:48:30.156 22345 ERROR __main__ [req-1a007cc5-cce8-4a63-8572-99e1148c784c John Doe test tenant] Standard context log output
2014-01-23 20:48:30.157 22345 ERROR __main__ {'private': {'user': John Doe, 'tenant': test tenant}} Modified context log output]}