Keeping PHI out of your application logs

Logs are the other copy

A log line is written whether or not anything goes wrong. A busy patient portal writes thousands an hour: every request, often every query, every job, every call to a lab or payer API. Those lines are shipped to a log pipeline, indexed for search, kept for months and read by anyone debugging anything, so one careless line can copy a patient's details thousands of times before anyone notices.

Most of it isn't written by you. Frameworks and libraries log on your behalf, and their defaults are made for debugging, not for health data. These are the usual places it gets in:

• The request line: the path and query string of every request (/patients/jane-doe/chart, /search?dob=1961-04-02)
• Request parameters, which some frameworks log for every request
• SQL statements and their bind values, at debug level
• Background job arguments, logged when a job is queued, when it runs and when it fails
• Exceptions the framework logs for you, message and all
• HTTP client debug output, with headers, query strings and sometimes bodies
• Your own log lines, written to be helpful: "Refill requested for Jane Doe"

The sections below take each one in turn, with the fix in Rails, Python and Node. None of them needs a new product: they're settings and a few lines of code in the logging you already have.

Request lines and parameters

Rails logs every request's parameters, filtered by config.filter_parameters. A new Rails app gets a list that covers passwords, tokens, secrets, email addresses, SSNs and card security codes, and each entry is a partial match, so :passw catches password and password_confirmation. Nothing in it knows about health data: a date of birth, a medical record number, a diagnosis or a free-text note is logged as it was typed. Add your own names to the list Rails generated:

Ruby, config/initializers/filter_parameter_logging.rb

Rails.application.config.filter_parameters += [
  :passw, :email, :secret, :token, :_key, :crypt, :salt, :certificate, :otp, :ssn, :cvv, :cvc,
  # Health data. Each is a partial match: :name covers first_name and last_name.
  :name, :dob, :birth, :mrn, :member_id, :diagnosis, :medication, :phone, :address, :notes,
  # Search boxes. A regular expression matches the whole key, so this is only "q",
  # where a plain :q would also filter request_id and quantity.
  :search, /\Aq\z/
]

Ruby: what the filter does, runnable on its own

require "active_support"
require "active_support/parameter_filter"

filter = ActiveSupport::ParameterFilter.new(%i[passw email ssn name dob mrn diagnosis])
params = {
  "patient" => { "first_name" => "Jane", "dob" => "1961-04-02", "mrn" => "A1234", "clinic_id" => 7 },
  "q" => "jane doe"
}
p filter.filter(params)

The second example prints first_name, dob and mrn as [FILTERED], keeps clinic_id, and logs "q" => "jane doe" as it is. Partial matching cuts both ways: :name also filters username and file_name, which is usually a fair price, and a search field isn't filtered until you name it, because nothing in a key like q says what people type into it. For a name that short, use a regular expression that matches the whole key, as in the initializer above.

The same list filters the query string in Rails' "Started GET" line, by parameter name, but it can't touch the path: /patients/jane-doe/chart is logged as it is. That fix is in your routes. Put ids in paths, never names, emails or dates of birth, and send searches in a request body or under a filtered parameter.

Then check what else logs the URL. Most web servers, proxies and load balancers write the full URL with its query string to an access log by default, and that log usually sits outside your application entirely.

SQL and bind values

SQL logging is debug output, and production rarely needs to run at debug level. Rails 8 logs at :info in production by default (RAILS_LOG_LEVEL), which leaves SQL out. At debug, Rails logs each statement with its bind values and filters a bind whose column name matches filter_parameters, so the list above protects SQL logs too. A value written into the SQL string itself, by string interpolation or in a literal IN list, isn't a bind, and isn't filtered.

Python's ORMs are similar. Django logs queries through the django.db.backends logger only when DEBUG is on. SQLAlchemy logs every statement with its parameters when echo is on, unless you tell it to leave the values out:

Python, SQLAlchemy

import os

from sqlalchemy import create_engine, text

# echo=True logs every statement. hide_parameters=True keeps the values out of
# those log lines, and out of the text of any database error SQLAlchemy raises.
engine = create_engine(os.environ["DATABASE_URL"], echo=True, hide_parameters=True)

with engine.connect() as connection:
    connection.execute(
        text("SELECT id FROM patients WHERE last_name = :last_name"),
        {"last_name": "Doe"},
    )

