JoeT
JoeT

Reputation: 145

Logging to console and file with function passing back return code

I've decided it makes sense that functions being called by a Powershell script should

  1. Log the same output to both a log file and to the console and
  2. should return a status indicating success/failure.

I found a way to do this but it seems ridiculously cumbersome and backwards (illustrated below). I'm thinking this is such a basic and essential capability for any scripting language and that I must be really lost and confused to be doing something in such a backwards way. I'm pretty new to PowerShell but come from a C# background.

I ended up adding -PassThru to every Add-Content statement in the function so the log entry will be coming back in the pipeline as item of an Object[] collection. I then am passing back a final boolean item in the Object[] collection which is the status of the function.

# Main script c:\temp\test1.ps1
Function Write-FunctionOutputToConsole {
    Param ([Object[]] $FunctionResults)

    foreach ($item in $FunctionResults) {
        if ($item -is [System.Array]) {
            Write-Host $($item)
        }
    }
}

Function Get-FunctionReturnCode {
    Param ([Object[]] $FunctionResults)

    if ($FunctionResults[-1] -is [System.Boolean]) {
        Return $FunctionResults[-1]
    }
}

. c:\temp\test2.ps1  #pull in external function

$LogFile = "c:\temp\test.log"

$results = FunctionThatDoesStuff -LogFile $LogFile -DesiredReturnValue $true

Write-FunctionOutputToConsole -FunctionResults $results
$FunctionReturnCode = Get-FunctionReturnCode -FunctionResults $results
Add-Content -Path $LogFile -Value "$(Get-Date -Format G) Logging in Main: returnValue=$FunctionReturnCode" -PassThru

# Do some logic based on $FunctionReturnCode

External function

# c:\temp\test2.ps1
function FunctionThatDoesStuff {
    Param(
        [string] $LogFile,
        [bool]   $DesiredReturnValue
    )

    Add-Content -Path $LogFile -Value "-----------------------------------------" -PassThru
    Add-Content -Path $LogFile -Value "$(Get-Date -Format G) returnValue=$DesiredReturnValue" -PassThru
    Add-Content -Path $LogFile -Value "$(Get-Date -Format G) line 1 being logged"      -PassThru
    Add-Content -Path $LogFile -Value "$(Get-Date -Format G) line 2 being logged"      -PassThru
    return $DesiredReturnValue 
}

Console Output:

PS C:\Temp> c:\temp\test1.ps1
-----------------------------------------
7/19/2018 3:26:28 PM returnValue=True
7/19/2018 3:26:28 PM line 1 being logged
7/19/2018 3:26:28 PM line 2 being logged
7/19/2018 3:26:28 PM Logging in Main: returnValue=True

Log File

PS C:\Temp> get-content c:\temp\test.log
-----------------------------------------
7/19/2018 3:29:59 PM returnValue=True
7/19/2018 3:29:59 PM line 1 being logged
7/19/2018 3:29:59 PM line 2 being logged
7/19/2018 3:29:59 PM Logging in Main: returnValue=True

As you can see this results in the identical information in the Console and logging file.

Upvotes: 0

Views: 1434

Answers (1)

Ansgar Wiechers
Ansgar Wiechers

Reputation: 200333

I think you're misunderstanding how PowerShell works. For one thing, the information whether or not the last command was successful is automatically stored in the automatic variable $?. In case of an error cmdlets will throw an exception that can be caught for error handling (see also). There is no need to signal success or error status with a return value. Also, PowerShell by default returns all uncaptured output from a function. The return keyword is just for control flow.

I would implement a logging function somewhat like this:

function Write-LogOutput {
    [CmdletBinding()]
    Param(
        [Parameter(Position=0, Mandatory=$true, ValueFromPipeline=$true)]
        [string[]]$Message,

        [Parameter(Position=1, Mandatory=$false)]
        [ValidateScript({Test-Path -LiteralPath $_ -IsValid})]
        [string]$LogFile = '.\default.log',

        [Parameter(Mandatory=$false)]
        [switch]$Quiet,

        [Parameter(Mandatory=$false)]
        [switch]$PassThru
    )

    Process {
        $Message | ForEach-Object {
            $msg = "[{0:yyyy-MM-dd HH:mm:ss}]`t{1}" -f (Get-Date), $_
            if (-not $Quiet.IsPresent) {
                $msg | Out-Host
            }
            $msg
        } | Add-Content $LogFile
        if ($PassThru.IsPresent) {
            $Message
        }
    }
}

and then use it like this:

function FunctionThatDoesStuff {
    # ...

    # something that should be logged, but not returned
    'foo' | Write-LogOutput -LogFile 'C:\path\to\your.log'
    # something that should be logged and returned by the function
    'bar' | Write-LogOutput -LogFile 'C:\path\to\your.log' -PassThru
    # something that should be returned, but not logged
    'baz'

    # ...
}

$result = FunctionThatDoesStuff
# Output:
# -------
# [2018-07-19 23:44:07]   foo
# [2018-07-19 23:44:07]   bar

$result
# Output:
# -------
# bar
# baz

Upvotes: 4

Related Questions