2013-01-25

Call command-line in PowerShell

Often I have to build a command-line statement dynamic and then execute the statement.
The PowerShell call operator (&) can be cumbersome to use, but following some simple rules or using a general template can do the trick. This operator is also called the invoke operator.

Parameters

When using the call operator you have to remember it executes the string to the first space, and because of this it can not take a command-line string with parameters like „ping www.sqladmin.info -n 5“.
A solution to this is given by Devlin Bentley in the blog entry „PowerShell Call Operator (&): Using an array of parameters to solve all your quoting problems“.

In general the trick is to call the command with the operator and put parameters in an additional array.
[String]$cmd = 'ping'
$cmd += '.exe'
[String[]]$param = @('www.sqladmin.info','-n','5')
& $cmd $param

A output of this could be
Pinging www.sqladmin.info [212.97.133.23] with 32 bytes of data:
Reply from 212.97.133.23: bytes=32 time=16ms TTL=120
Reply from 212.97.133.23: bytes=32 time=24ms TTL=120
Reply from 212.97.133.23: bytes=32 time=23ms TTL=120
Reply from 212.97.133.23: bytes=32 time=20ms TTL=120
Reply from 212.97.133.23: bytes=32 time=19ms TTL=120

Ping statistics for 212.97.133.23:
Packets: Sent = 5, Received = 5, Lost = 0 (0% loss),
Approximate round trip times in milli-seconds:
Minimum = 16ms, Maximum = 24ms, Average = 20ms


By putting the command in a string by itself, it can be build in script with path and so on. I have tried to illustrate this by adding the file extension in a seperate line of the script above.

The parameter values can be defined element by element into a parameter array.
[String]$cmd = 'ping'
$cmd += '.exe'
[String[]]$param = @()
$param += 'www.sqladmin.info'
$param += '-n'
$param += '5'
& $cmd $param


Catch output

To catch the output line by line it can be taken from the output stream.
[String]$cmd = 'ping'
$cmd += '.exe'
[String[]]$param = @('www.sqladmin.info','-n','5')
& $cmd $param |
ForEach-Object { "{0:s}Z $($_)" -f $([System.DateTime]::UtcNow) }

A output of this could be
2013-03-26T13:10:39Z
2013-03-26T13:10:39Z Pinging www.sqladmin.info [212.97.133.23] med 32 byte data:
2013-03-26T13:10:39Z Reply from 212.97.133.23: byte=32 time=3ms TTL=118
2013-03-26T13:10:40Z Reply from 212.97.133.23: byte=32 time=2ms TTL=118
2013-03-26T13:10:41Z Reply from 212.97.133.23: byte=32 time=3ms TTL=118
2013-03-26T13:10:42Z Reply from 212.97.133.23: byte=32 time=2ms TTL=118
2013-03-26T13:10:43Z Reply from 212.97.133.23: byte=32 time=2ms TTL=118
2013-03-26T13:10:43Z
2013-03-26T13:10:43Z Ping statistics for 212.97.133.23:
2013-03-26T13:10:43Z Packets: Sent = 5, Recieved = 5, Lost = 0 (0% loss),
2013-03-26T13:10:43Z Approximate round trip times in milli-seconds:
2013-03-26T13:10:43Z Minimum = 2ms, Maximum = 3ms, Average = 2ms


Be aware of large amounts of output. I have experienced that several thousand lines of output will make the script execution unstable in a unpredictable way.

Exception

A simple exception handling with Try-Catch-Finally blocks could be like
[String]$cmd = 'ping'
$cmd += '.exe'
[String[]]$param = @('www.sqladmin.info','-n','5')
try {
  & $cmd $param |
  ForEach-Object { "{0:s}Z $($_)" -f $([System.DateTime]::UtcNow) }
}
catch {
  "{0:s}Z ERROR: $($_.Exception.Message)" -f $([System.DateTime]::UtcNow)
}

If the command in the variable $cmd is change to „noping.exe“, the output will like
2013-03-29T14:42:31Z ERROR: The term 'noping.exe' is not recognized as the name of a cmdlet, function, script file, or operable program. Check the spelling of the name, or if a path was included, verify that the path is correct and try again.

Trap

In the beginning PowerShell only had the Trap command, but it had some limitations. Passing on a error from a Trap can be done with the Throw.
It is generally recommended to use Try-Catch-Finally that we got with PowerShell v2.
Jeffrey Snover shared a very short but precise comparison in „Traps vs Try/Catch“.

Error