Leave echo off in production anyway: a statement's text says which table it read and which columns it searched on, which can be revealing on its own.

Background job arguments

A job's arguments are logged when it's queued and when it runs, and kept in the queue's own store until it finishes, or longer if it fails. Pass a patient object or a hash of their details, and every one of those copies has it. Active Job logs arguments by default. A job can turn that off for itself and its subclasses, as below, or config.active_job.log_arguments = false turns it off for every job:

Ruby, app/jobs/send_lab_results_job.rb

class SendLabResultsJob < ApplicationJob
  self.log_arguments = false

  # Takes an id, not the record: the job looks the patient up when it runs,
  # so its arguments say nothing about them wherever they're shown.
  def perform(lab_result_id)
    lab_result = LabResult.find(lab_result_id)
    LabResultMailer.ready(lab_result).deliver_now
  end
end

# SendLabResultsJob.perform_later(lab_result.id)

Passing ids is the bigger fix of the two. log_arguments only changes Rails' own log lines, while an id stays harmless in the queue's storage, its dashboard and its list of failed jobs too. Failed jobs matter most, because job systems keep their arguments so they can retry them, and show them next to the error.

Exceptions the framework logs for you

When a request fails, the framework logs the exception before it renders the error page. Rails writes the exception's class, message and backtrace to the log. Django's django.request logger records "Internal Server Error" with the request's path and the traceback. Express's default error handler prints the stack, message included, to stderr. So every exception message that names a patient lands in your logs as well as in your error tracker, and the logs keep it longer.

The fix is the same in both places: build messages from ids and codes, never from names, dates or diagnoses. "No pharmacy on file for patient 8812" is just as useful while you debug, and you can look the patient up when you need to. For messages you don't control, such as a library's error that quotes the value it rejected, catch the error at the boundary and raise your own, with the original kept as its cause in code rather than copied into the text.

HTTP client debug logs

Calls to labs, pharmacies and payers carry the most sensitive data in the app, in query strings, headers and bodies, and an HTTP client's logging prints exactly those. Faraday's logger middleware logs request and response headers unless you say otherwise, Authorization included, and every URL with its query string. Turn headers off, leave bodies off, and filter what's left:

Ruby, Faraday

require "faraday"
require "logger"

