Logging private data

Question

In general, I write a debug log whenever one of my functions is entered, including the parameters.

For instance:

    function execute_query($query, $conn_string)
    {
        $this->log->debug(sprintf('Entering execute_query(query=%s, conn_string=%s)', $query, $conn_string));
        //Do Stuff
    }

The potential problem that I see is that the parameter could contains private data (e.g. connection string could contain a username and password) and it will be written to the log.

That being said, when developing the application I have the logger set to include the debug level, and I would actually find this helpful. When deploying to production I would expect the level to be set to info or error, and so the username/password would never be written to the log.

Is there a best practice around this?

Answer 1

We had a highly escalated support case once about passwords being printed in the log file and as you can imagine, management jumped into fire-fighting mode, directing the devs to fix it 'by all means necessary.'

I'm not sure which language you're using, but here are the several measures that can be taken:

1. Some logging frameworks themselves have filtering capabilities, tailored to filter out passwords (example) - see if yours has such a feature
2. If you can isolate the password-printing culprits to a set of packages/classes, then disable them entirely for INFO/higher levels (log4j allows doing this easily). For instance, disabling logging for the Hibernate package(s) gets rid of all the ORM-related logs that may contain connection strings having passwords in them.
3. If you use internationalization (I10n), then strip all the password-printing messages from the resource file

4. In cases where you want to only obfuscate the password and continue printing the rest of the log message,

   a. Create a custom log handler/formatter in whichever logging library you're using such that all logs pass through your own function

   b. Add some logic here to replace the password string (identified in various ways in the log message, such as searching for "password=..." or matching a regex) with asterisks

   c. Ensure that this 'filter' function is only called for a particular log level (preferably DEBUG only) and only when the configured log level is <= to that. This is likely going to be a performance hit and you wouldn't want to run ALL log messages through this filter)

(4) above can be easily done in Python as follows:

class PasswordSafeLogFormatter(logging.Formatter):
""" Custom formatter that obfuscates passwords """

def format(self, record):
    """
    Search the log message for a password-like string and obfuscate it

    :param record: Logging record
    :return: Formatted message
    """
    PASSWORD_REGEX = r'password=.*' # Regular expression that matches a password present in a log
    PASSWORD_SUBSTITUTION = r'password=****' # Obfuscated text to be inserted in the log

    record.message = re.sub(PASSWORD_REGEX,PASSWORD_SUBSTITUTION, record.message)

    return super(PasswordSafeLogFormatter, self).format(record)

def initialize_logger():
    """ Initializes the logging module for the application """
    root_logger = logging.getLogger()

    file_log_handler = RotatingFileHandler(log_file_path, maxBytes=LOG_FILE_ROTATION_BYTES,
                                           backupCount=LOG_FILE_RETENTION_COUNT)
    formatter = PasswordSafeLogFormatter(LOG_FORMAT_SPECIFIER)
    file_log_handler.setFormatter(formatter)
    root_logger.addHandler(file_log_handler)

Note: This code snippet filters all log messages and blatantly ignores (4)c above - don't use it AS-IS!