2

To improve my command lines scripts, I want to add some optional console output, mainly for logging purposes. In my PowerShell modules, I use Write-Verbose for this (but it should be clear this isn't specifically a Powershell question, presumably, the situation is similar in other languages). There are plenty of sites and lists about best practices regarding scripting in general, however, I could not find a proper description on how to adequately use a something like Write-Verbose.

Should the output describe the next/previous command, hence become part of code documentation or would that be excessive?

For example I have the following code block:

$files = Get-ChildItem -Path C:\... -Recurse
Write-Verbose -Message "All files are retrieved"
foreach ($file in $files)
{
  Do-Something
  Write-Verbose -Message "Something has been done"
}
Export-Csv -Path .
Write-Verbose -Message "The report has been exported as CSV file"
Doc Brown
  • 199,015
  • 33
  • 367
  • 565
Alex_P
  • 151
  • 7
  • 1
    I took the freedom to reword your question in a more language agnostic manner, so it will not be seen as a request for programming help, which would be off-topic here. – Doc Brown Jan 29 '21 at 12:29
  • 1
    What do you think? What Help/information does each approach provide to a user of the script? And to a programmer getting a bug report? – marstato Jan 30 '21 at 16:52

1 Answers1

3

Log the planned action before you do it, and log the result when the outcome is known. The outcome message should repeat enough information about the action that the reader can understand what has happened.

When a process is aborted (e.g. because of a failure) the logged error message should explain why the planned action cannot continue. (e.g. "FAILURE: Cannot paint the bike shed because the vote on colour was a tie, abandoning construction").

Rationale:

These messages have different priorities. When a failure happens, the outcome message is an error message. The "plan" message may just have been INFO or DEBUG. Hence the reader may not have seen it, and so some of the context should be included in the outcome message.

As a design pattern, this kind of stratification of logging messages is provided for in many, many logging frameworks (e.g. anything called Log4XXX).

The problem with using verbose messages after the action is complete only, is that this provides no help at all when something goes wrong, and provides no context to the user watching the messages if an action (perhaps an ultimately successful one) is taking a long time.

If you are building a library, consider returning richer status objects rather than logging error messages. This is because low-level code may fail to do a thing without this being a problem at the top-level, and logging a spurious error message (about a thing we didn't need to succeed) is misleading.

James Youngman
  • 3,104
  • 2
  • 14
  • 19