Application Logging

Application Logging #

SQLDSC writes a log file of every change it makes. A typical directory structure with log files looks like this:

│   ├───nodes
│   ├───tags
│   ├───scripts
│   └───state

It generates one file per month per user. The file name is sqldsc_YYYYY_MM_domain_user.ndjson. This simplifies keeping log files in a source code repository.

The log files are formatted as NDJSON (Newline Delimited JSON). NDJSON means each file holds multiple JSON objects delimited by newline.

The log files look something like this:

{"time":"2020-06-26T14:02:50-05:00","level":"info","instance":"D40\\SQL2016","cmd":"EXEC sp_configure 'max degree of parallelism', '13';","user":"DOMAIN\\user"}
{"time":"2020-06-26T14:02:52-05:00","level":"info","instance":"D40\\SQL2017","cmd":"sqlcmd.exe -S \"D40\\SQL2017\" -i \"vars.sql\" -E -b -X1 -v v1=\"first\" -v v2=\"1\"","user":"DOMAIN\\user"}
{"time":"2020-06-26T14:02:52-05:00","level":"info","instance":"D40\\SQL2019","cmd":"EXEC sp_configure 'max degree of parallelism', '44';","user":"DOMAIN\\user"}
  • Passwords and password hashes are masked.
  • The NDJSON Colorizer helps to view the logs.
  • This format can make it difficult to track changes made to a single server by multiple people. Search works well for that.

Extracting Log Events #

I often find myself copying log events into change control process documents. There’s a simple command-line option to extract log files into a more human-readable format. The following command extracts all log events across all log files starting on June 26th.

sqldsc logs --start 2020-06-26

The output looks like this:

2020-06-26 | 14:02:50 CDT | D40\SQL2016 | EXEC sp_configure 'max degree of parallelism', '13';
2020-06-26 | 14:02:52 CDT | D40\SQL2017 | sqlcmd.exe -S "D40\SQL2017" -i "vars.sql" -E -b -X1 -v v1="first" -v v2="1"
2020-06-26 | 14:02:52 CDT | D40\SQL2019 | EXEC sp_configure 'max degree of parallelism', '44';

I can copy paste this into a document with bullet points to document the changes.