2013-03-15

SQLPS Clear-Host error

When a ps1-scriptfile contains a Clear-Host statement, which I often use when testing a script in PowerShell ISE, the script fails on SQLPS with an error like this:
A job step received an error at line 3 in a PowerShell script. The corresponding line is '$space.ForegroundColor = $host.ui.rawui.ForegroundColor'. Correct the script and reschedule the job. The error information returned by PowerShell is: 'Exception setting "ForegroundColor": "Cannot convert null to type "System.ConsoleColor" due to invalid enumeration values. Specify one of the following enumeration values and try again. The possible enumeration values are "Black, DarkBlue, DarkGreen, DarkCyan, DarkRed, DarkMagenta, DarkYellow, Gray, DarkGray, Blue, Green, Cyan, Red, Magenta, Yellow, White"."

A quick work-around is to comment out the Clear-Host statement as a preparation to execute it as a PowerShell step in a SQL Server Agent job.

This is on a Windows Server 2008 R2 with SQL Server 2008 R2. The Windows PowerShell is 3.0 while SQLPS is 2.0.

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“.