Structured Logging

Structured Logging makes Liquibase operation data easily available and machine-readable. You can use monitoring and analysis tools to read, query, and act upon this data in automated workflows. Liquibase not only does the tricky work of database schema versioning and management, it also helps you understand the data around these operations and how they fit into your overall DevOps and CI/CD performance.

Tools you can use with Liquibase Structured Logging include AWS Cloudwatch, Granfana, Opensearch, Sematext, Splunk, ElasticSearch and other analysis instruments. Monitoring and analysis tools can easily determine and act upon both real-time and long-term trend data for Liquibase usage with Structured Logging. Other data that Liquibase can use are performance, errors, security, tracking for auditablility and outcomes, and even standard DORA DevOps metrics.

Liquibase uses a Mapped Diagnostic Context (MDC) to generate structured logs in a JSON format.

This feature is available in Liquibase 4.21.0 and later. Additional functionality is available in later releases.

Examples

[2023-02-27 16:37:00] FINE [liquibase.integration] Performance monitoring disabled
[2023-02-27 16:37:00] FINE [liquibase.configuration] No configuration value for liquibase.outputFile found
[2023-02-27 16:37:00] FINE [liquibase.configuration] No configuration value for liquibase.strict found

--log-format=JSON does not have any line breaks because it is intended for machine parsing and consumption by industry standard log tools.