The automatic variable $LastExitCode contains the exit code of the last program that was executed.
This is nice in a simple setup, but sometimes there are several errors from one program. In such case I would like to know all errors and their details.
The automatic variable $Error is an array of all errors (System.Management.Automation.ErrorRecord) in the current PowerShell session. The latest error is the first element in the array ($Error[0]).
This is a simple demonstration how $Error can be used:
$Error.Clear()

try {
  throw [System.DivideByZeroException]
}
catch {
  $PSItem.CategoryInfo
}
finally {
  ":: Final"
}

if ($Error) {
  "{0:s} Error in script execution. See log for details." -f $([System.DateTime]::Now)
  if ($Error[0].Exception -match 'System.DivideByZeroException') {
    "-- Divide-By-Zero Exception"
  }
}

"$($Error.Count) Error(-s)."


The result will be something like this:
Category : OperationStopped
Activity :
Reason : RuntimeException
TargetName : System.DivideByZeroException
TargetType : RuntimeType

:: Final
2014-01-27T20:45:29 Error in script execution. See log for details.
-- Divide-By-Zero Exception
1 Error(-s).


When building/developing a script $Error is a great tool to look into an error.
Details on the exception itself can be very usefull. This you can get by piping the Exception to the CmdLet Get-Member. The professional lazy scripting guy can use the alias:
$error[0].Exception | gm

Injection attack

Several blog posts and forum answers uses the cmdlet Invoke-Expression, but please notice that this could make the script open to injection attacs. This is described by the Windows PowerShell Team in the blog post „Invoke-Expression considered harmful“.

Running Executables

This subject is already described in a TechNet Wiki article: „PowerShell: Running Executables“.
The article covers several other methods to call a command-line in PowerShell, but I will for now stay with the call operator.

History

2014-01-27 : Exception handling added note on Trap. Error section added.
2013-03-29 : Exception handling example added.
2013-03-26 : The parts on piping the output and defining the parameter values element by element are added.

2012-11-28

Job history template using SQL Server Agent tokens

To log the execution and output from all steps in a SQL Server Agent job into a single logfile, you can use SQL Server tokens and macros to create the logfile in the default SQL Server LOG-folder, and let each jobstep add their output to the file. The default SQL Server LOG-folder is also the folder where SQL Server places Errorlog files (ERRORLOG.nn) and tracefiles (.trc) from default trace.

The first jobstep is a dummy step that only initialize the logfile on a normal job execution.
The jobstep can be created with
EXECUTE [msdb].[dbo].[sp_add_jobstep]
@job_id=@jobId,
@step_name=N'Job Begin',
@step_id=1,
@cmdexec_success_code=0,
@on_success_action=3,
@on_success_step_id=0,
@on_fail_action=2,
@on_fail_step_id=0,
@retry_attempts=0,
@retry_interval=0,
@os_run_priority=0,
@subsystem=N'TSQL',
@command=N'DECLARE @errmsg nvarchar(2047);
SET @errmsg = LEFT(CONVERT(nvarchar(128), GETUTCDATE(), 127), 22) + N''Z : Job Begin...'';
RAISERROR(@errmsg,0,0) WITH NOWAIT;',
@database_name=N'master',
@output_file_name=N'$(ESCAPE_SQUOTE(SQLDIR))\LOG\MacroTest.$(ESCAPE_SQUOTE(STRTDT))T$(ESCAPE_SQUOTE(STRTTM)).log',
@flags=0;

The output filename is created in the default SQL Server Log with „$(ESCAPE_SQUOTE(SQLDIR))\LOG\“ and the name of the file is created with a name like the jobname, a timestamp and the filetype „log“.
I miss two things as a token; the jobname and the time where the job began in UTC. Right now I will have to enter a jobname manually and take care of the local time when we switch between summer- and wintertime (Daylight saving time).
The logfiles initial output is generated by a RAISERROR call. Please notice that I give the errormessage a UTC timestamp in a ISO 8601 format.

A actual job step will the add the output to the logfile. A jobstep could be created with
EXECUTE [msdb].[dbo].[sp_add_jobstep]
@job_id=@jobId,
@step_name=N'Job Execution 01',
@step_id=2,
@cmdexec_success_code=0,
@on_success_action=3,
@on_success_step_id=0,
@on_fail_action=2,
@on_fail_step_id=0,
@retry_attempts=0,
@retry_interval=0,
@os_run_priority=0,
@subsystem=N'TSQL',
@command=N'DECLARE @errmsg nvarchar(2047);
SET @errmsg = LEFT(CONVERT(nvarchar(128), GETUTCDATE(), 127), 22) + N''Z : Job Executing {01}...'';
RAISERROR(@errmsg,0,0) WITH NOWAIT;',
@database_name=N'master',
@output_file_name=N'$(ESCAPE_SQUOTE(SQLDIR))\LOG\MacroTest.$(ESCAPE_SQUOTE(STRTDT))T$(ESCAPE_SQUOTE(STRTTM)).log',
@flags=2;