conn = Faraday.new(url: "https://api.payer.example") do |f|
  # headers: true is Faraday's default, and would log the Authorization header.
  f.response :logger, Logger.new($stdout), headers: false, bodies: false do |logger|
    logger.filter(/(member_id=)[^&\s"]+/, '\1[FILTERED]')
  end
end

conn.get("/eligibility", { member_id: "A12345678", plan: "gold" }, { "Authorization" => "Bearer abc" })

That logs request: GET https://api.payer.example/eligibility?member_id=[FILTERED]&plan=gold and the response's status, nothing else.

In Python, urllib3 (which requests uses) logs each request's method, path and query string at debug level, and http.client prints raw headers when its debuglevel is set. Keep the urllib3 logger at WARNING in production with logging.getLogger("urllib3").setLevel(logging.WARNING), and never leave a debuglevel on. In Node, keep debugging switches such as NODE_DEBUG out of your production environment.

Structured logs with an allowlist

Filters and redaction lists are denylists: they remove the fields someone thought of. The dependable pattern is the opposite. Log events with named fields, and let a field through only when it's on a short list of keys you've decided are safe, so a new field nobody reviewed is dropped by default instead of logged by default. It's the same idea as strict privacy in an error tracker.

In Python, one formatter can do it for every logger at once. This one logs each call's own words and never its arguments, keeps the allowed fields, names the ones it dropped, and records an exception's type and location without its message:

Python, standard library only

import json
import logging
import sys
import traceback

# The only keys a log line may carry. Anything else is dropped by name.
ALLOWED_FIELDS = {"request_id", "route", "status", "duration_ms", "patient_id", "error_code"}


class AllowlistJsonFormatter(logging.Formatter):
    def format(self, record):
        entry = {
            "time": self.formatTime(record),
            "level": record.levelname,
            "logger": record.name,
            # The call's own words, never its arguments: "Refill requested for %s"
            # is logged, the name that would have filled the %s is not.
            "event": str(record.msg),
        }
        fields = getattr(record, "fields", {})
        entry.update({key: value for key, value in fields.items() if key in ALLOWED_FIELDS})
        dropped = sorted(key for key in fields if key not in ALLOWED_FIELDS)
        if dropped:
            entry["dropped_fields"] = dropped
        if record.exc_info:
            error_type, _, tb = record.exc_info
            # The exception's type and where it happened, not its message.
            entry["error_type"] = error_type.__name__
            entry["error_at"] = [
                "{}:{} in {}".format(frame.filename, frame.lineno, frame.name)
                for frame in traceback.extract_tb(tb)
            ]
        return json.dumps(entry)


handler = logging.StreamHandler(sys.stdout)
handler.setFormatter(AllowlistJsonFormatter())
logging.basicConfig(level=logging.INFO, handlers=[handler])
log = logging.getLogger("pharmacy")

log.info("Refill requested for %s", "Jane Doe", extra={"fields": {
    "route": "/patients/<int:patient_id>/refills",
    "patient_id": 8812,
    "medication": "sertraline 50mg",
}})

try:
    raise LookupError("No pharmacy on file for Jane Doe")
except LookupError:
    log.exception("Refill failed", extra={"fields": {"patient_id": 8812, "error_code": "NO_PHARMACY"}})

It prints two JSON lines. The first has the event "Refill requested for %s", the route and patient_id, and lists medication under dropped_fields. The second has error_code, error_type LookupError and the file and line it was raised on, but not "No pharmacy on file for Jane Doe".

A patient id is far less than a name, but it still points at one patient, so treat even an allowlisted log as sensitive data.

Node: redact or allowlist

pino has redaction built in: list the paths that can hold personal data, and they're replaced before the line is written. It's fast and easy to add to an existing app, but it's still a denylist, so a field you didn't list goes out. winston has no redaction setting, but a custom format can keep an allowlist in a few lines, as in the second example:

JavaScript, pino (redact.mjs)

import pino from "pino";

const logger = pino({
  redact: {
    paths: [
      "req.headers.authorization",
      "req.headers.cookie",
      "patient.name",
      "patient.dob",
      "*.email",
    ],
    censor: "[FILTERED]",
  },
});

logger.info(
  {
    req: { method: "GET", headers: { authorization: "Bearer eyJhbGciOi", cookie: "session=abc" } },
    patient: { id: 8812, name: "Jane Doe", dob: "1961-04-02", email: "jane@example.com" },
    route: "/patients/:id/chart",
  },
  "chart opened",
);

JavaScript, winston (allowlist.mjs)

import winston from "winston";

// The only fields a log line may carry, besides its level, message and time.
const ALLOWED = new Set(["request_id", "route", "status", "duration_ms", "patient_id", "error_code"]);
const ALWAYS_KEPT = new Set(["level", "message", "timestamp"]);

const allowlist = winston.format((info) => {
  for (const key of Object.keys(info)) {
    if (!ALWAYS_KEPT.has(key) && !ALLOWED.has(key)) delete info[key];
  }
  return info;
});

const logger = winston.createLogger({
  level: "info",
  format: winston.format.combine(allowlist(), winston.format.timestamp(), winston.format.json()),
  transports: [new winston.transports.Console()],
});

logger.info("appointment booked", {
  route: "/appointments/:id",
  patient_id: 8812,
  patient_name: "Jane Doe",
  reason: "follow-up on biopsy results",
});

The pino line keeps the route and the patient's id, with the authorization header, cookie, name, date of birth and email replaced by [FILTERED]. The winston line keeps only route and patient_id: patient_name and reason are dropped without anyone having listed them. Either way, keep the message itself a fixed description of the event, and put values in fields where the rules can see them.

Retention and access

Whatever gets through, logs are a store of data like any other, and usually a less guarded one than the database. A few habits limit what a mistake costs:

• Keep logs only as long as you use them. Debugging rarely needs more than a few weeks, and an audit trail belongs in its own store, with its own rules.
• Limit who can search production logs, and record who did.
• Know every place your logs go: the pipeline, its archive, a copy in object storage, a support tool. Each is somewhere PHI can end up, under whatever agreement you have with that service.
• Don't paste log lines into chat or tickets. Link to them, so access rules still apply.
• Test it: send a request with made-up patient details in staging, then search every log store for the name.

None of this settles your obligations under HIPAA on its own: those depend on your whole setup, including what your apps send where, your agreements with the services you use and your own policies. Treat the code above as a starting point, and check it against your own requirements.