Starting Liquibase at 16:40:53 (version [Core: //DAT-11693/7176/44d487/2023-02-09 14:35+0000, Pro: DAT-11693/2749/7aac10/2023-02-09T14:30:34Z] #7176 built at 2023-02-09 14:35+0000)
Liquibase Version: [Core: //DAT-11693/7176/44d487/2023-02-09 14:35+0000, Pro: DAT-11693/2749/7aac10/2023-02-09T14:30:34Z]
Liquibase Labs [Core: //DAT-11693/7176/44d487/2023-02-09 14:35+0000, Pro: DAT-11693/2749/7aac10/2023-02-09T14:30:34Z] by Liquibase licensed to Dev until Sat Dec 30 22:59:59 CST 2023
{"timestamp":"2023-02-27T22:40:53.029Z","level":"INFO","class":"liquibase.integration","thread":"1","message":"Starting command execution.","liquibaseVersion":"DEV","liquibaseSystemUser":"mariochampion","liquibaseSystemName":"mmc-mbp.lan"}
{"timestamp":"2023-02-27T22:40:53.131Z","level":"INFO","class":"liquibase.license","thread":"1","message":"Successfully installed license from Base64 string starting with 'ABwwGgQU6h' (property liquibaseProLicenseKey).\n","liquibaseOperation":"update"}
{"timestamp":"2023-02-27T22:40:53.272Z","level":"INFO","class":"liquibase.database","thread":"1","message":"Set default schema name to PUBLIC","liquibaseOperation":"update","liquibaseCommandName":"update"}
{"timestamp":"2023-02-27T22:40:53.439Z","level":"INFO","class":"liquibase.lockservice","thread":"1","message":"Successfully acquired change log lock","liquibaseOperation":"update","liquibaseCommandName":"update","changesetSql":"INSERT INTO PUBLIC.DATABASECHANGELOGLOCK (ID, LOCKED) VALUES (1, FALSE)"}
{"timestamp":"2023-02-27T22:40:53.450Z","level":"INFO","class":"liquibase.changelog","thread":"1","message":"Creating database history table with name: PUBLIC.DATABASECHANGELOG","liquibaseOperation":"update","liquibaseCommandName":"update","changesetSql":"INSERT INTO PUBLIC.DATABASECHANGELOGLOCK (ID, LOCKED) VALUES (1, FALSE)","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":""}
{"timestamp":"2023-02-27T22:40:53.455Z","level":"INFO","class":"liquibase.changelog","thread":"1","message":"Reading from PUBLIC.DATABASECHANGELOG","liquibaseOperation":"update","liquibaseCommandName":"update","changesetSql":"CREATE TABLE PUBLIC.DATABASECHANGELOG (ID VARCHAR(255) NOT NULL, AUTHOR VARCHAR(255) NOT NULL, FILENAME VARCHAR(255) NOT NULL, DATEEXECUTED TIMESTAMP NOT NULL, ORDEREXECUTED INT NOT NULL, EXECTYPE VARCHAR(10) NOT NULL, MD5SUM VARCHAR(35), DESCRIPTION VARCHAR(255), COMMENTS VARCHAR(255), TAG VARCHAR(255), LIQUIBASE VARCHAR(20), CONTEXTS VARCHAR(255), LABELS VARCHAR(255), DEPLOYMENT_ID VARCHAR(10))","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":""}
Running Changeset: example-changelog.sql::1::devone
{"timestamp":"2023-02-27T22:40:53.484Z","level":"INFO","class":"liquibase.changelog","thread":"1","message":"Custom SQL executed","liquibaseOperation":"update","liquibaseCommandName":"update","changesetSql":"create table person (\n    id int primary key auto_increment not null,\n    name varchar(50) not null,\n    address1 varchar(50),\n    address2 varchar(50),\n    city varchar(30)\n)","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462","changesetId":"1","changesetAuthor":"devone","changesetFilepath":"example-changelog.sql","changesetComment":"example comment","changesetLabel":"example-label","changesetContext":"()","changesetOperationStart":"2023-02-27T16:40:53.477"}
{"timestamp":"2023-02-27T22:40:53.488Z","level":"INFO","class":"liquibase.changelog","thread":"1","message":"ChangeSet example-changelog.sql::1::devone ran successfully in 12ms","liquibaseOperation":"update","liquibaseCommandName":"update","changesetSql":"create table person (\n    id int primary key auto_increment not null,\n    name varchar(50) not null,\n    address1 varchar(50),\n    address2 varchar(50),\n    city varchar(30)\n)","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462","changesetId":"1","changesetAuthor":"devone","changesetFilepath":"example-changelog.sql","changesetComment":"example comment","changesetLabel":"example-label","changesetContext":"()","changesetOperationStart":"2023-02-27T16:40:53.477","changesetOperationStop":"2023-02-27T16:40:53.488","changesetOutcome":"executed"}
Running Changeset: example-changelog.sql::2::anotherdev
{"timestamp":"2023-02-27T22:40:53.502Z","level":"INFO","class":"liquibase.changelog","thread":"1","message":"Custom SQL executed","liquibaseOperation":"update","liquibaseCommandName":"update","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462","changesetId":"2","changesetAuthor":"anotherdev","changesetFilepath":"example-changelog.sql","changesetComment":"example comment","changesetLabel":"example-label","changesetContext":"example-context","changesetOperationStart":"2023-02-27T16:40:53.499","changesetSql":"create table company (\n    id int primary key auto_increment not null,\n    name varchar(50) not null,\n    address1 varchar(50),\n    address2 varchar(50),\n    city varchar(30)\n)"}
{"timestamp":"2023-02-27T22:40:53.504Z","level":"INFO","class":"liquibase.changelog","thread":"1","message":"ChangeSet example-changelog.sql::2::anotherdev ran successfully in 5ms","liquibaseOperation":"update","liquibaseCommandName":"update","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462","changesetId":"2","changesetAuthor":"anotherdev","changesetFilepath":"example-changelog.sql","changesetComment":"example comment","changesetLabel":"example-label","changesetContext":"example-context","changesetOperationStart":"2023-02-27T16:40:53.499","changesetSql":"create table company (\n    id int primary key auto_increment not null,\n    name varchar(50) not null,\n    address1 varchar(50),\n    address2 varchar(50),\n    city varchar(30)\n)","changesetOperationStop":"2023-02-27T16:40:53.504","changesetOutcome":"executed"}
Running Changeset: example-changelog.sql::e24850bc-2310-11ed-861d-0242ac120002::mr.man
{"timestamp":"2023-02-27T22:40:53.516Z","level":"INFO","class":"liquibase.changelog","thread":"1","message":"Custom SQL executed","liquibaseOperation":"update","liquibaseCommandName":"update","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462","changesetId":"e24850bc-2310-11ed-861d-0242ac120002","changesetAuthor":"mr.man","changesetFilepath":"example-changelog.sql","changesetComment":"example comment","changesetLabel":"example-label","changesetContext":"example-context","changesetOperationStart":"2023-02-27T16:40:53.512","changesetSql":"alter table person add column country varchar(2)"}
{"timestamp":"2023-02-27T22:40:53.518Z","level":"INFO","class":"liquibase.changelog","thread":"1","message":"ChangeSet example-changelog.sql::e24850bc-2310-11ed-861d-0242ac120002::mr.man ran successfully in 6ms","liquibaseOperation":"update","liquibaseCommandName":"update","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462","changesetId":"e24850bc-2310-11ed-861d-0242ac120002","changesetAuthor":"mr.man","changesetFilepath":"example-changelog.sql","changesetComment":"example comment","changesetLabel":"example-label","changesetContext":"example-context","changesetOperationStart":"2023-02-27T16:40:53.512","changesetSql":"alter table person add column country varchar(2)","changesetOperationStop":"2023-02-27T16:40:53.517","changesetOutcome":"executed"}

{"timestamp":"2023-02-27T22:40:53.526Z","level":"INFO","class":"liquibase","thread":"1","message":"UPDATE SUMMARY","liquibaseOperation":"update","liquibaseCommandName":"update","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462"}
UPDATE SUMMARY
{"timestamp":"2023-02-27T22:40:53.526Z","level":"INFO","class":"liquibase","thread":"1","message":"Run:                          3","liquibaseOperation":"update","liquibaseCommandName":"update","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462"}
Run:                          3
{"timestamp":"2023-02-27T22:40:53.527Z","level":"INFO","class":"liquibase","thread":"1","message":"Previously run:               0","liquibaseOperation":"update","liquibaseCommandName":"update","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462"}
Previously run:               0
{"timestamp":"2023-02-27T22:40:53.528Z","level":"INFO","class":"liquibase","thread":"1","message":"DBMS mismatch:                0","liquibaseOperation":"update","liquibaseCommandName":"update","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462"}
DBMS mismatch:                0
{"timestamp":"2023-02-27T22:40:53.529Z","level":"INFO","class":"liquibase","thread":"1","message":"Not in filter:                0","liquibaseOperation":"update","liquibaseCommandName":"update","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462"}
Not in filter:                0
{"timestamp":"2023-02-27T22:40:53.530Z","level":"INFO","class":"liquibase","thread":"1","message":"-------------------------------","liquibaseOperation":"update","liquibaseCommandName":"update","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462"}
-------------------------------
{"timestamp":"2023-02-27T22:40:53.530Z","level":"INFO","class":"liquibase","thread":"1","message":"Total change sets:            3\n","liquibaseOperation":"update","liquibaseCommandName":"update","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462"}
Total change sets:            3

{"timestamp":"2023-02-27T22:40:53.531Z","level":"INFO","class":"liquibase","thread":"1","message":"Update command completed successfully.","liquibaseOperation":"update","liquibaseCommandName":"update","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462","deploymentOutcome":"success","deploymentOutcomeCount":"3"}
{"timestamp":"2023-02-27T22:40:53.535Z","level":"INFO","class":"liquibase.lockservice","thread":"1","message":"Successfully released change log lock","liquibaseOperation":"update","liquibaseCommandName":"update","liquibaseTargetUrl":"jdbc:h2:tcp://localhost:9090/mem:dev","commandLabelFilter":"()","commandContextFilter":"","deploymentId":"7537653462"}
Liquibase command 'update' was executed successfully.

--log-format=JSON_PRETTY includes line breaks for easier human readability.

Starting Liquibase at 16:38:59 (version [Core: //DAT-11693/7176/44d487/2023-02-09 14:35+0000, Pro: DAT-11693/2749/7aac10/2023-02-09T14:30:34Z] #7176 built at 2023-02-09 14:35+0000)
Liquibase Version: [Core: //DAT-11693/7176/44d487/2023-02-09 14:35+0000, Pro: DAT-11693/2749/7aac10/2023-02-09T14:30:34Z]
Liquibase Labs [Core: //DAT-11693/7176/44d487/2023-02-09 14:35+0000, Pro: DAT-11693/2749/7aac10/2023-02-09T14:30:34Z] by Liquibase licensed to Dev until Sat Dec 30 22:59:59 CST 2023
{
  "timestamp": "2023-02-27T22:38:59.647Z",
  "level": "INFO",
  "class": "liquibase.integration",
  "thread": "1",
  "message": "Starting command execution.",
  "liquibaseVersion": "DEV",
  "liquibaseSystemUser": "mariochampion",
  "liquibaseSystemName": "mmc-mbp.lan"
}
{
  "timestamp": "2023-02-27T22:38:59.744Z",
  "level": "INFO",
  "class": "liquibase.license",
  "thread": "1",
  "message": "Successfully installed license from Base64 string starting with 'ABwwGgQU6h' (property liquibaseProLicenseKey).\n",
  "liquibaseOperation": "status"
}
{
  "timestamp": "2023-02-27T22:38:59.906Z",
  "level": "INFO",
  "class": "liquibase.database",
  "thread": "1",
  "message": "Set default schema name to PUBLIC",
  "liquibaseOperation": "status",
  "liquibaseCommandName": "status"
}

In Liquibase 4.25.1, when an exception occurs with Structured Logging, a new JSON object appears in the log that gives users an indepth look at the primaryClass, primaryReason, the source, and the exception details.

{"exceptionDetails":
   "primaryClass":"liquibase.exception.DatabaseException",
   "primaryReason":"ERROR: relation "staff" already exists [Failed SQL: (0) CREATE TABLE public.staff (staff_id INTEGER GENERATED BY DEFAULT AS IDENTITY NOT NULL, first_name VARCHAR(45) NOT NULL, last_name VARCHAR(45) NOT NULL, email VARCHAR(50), active BOOLEAN DEFAULT TRUE NOT NULL, username VARCHAR(16) NOT NULL, CONSTRAINT staff_pkey PRIMARY KEY (staff_id))]",
   "source":"liquibase version 4.24.0 #14062" (or "<someDatabaseName version, etc>" if it is an exception we caught, but didnt throw)
   "exception":"<the full raw output of the exception details>"
}

Tip: For example dashboards using tools like AWS CloudWatch, Datadog, Elastic, and Splunk, see the GitHub repository liquibase/Observability-Dashboards.

Enable Structured Logging

  1. Set the --license-key property using your Liquibase Pro license key. See How to Apply Your Liquibase Pro License Key.
  2. Set the --log-format property to JSON or JSON_PRETTY:
    • CLI: liquibase --log-format=JSON or JSON_PRETTY
    • Properties file: liquibase.logFormat=JSON or JSON_PRETTY
    • Environment Variable: LIQUIBASE_LOG_FORMAT=JSON or JSON_PRETTY
  3. Set the --log-level property to a value other than OFF. Use this to define what to include in your structured logs. Valid values are FINE, INFO, WARN, and SEVERE.
  4. (Optional) Set the --log-file properties so the log data is sent to a file rather than to the console. This is useful if you want to capture a file to be ingested by your log analysis tool, such as Elastic or Cloudwatch, etc.

    To do so, set the --log-file property equal to the log file of your choice in the file, as an environment variable, or in the CLI.

    Example: liquibase --log-format=JSON_PRETTY --log-level=INFO update --log-file=mylogfile.log

Structured Logging is enabled successfully!

Note: By default, console messages are included in your log. If you need to disable this, set mirror-console-messages-to-log to false.

Analyze and Use Structured Log Data

After you enable Liquibase structured logs, you can configure tools outside of Liquibase to send the data to useful places:

  1. Select an external observability platform like AWS CloudWatch, Datadog, Dynatrace, Elastic, or Splunk. Your observability platform contains several tools to index logs and display them in human-readable dashboards.
  2. Configure a logging agent compatible with your observability platform like AWS CloudWatch Agent, Datadog Agent, Dynatrace OneAgent, Filebeat or Logstash (Elastic Stack), or Splunk Universal Forwarder or Splunk HTTP Event Collector (HEC).
  3. Ingest Liquibase structured logs using your observability platform's logging agent.
    • If your company has an observability subject matter expert (SME), consult them to determine what architecture to use to index your logs. You may want to ingest logs in multiple environments, each of which may have unique requirements.
    • If your company doesn't have an observability SME, contact Liquibase Support for assistance.
    • Note: Configuration of an external tool may not be entirely covered by your Liquibase support plan.

  4. Analyze (index) the logs you have ingested using your observability platform's log indexing tool, such as AWS CloudWatch Logs Insights, Datadog Logs Processing Pipeline, Dynatrace Log Management and Analytics, Elasticsearch or Logstash, or Splunk Indexer. Consult your observability SME for guidance.
  5. View your data by constructing a dashboard in your observability platform. You must query the logs you have ingested and indexed and send this data to your dashboard to represent it visually. The Liquibase Observability-Dashboards repository on GitHub contains several sample dashboards for common metrics. For a list of keys (endpoints) you can include in your queries, see Structured Logging Keys.
  6. Automate data monitoring and reporting in your CI/CD pipeline. Ensure that your logging jobs run automatically after every Liquibase operation in your pipeline. Using your indexed logs, write queries that automatically notify you of problematic behavior. You can also use Liquibase Operation Reports to receive information about common Liquibase operations.

Disable Structured Logging

To disable structured logging, do one of the following:

  • Set --log-format to TEXT to explicitly use unstructured logs
  • Omit the --log-format parameter and Liquibase reverts to the default value of TEXT

Supported commands

You can get structured logs from the output of the following commands:

Note: Structured Logging affects log output, not command output. Commands like status, history, and diff deliver command output directly in the console. Log output is fine-grained and often related to code or metadata.

Also, not all commands are yet structured. These commands will still produce a structured log, but there will not be additional data or content in these log objects. The new content that is available in structured logs includes things like deploymentID, command parameters, label filter settings, nested objects, and more.

Keys

For a list of keys that Liquibase includes in the JSON output, see Structured Logging Keys.