The value 2 to the parameter @flag append the output to the logfile.

When the job has executed all (real) steps, the logfile is ended a dummy step, that enter a final timestamp. This can be used for execution time comparisons. The jobstep can be created with
EXECUTE [msdb].[dbo].[sp_add_jobstep]
@job_id=@jobId,
@step_name=N'Job End',
@step_id=3,
@cmdexec_success_code=0,
@on_success_action=1,
@on_success_step_id=0,
@on_fail_action=2,
@on_fail_step_id=0,
@retry_attempts=0,
@retry_interval=0,
@os_run_priority=0,
@subsystem=N'TSQL',
@command=N'DECLARE @errmsg nvarchar(2047);
SET @errmsg = LEFT(CONVERT(nvarchar(128), GETUTCDATE(), 127), 22) + N''Z : Job End.'';
RAISERROR(@errmsg,0,0) WITH NOWAIT;',
@database_name=N'master',
@output_file_name=N'$(ESCAPE_SQUOTE(SQLDIR))\LOG\MacroTest.$(ESCAPE_SQUOTE(STRTDT))T$(ESCAPE_SQUOTE(STRTTM)).log',
@flags=2;


A execution of a job with three steps where one is the actual job execution could generate a output like this
Job 'MacroTest' : Step 1, 'Job Begin' : Began Executing 2012-11-28 08:21:51

2012-11-28T07:21:51.95Z : Job Begin... [SQLSTATE 01000]
Job 'MacroTest' : Step 2, 'Job Execution 01' : Began Executing 2012-11-28 08:21:51

2012-11-28T07:21:51.98Z : Job Executing {01}... [SQLSTATE 01000]
Job 'MacroTest' : Step 3, 'Job End' : Began Executing 2012-11-28 08:21:52

2012-11-28T07:21:52.01Z : Job End. [SQLSTATE 01000]

If the job is started from another step than the initial step, the output is still caught in a logfile. In this case a new file is created implicit by adding output to it. A partial execution could generate a output like this
Job 'MacroTest' : Step 2, 'Job Execution 01' : Began Executing 2012-11-28 09:50:21

2012-11-28T08:50:21.81Z : Job Executing {01}... [SQLSTATE 01000]
Job 'MacroTest' : Step 3, 'Job End' : Began Executing 2012-11-28 09:50:21

2012-11-28T08:50:21.84Z : Job End. [SQLSTATE 01000]


SQL Server Agent tokens and macros are documented in „Use Tokens in Job Steps“ on MSDN Library.

A more complex and dynamic creation of SQL Server Agent jobsteps can be studied in the SQL Server Maintenance Solution from Ola Hallengren.

2012-10-30

SQL Server major version

When I automate installation or administration I often has to use the major version of the SQL Server database installation.
Unfortunately SERVERPROPERTY('ProductVersion') return a string with the complete versionnumber, and there is no other propertyname to get only the major version.
I would like something similar to the SMO Server.VersionMajor property.

Some cutting and casting does the trick to get the left part before the first dot:
DECLARE @version_major INT = CAST(LEFT(CAST(SERVERPROPERTY('ProductVersion') AS NVARCHAR(MAX)), CHARINDEX('.',CAST(SERVERPROPERTY('ProductVersion') AS NVARCHAR(MAX))) - 1) AS INT);

This gives me a integer that can be compared or be part of a calculation like
... ( @version_major - 1 ) ...

Some security configuration statements are dependant on the major version, and can behandled like this
IF @version_major <= 8
  PRINT N'Not SQL Server 2005 or above.';
ELSE
  PRINT N'SQL Server 2005 or above';


In my SQL Server repository I store the version information in the table [sqladmin].[version], where the version number is in the column [version].[version_number] as NVARCHAR(128).
The major version in a SELECT statement as integer can be done with something like this:
SELECT
  N'ssdb_version_major' = CASE [version].[version_number]
    WHEN N'(unknown)' THEN 0
    ELSE CAST( LEFT([version].[version_number], ABS(CHARINDEX(N'.',[version].[version_number])-1)) AS INT)
  END
FROM
  [sqladmin_repository].[sqladmin].[version];


