Powershell debugging II

Published 22 January 11 10:24 PM | MartinBell

In my previous Powershell blog post I talked about debugging Powershell scripts using Set-PSDebug and Set-PSBreakpoint, which is great if you can use them, but there are certain circumstances where you may not be able to do that. This is where writing to a log file may be useful.

Powershell has several Write-… cmdlets these include:

Name

Synopsis

Write-Host

Writes customized output to a host.

Write-Progress

Displays a progress bar within a Windows PowerShell command window.

Write-Debug

Writes a debug message to the console.

Write-Verbose

Writes text to the verbose message stream.

Write-Warning

Writes a warning message.

Write-Error

Writes an object to the error stream.

Write-Output

Sends the specified objects to the next command in the pipeline. If the command is the last command in the pipeline, the objects are displayed in the console.

Write-EventLog

Writes an event to an event log.


Output from Write-Progress, Write-Debug, Write-Verbose and Write-Warning can be controlled by setting the following environment variables:

Name

Synopsis

Default Value

Write-Progress

$ProgressPreference

Continue

Write-Debug

$DebugPreference

SilentlyContinue

Write-Verbose

$VerbosePreference

SilentlyContinue

Write-Warning

$WarningPreference

Continue


The current values of these variables can be obtained by either examining them directly or using the Get-Variable cmdlet e.g. Get-Variable *Preference
If the variable is set to "SilentContinue" then the cmdlet will not produce any output.

You can therefore optionally choose to write output by setting the variable before running your script.

For example adding debug messages to my previous script:

# load assemblies
[Reflection.Assembly]::LoadWithPartialName("Microsoft.SqlServer.Smo")
[Reflection.Assembly]::LoadWithPartialName("Microsoft.SqlServer.SqlEnum")
[Reflection.Assembly]::LoadWithPartialName("Microsoft.SqlServer.ConnectionInfo")
 
function fn_getdbs ( [string] $server, [string] $userName, [string] $password ) {
 
    try {
        $conn = new-object Microsoft.SqlServer.Management.Common.ServerConnection ;
        $conn.LoginSecure = $false ;
        $conn.Login = $userName ;
        $conn.Password = $password ;
        $conn.ServerInstance = $server ;
        $conn.NonPooledConnection = $true ;
        write-debug $conn ;
        $srv = New-Object Microsoft.SqlServer.Management.Smo.Server ($conn) ;
        foreach($j in $srv.Databases) {
            write-debug $j.name ;
            write-host $j.name ;
        } ;
    }
    catch {
        $err = $Error[0].Exception ;
        write-debug "Error caught: " ;
        write-debug $err ;
        write-host "Error caught: " $err.Message ;
        continue ;
    } ;
}

Calling the procedure as normal will not be any different but using the following commands:

set-variable DebugPreference Continue
fn_getdbs "localhost" "validuser" "validpassword"

produces the following output:

DEBUG: server='localhost';uid='validuser';password='va;lidpassword';Pooling=false;multipleactiveresultsets=false
DEBUG: AdventureWorks
AdventureWorks
DEBUG: AdventureWorks2008
AdventureWorks2008
DEBUG: AdventureWorksDW
AdventureWorksDW
DEBUG: AdventureWorksDW2008
AdventureWorksDW2008
DEBUG: AdventureWorksLT
AdventureWorksLT
DEBUG: AdventureWorksLT2008
AdventureWorksLT2008
DEBUG: master
master
DEBUG: model
model
DEBUG: msdb
msdb
DEBUG: ReportServer
ReportServer
DEBUG: ReportServerTempDB
ReportServerTempDB
DEBUG: tempdb
tempdb


and the command:

fn_getdbs "localhost" "validuser" "invalidpassword"

produces:

DEBUG: server='localhost';uid='validuser';password='invalidpassword';Pooling=false;multipleactiveresultsets=false
DEBUG: Error caught:
DEBUG: System.Management.Automation.ExtendedTypeSystemException: The following exception was thrown when tryi
ng to enumerate the collection: "Failed to connect to server localhost.". ---> Microsoft.SqlServer.Management
.Common.ConnectionFailureException: Failed to connect to server localhost. ---> System.Data.SqlClient.SqlExce
ption: Login failed for user 'validuser'.
   at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection)
   at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj)
   at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataS
tream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
   at System.Data.SqlClient.SqlInternalConnectionTds.CompleteLogin(Boolean enlistOK)
   at System.Data.SqlClient.SqlInternalConnectionTds.AttemptOneLogin(ServerInfo serverInfo, String newPasswor
d, Boolean ignoreSniOpenTimeout, Int64 timerExpire, SqlConnection owningObject)
   at System.Data.SqlClient.SqlInternalConnectionTds.LoginNoFailover(String host, String newPassword, Boolean
redirectedUserInstance, SqlConnection owningObject, SqlConnectionString connectionOptions, Int64 timerStart)

   at System.Data.SqlClient.SqlInternalConnectionTds.OpenLoginEnlist(SqlConnection owningObject, SqlConnectio
nString connectionOptions, String newPassword, Boolean redirectedUserInstance)
   at System.Data.SqlClient.SqlInternalConnectionTds..ctor(DbConnectionPoolIdentity identity, SqlConnectionSt
ring connectionOptions, Object providerInfo, String newPassword, SqlConnection owningObject, Boolean redirect
edUserInstance)
   at System.Data.SqlClient.SqlConnectionFactory.CreateConnection(DbConnectionOptions options, Object poolGro
upProviderInfo, DbConnectionPool pool, DbConnection owningConnection)
   at System.Data.ProviderBase.DbConnectionFactory.CreateNonPooledConnection(DbConnection owningConnection, D
bConnectionPoolGroup poolGroup)
   at System.Data.ProviderBase.DbConnectionFactory.GetConnection(DbConnection owningConnection)
   at System.Data.ProviderBase.DbConnectionClosed.OpenConnection(DbConnection outerConnection, DbConnectionFa
ctory connectionFactory)
   at System.Data.SqlClient.SqlConnection.Open()
   at Microsoft.SqlServer.Management.Common.ConnectionManager.InternalConnect(WindowsIdentity impersonatedIde
ntity)
   at Microsoft.SqlServer.Management.Common.ConnectionManager.Connect()
   --- End of inner exception stack trace ---
   at Microsoft.SqlServer.Management.Common.ConnectionManager.Connect()
   at Microsoft.SqlServer.Management.Common.ConnectionManager.get_DatabaseEngineType()
   at Microsoft.SqlServer.Management.Smo.Server.GetExecutionManager()
   at Microsoft.SqlServer.Management.Smo.SqlSmoObject.get_ServerVersion()
   at Microsoft.SqlServer.Management.Smo.SqlSmoObject.GetDbComparer(Boolean inServer)
   at Microsoft.SqlServer.Management.Smo.SqlSmoObject.InitializeStringComparer()
   at Microsoft.SqlServer.Management.Smo.AbstractCollectionBase.get_StringComparer()
   at Microsoft.SqlServer.Management.Smo.SimpleObjectCollectionBase.InitInnerCollection()
   at Microsoft.SqlServer.Management.Smo.SmoCollectionBase.get_InternalStorage()
   at Microsoft.SqlServer.Management.Smo.SmoCollectionBase.InitializeChildCollection(Boolean refresh)
   at Microsoft.SqlServer.Management.Smo.SmoCollectionBase.GetEnumerator()
   at System.Management.Automation.LanguagePrimitives.GetEnumerator(Object obj)
   --- End of inner exception stack trace ---
   at System.Management.Automation.LanguagePrimitives.GetEnumerator(Object obj)
   at System.Management.Automation.foreachStatementNode.Execute(Array input, Pipe outputPipe, ArrayList& resultList, ExecutionContext context)
   at System.Management.Automation.StatementListNode.ExecuteStatement(ParseTreeNode statement, Array input, Pipe outputPipe, ArrayList& resultList, ExecutionContext context)
Error caught:  The following exception was thrown when trying to enumerate the collection: "Failed to connect to server localhost.".

Unfortunately to write this debug information to a file you can’t just pipe it to the Out-File cmdlet but you can write your own code using the Add-Content cmdlet:

# load assemblies
[Reflection.Assembly]::LoadWithPartialName("Microsoft.SqlServer.Smo")
[Reflection.Assembly]::LoadWithPartialName("Microsoft.SqlServer.SqlEnum")
[Reflection.Assembly]::LoadWithPartialName("Microsoft.SqlServer.ConnectionInfo")
 
function create-log ( [string] $logoutputfile ) {

    if ( $DebugPreference -ne "SilentlyContinue" ) {
        if ( $logoutputfile -eq "" ) {
            $global:logfile = "C:\temp\audit_" + (get-date -format "yyyyMMddHHmmss") + ".log" ;
        } else {
            $global:logfile = $logoutputfile ;
        }
        new-item $global:logfile -type File -value "Powershell Log file: "  -force ;
        add-content -path $global:logfile -value (get-date) ;
    }
}

function write-log ( [string] $logitem ) {

    if ( $DebugPreference -ne "SilentlyContinue" ) {
        add-content -path $global:logfile -value $logitem ;
        write-debug $logitem ;
    }
   

}

function fn_getdbs ( [string] $server, [string] $userName, [string] $password ) {
 
    try {

    create-log  ;
    $conn = new-object Microsoft.SqlServer.Management.Common.ServerConnection ;
        $conn.LoginSecure = $false ;
        $conn.Login = $userName ;
        $conn.Password = $password ;
        $conn.ServerInstance = $server ;
        $conn.NonPooledConnection = $true ;
        write-log $conn ;
        $srv = New-Object Microsoft.SqlServer.Management.Smo.Server ($conn) ;
        foreach($j in $srv.Databases) {
            write-log $j.name
            write-host $j.name ;
        } ;
    }
    catch {
        $err = $Error[0].Exception ;
        write-log "Error caught: " ;
        write-log $err ;
        write-host "Error caught: " $err.Message ;
        continue ;
    } ;
}

This still checks the variable $DebugPreference to determine if debug is to be output and only creates or writes to the log file if it is not set to “SilentContinue”

Filed under:

Comments

# Powershell debugging - Martin Bell UK SQL Server MVP said on January 23, 2011 09:45 AM:

Pingback from  Powershell debugging - Martin Bell UK SQL Server MVP

# Dew Drop – January 24, 2011 | Alvin Ashcraft's Morning Dew said on January 24, 2011 02:06 PM:

Pingback from  Dew Drop – January 24, 2011 | Alvin Ashcraft's Morning Dew

# Martin Bell (MartinBell) posts Powershell debugging II | sqlmashup said on January 24, 2011 07:02 PM:

Pingback from  Martin Bell (MartinBell) posts Powershell debugging II | sqlmashup

# solicitor family said on October 19, 2014 04:20 PM:

Powershell debugging II - Martin Bell UK SQL Server MVP

# Hen Night T Shirts said on November 14, 2014 10:54 PM:

Powershell debugging II - Martin Bell UK SQL Server MVP

This Blog

SQL Blogs

Syndication