Please notice the ABS() on the CHARINDEX() because of the subtraction (-1). It looks like the SQL Server optimizer looks at the subtraction before CHARINDEX(). Without the ABS() the statement failed with this error:
Msg 537, Level 16, State 3, Line 1
Invalid length parameter passed to the LEFT or SUBSTRING function.

The case on the string „(unknown)“ is because the column is defined NOT NULL, and a unknown version number - usually because there is no connection between the repository collector and the database instance - is given the default value „(unknown)“. Even when a subset is selected by a WHERE clause, all rows are evaluated for CAST(). Without the CASE the statement failed with this error:
Msg 245, Level 16, State 1, Line 1
Conversion failed when converting the nvarchar value '(' to data type int.



(This is a running update from 2011-12-21)

2012-10-29

VLF count on SQL Server 2012

Some time ago I posted the blog entry „VLF count“ where the (undocumented) function „DBCC LogInfo“ is used to collect the VLF count of a database.
This I have implemented in my SQL Server repository, but with the first SQL Server 2012 installation, the collection failed. The collection is done on a given database with this statement:
SET NOCOUNT ON;
CREATE TABLE #stage(
 [file_id] INT
 ,[file_size] BIGINT
 ,[start_offset] BIGINT
 ,[f_seq_no] BIGINT
 ,[status] BIGINT
 ,[parity] BIGINT
 ,[create_lsn] NUMERIC(38)
);
INSERT INTO #stage EXECUTE (N'DBCC LogInfo WITH no_infomsgs');
SELECT COUNT(1) FROM #stage;
DROP TABLE #stage;


And the error message is:
Msg 213, Level 16, State 7, Line 1
Column name or number of supplied values does not match table definition.


It turns out that the resultset of DBCC LogInfo has changed with SQL Server 2012, where SQL Server 2000 to 2008 R2 has these DBCC LogInfo columns:
NameType
FileIdINT
FileSizeBIGINT
StartOffsetBIGINT
FSeqNoBIGINT
StatusBIGINT
ParityBIGINT
CreateLSNNUMERIC(38)
And SQL Server 2012 has these DBCC LogInfo columns:
NameType
RecoveryUnitIdINT
FileIdINT
FileSizeBIGINT
StartOffsetBIGINT
FSeqNoBIGINT
StatusBIGINT
ParityBIGINT
CreateLSNNUMERIC(38)

The column „RecoveryUnitId“ is added in the beginning of the resultset.

On SQL Server 2012 this rewritten statement gives the VLF count of the current database:
SET NOCOUNT ON;
CREATE TABLE #stage(
 [recovery_unit_id] INT
 ,[file_id] INT
 ,[file_size] BIGINT
 ,[start_offset] BIGINT
 ,[f_seq_no] BIGINT
 ,[status] BIGINT
 ,[parity] BIGINT
 ,[create_lsn] NUMERIC(38)
);
INSERT INTO #stage EXECUTE (N'DBCC LogInfo WITH no_infomsgs');
SELECT COUNT(1) FROM #stage;
DROP TABLE #stage;


I am rewriting (refactoring) my script to depend on the major version number.

BTW – Please take a look on the Microsoft Connect item „Document DBCC LOGINFO() or create new DMVs to view VLF info“.

2012-10-16

Check NetBackup file backup


I have been looking in ways to ensure that a SQL Server backup file is backed up by NetBackup, so that the backup file can be deleted from the local disk. I have not found a API for the local NetBackup client, but there are a lot of command-line tools.
In this case our backup vendor has pointed out the tool "bplist" (bplist.exe). Usually bplist is located in the folder „%ProgramFiles\Veritea\NetBackup\bin\“.
A bplist answer example looks like this:
-rwx------ root;SQL1 root;Doma      485888 Jul 29 20:00:01 E:\MSSQL\Backup\ReportServer_backup_2012_07_28_221142_2861771.bak
if bplist is called with the parameters „-l -b -Listseconds“.

WARNING!!!
No year on NetBackup backup.
This is also discussed in the forum thread "bplist does not display the year of a backup?".
It looks like there is an issue on the age of the backup, if it is more than six months old or not.
Also when I look in the documentation, there are some differences on the answer from the NetBackup server if it is Windows or Linux. Please notice that it is the NetBackup server, not the client operating system that gives the answer.

bplist can be executed in PowerShell with the invoke operator (&):
& "<NetBackup folder>\bplist.exe" -l -b "X:\MSSQL\Backup\sqladmin_repository_backup_2012_12_24_172249_7006410.bak"
The full path must be provided for the file to examine in NetBackup.

To look at how to handle bplist and its answer in a automated way, I made this PowerShell spike script:
param (
  [Parameter()]
  [ValidateScript({Get-ChildItem -Path $_})]
  [string]$NetBackup_Folder = 'C:\Program Files\Veritas\NetBackup\bin'
)

Set-StrictMode -Version 2.0

function Get-NetBackup_bplist {
[CmdletBinding()]
param(
  [Parameter(Mandatory=$true,ValueFromPipeline=$true)]
  [System.IO.FileInfo]$File
)
  BEGIN { Write-Verbose "OS Version = $([System.Environment]::OSVersion.VersionString)" }
  PROCESS {
    Write-Verbose "File name = '$($File.FullName)'."

    $BpList = New-Object -TypeName PSObject
    $BpList = $File
    $BpList.PSObject.TypeNames.Insert(0,'SqlAdmin.NetBackup.BpList')

    # Get file backup status from NetBackup
    $bplist_answer = $(& "$NetBackup_Folder\bplist.exe" -l -b -Listseconds "$($File.FullName)") 2>&1 # Redirect bplist.exe error to $bplist_answer
    if ($bplist_answer.GetType().IsArray) { # Multiple backups in NetBackup
      Write-Verbose " $($bplist_answer.Length) backups found in NetBackup. Will continue on last backup."
      $_bplist = $bplist_answer[0] # Get last backup in NetBackup
    }
    else {
      $_bplist = $bplist_answer
    }
    Write-Verbose " $($_bplist)"

    # Evaluate file backup status from NetBackup. Add -PassThru to last added member.
    if ($_bplist.ToString() -ceq 'EXIT STATUS 227: no entity was found') { # File not in NetBackup
      Write-Verbose " --- NO backup in NetBackup ($($File.Name))."
      Add-Member -InputObject $BpList -MemberType NoteProperty -Name HasBackup -Value $false
      Add-Member -InputObject $BpList -MemberType NoteProperty -Name BackupLength -Value $null
      Add-Member -InputObject $BpList -MemberType NoteProperty -Name BackupTime -Value $null
    }
    else {
      Write-Verbose " +++ Backup is in NetBackup ($($File.Name))."
      Add-Member -InputObject $BpList -MemberType NoteProperty -Name HasBackup -Value $true

      # Get backup details
      $regex = [regex]"\w+"
      $Backup = $($regex.matches($_bplist)) # Returns [System.Text.RegularExpressions.Match]

      if ($Backup[5].Value.SubString($Backup[5].Length-1) -eq 'K') { # Is the most right char 'K'?
        $Backup_Size = [int]$Backup[5].Value.SubString(0,$Backup[5].Length-1) * 1024 # Convert from KB to Bytes
      }
      else {
        $Backup_Size = [int]$Backup[5].Value
      }
      Add-Member -InputObject $BpList -MemberType NoteProperty -Name BackupLength -Value $Backup_Size
      $DateParse = "$($Backup[7].Value) $($Backup[6].Value) $([System.DateTime]::Now.Year) $($Backup[8].Value):$($Backup[9].Value):$($Backup[10].Value)"
      Add-Member -InputObject $BpList -MemberType NoteProperty -Name BackupTime -Value $([System.DateTime]::Parse($DateParse))
    }
    Write-Output $BpList
  }
  END {}
}


### INVOCATION ###
switch -casesensitive ($ComputerName) {
  'TRACY.SQLADMIN.LAN' {
  Get-ChildItem -Path 'D:\MSSQL_Backup' |
  Sort-Object -Property Length -Descending |
  Sort-Object -Property LastWriteTime -Descending |
  Select-Object -First 100 |
  Get-NetBackup_bplist | #-Verbose |
  Where-Object { $_.HasBackup -eq $true } |
  #Format-Table Name,Length,HasBackup,BackupTime,BackupLength -AutoSize
  ForEach-Object { Remove-Item $_.FullName -Confirm:$true }
  break
  }
  default {
  Get-ChildItem -Path 'X:\MSSQL\Backup' |
  Sort-Object -Property Length -Descending |
  Select-Object -First 20 |
  Get-NetBackup_bplist |
  #Format-Table Name,Length,HasBackup,BackupTime -AutoSize
  ForEach-Object { Remove-Item $_.FullName -Confirm:$true }
  break
  }
}


Again – a spike…

The general motivation to look into this is to ensure that the restore chain is complete, also in the secondary backup on NetBackup.
The complete restore chain is necessary to ensure complete recovery.

(This is a running update on a post from 2012-08-27)