Showing posts with label T-SQL. Show all posts
Showing posts with label T-SQL. Show all posts

2025-01-05

The obscure star-database

To play around with some obscrure naming possibilities in SQL Server I create the star-database. The name has nothing to do with the data warehouse star-schema pattern. The name is because the database is named with the star character (*).

CREATE DATABASE [*]
    ON PRIMARY ( NAME = N'star_data', FILENAME = N'L:\SSDB2019\Data\star_data.mdf', SIZE = 8MB, FILEGROWTH = 8MB )
    LOG ON ( NAME = N'star_log', FILENAME = N'L:\SSDB2019\TransLog\star_log.ldf', SIZE = 8MB, FILEGROWTH = 8MB );

The database is created on specific directory as inplicit default path using only the database name does not work. This was expected. Using the star-character as name requires me to wrap the name in [].

In the star-database I then create a star-schema.

USE [*];
GO
CREATE SCHEMA [*] AUTHORIZATION [dbo];

... and then a star-table.

CREATE TABLE [*].[*]
(
    [*] bigint NOT NULL IDENTITY (0, 2),
    [%] nvarchar(42) NULL,
    [<] int null,
    [>] int null
);
GO
ALTER TABLE [*].[*] ADD CONSTRAINT
    [PK_star] PRIMARY KEY CLUSTERED 
    ([*]) ON [PRIMARY];

The column names are are almost as obscure as the other names. And then I insert a few rows.

INSERT INTO [*].[*] ([%],[<],[>])
VALUES
    (N'række0', 1000, -1000),
    (N'rÆkke1', 10, -100),
    (N'räkke2', 237, 7);

Then I can select the table in different ways, where the syntax is quite important to the output.

SELECT [*] FROM [*].[*];
SELECT * FROM [*].[*];
SELECT COUNT(*) AS [**] FROM [*].[*];

The first two statements visually looks similar, but the [] makes quite a difference. Adding some WHERE-clauses also adds to the fun.

SELECT * FROM [*].[*] WHERE [%] LIKE '%ä%';
SELECT * FROM [*].[*] WHERE [<]<500;
SELECT * FROM [*].[*] WHERE [>]<0;

The script is in SQLAdmin Github (star_database.sql). Next round could be adding more fun with unicode...

The obscure master-database

The master database is well known. And creating a database with a similar name can make things obscure or unexpected. Playing with adding space before or after "master" is only partly possible. Adding a space after the name as [master ] does not work and gives the error "Msg 1801, Level 16, State 3, Line 8 Database 'master ' already exists. Choose a different database name.". But adding a space before like [ master] does work.

CREATE DATABASE [ master] ON  PRIMARY 
( NAME = N'master0_data', FILENAME = N'L:\SSDB2019\Data\master0_data.mdf', SIZE = 8MB, FILEGROWTH = 8MB )
LOG ON 
( NAME = N'master0_log', FILENAME = N'L:\SSDB2019\TransLog\master0_log.ldf', SIZE = 8MB, FILEGROWTH = 8MB );

Adding other characters known from other parts of a database can add to the obscure situation.

CREATE DATABASE [master.] ON  PRIMARY 
( NAME = N'master_dot_data', FILENAME = N'L:\SSDB2019\Data\master_dot_data.mdf', SIZE = 8MB, FILEGROWTH = 8MB )
 LOG ON 
( NAME = N'master_dot_log', FILENAME = N'L:\SSDB2019\TransLog\master_dot_log.ldf', SIZE = 8MB, FILEGROWTH = 8MB );
GO

CREATE DATABASE [master.dbo] ON  PRIMARY 
( NAME = N'master_dbo_data', FILENAME = N'L:\SSDB2019\Data\master_dbo_data.mdf', SIZE = 8MB, FILEGROWTH = 8MB )
 LOG ON 
( NAME = N'master_dbo_log', FILENAME = N'L:\SSDB2019\TransLog\master_dbo_log.ldf', SIZE = 8MB, FILEGROWTH = 8MB );

The script file with the obscure master databases is also in SQLAdmin Github in obscure_master_database.sql.

2024-07-03

Stored Procedure Guidelines (T-SQL)

Here are some personal guidelines on writing and using a stored procedure. They are mentioned in a somewhat random order. The list and each recommendation will most likely change over time with new experinces, feedback and other new knowledge.

SET NOCOUNT ON

… to avoid unnecessary activity and communication on row count.

SET XACT_ABORT ON

… to roll back most transactions on error. See details from Sommarskog (link) and Swart (link).

SET QUOTED_IDENTIFIER ON

… to make the code a little more robust and strict. Also some protection against injection. Still I would prefer to enclose object and other identifiers in square brackets. This I think makes the code more strict and easy to maintain with several developers and teams involved.

Use schema name

... on used tables. Put procedure in custom schema without data. Do not use the schemas dbo or sys as they are not in your control.

Use tables

... not functional objects such as views, other procedures and triggers. And only use functions in stored procedure with careful big-O considerations. This could only be worse with the use of nested views, procedures, functions, triggers and other functional objects.

Use sets

... not cursors or sub-selects as SQL Server is set-based. Cursors are fine when on DB2 or Oracle. Sub-selects are often seen on SAS.

Use functional name

... not sp_ or other Hungarian naming. It doesn´t really matter what type the object is.

Use sp_executesql

hellip; for dynamic SQL. Not EXECUTE. In general you should avoid dynamic SQL. This includes prepared statements.

Use specific columns

... only take data that are required. Network traffic is then reduced to the required amount.

Use order of columns

... as given in the tables. One table a time. Re-arranging the columns could add significant resource consumption on each call.

Use keys

... and indexes with care. Use index on foreign keys. Check for covering index. Index usage might change with change of data in used tables.

Use table variables

... not temporary tables. This will keeps activity in buffer and away from storage,

Be direct

... and avoid temporary cached or staged data. Do not use dirty reads!

Be short

... by short transactions. Avoid costly isolation levels such as Repeatble Read. Also you can save some network traffic on often used stored procedures by short names on the procedure and the parameters.

Use effective parameters

... and avoid parameter sniffing. Focus on parameters where the values change a lot. Convert these parameters to local variables when suitable.

Check values

... before usage. Especially parameter values! Do the value check inside the procedure before usage.

Use effective types

... and avoid custom types. Custom types will add resource consumption on resources. And in some situation increase blockings on metadata.

Use effective operators

... avoid costly operators such as LIKE. Be carefull with COALESCE, string operations and aggregated values. T-SQL is for finding and sorting data. Use other languages for complex calculations and text processing.

Use explicit type cast

... not indirect or implicit. And you are still somewhat in control.

Use EXISTS

... not COUNT. As this is more effective with T-SQL.

Use effective error handling

... by testing before exception handling with TRY - CATCH. Consider exception handling as last-line-of-defence after tests and checks. Even when using exception handling this should be kept inseide the procedure. Throwing a exception outside the procedure could be rather costly on the resource consumption.

Use MS_Description

... extended property. This helps development with Visual Studio, see SQLAdmin on Descriptions.

Document

... procerdure, each parameter and output/return value in code, detailed and with examples. Also when you are the one and only developer and user.

Set security explicit

... on procedure through custom database roles on Active Directory groups. Using default database roles is outside your control.

Use ALTER PROCEDURE

... not DROP - CREATE PROCEDURE. Security and other external configurations will be lost on each change.

Monitor

... usage and performance with DMVs, XEvents etc. See Monitoring Performance of Natively Compiled Stored Procedures.

Call procedure effective

... with CommandType.StoredProcedure and SqlParameter objects on the SqlCommandobject. Use careful crafted connection string with secure authentication (SSPI) like Kerberos.

Reference

Kimberly Tripp, SQLSkills: Building High Performance Stored Procedures.

 

Top 10 stored procedure performance tuning tips in SQL server

History

2026-01-02 : Section on XACT_ABORT added. 2024-07-03 : Post published.

2022-07-15

Execute on a subset of databases

Sometimes it is necessary to execute a command or a statement on a subset of the databases in a instance. A quick solution is to generate the commands in a SELECT on sys.database and then execute the output.

But when this has been done a few times for a recurring task the solution becomes boring and tiresome. And then a more automated solution is required.

Automating the entire statement build and execxution over a cursor and using sp_executesql looks like a nice T-SQL solution.

DECLARE @DatabaseID AS INT;
DECLARE @DatabaseName AS NVARCHAR(50);
 
DECLARE @DatabaseCursor AS CURSOR;
SET @DatabaseCursor = CURSOR LOCAL FAST_FORWARD FOR
  SELECT name, database_id
  FROM sys.databases
  WHERE databases.name LIKE 'wso2am!_%' ESCAPE ('!');
OPEN @DatabaseCursor;

FETCH NEXT FROM @DatabaseCursor INTO @DatabaseName, @DatabaseID;
WHILE @@FETCH_STATUS = 0
BEGIN
  DECLARE @BackupSql NVARCHAR(4000) = N'BACKUP DATABASE [' + @DatabaseName + N'] TO DISK =''R:\BACKUP\' + @DatabaseName + '.bak'' WITH COPY_ONLY;';
  DECLARE @Msg NVARCHAR(2047) = CONVERT(nchar(27), SYSUTCDATETIME()) + N'Z  Backup [' + @DatabaseName + N']...'
  RAISERROR (@Msg, 0,0) WITH NOWAIT;
  DECLARE @BeginTime DATETIME2 = SYSUTCDATETIME();
  EXECUTE master.dbo.sp_executesql @stmt = @BackupSql;
  DECLARE @EndTime DATETIME2 = SYSUTCDATETIME();
  SET @Msg = N'  Duration = ' + CAST(DATEDIFF(s , @BeginTime, @EndTime) AS NVARCHAR(42)) + N's';
  RAISERROR (@Msg ,0,0) WITH NOWAIT;

  FETCH NEXT FROM @DatabaseCursor INTO @DatabaseName, @DatabaseID;
END
 
CLOSE @DatabaseCursor;
DEALLOCATE @DatabaseCursor;

The example above is part of cloning a subset of databases. I hope that you can use this in other situations.

2022-07-11

RAISERROR with UNIQUEIDENTIFIER

The T-SQL type Uniqueidentifier is not a formatting possibility for at RAISERROR message. But converting the value to a string is a quick fix. This example is based on the Uniqueidentifier output from the procedure sp_add_jobschedule.

DECLARE @_schedule_uid UNIQUEIDENTIFIER = N'7f6a5df0-a68f-4b07-992f-b7595958061f';
DECLARE @_schedule_code NVARCHAR(50) = CONVERT(NVARCHAR(50), @_schedule_uid);
RAISERROR ( N'Schedule UID = %s', 0,0, @_schedule_code ) WITH NOWAIT;

The output is then

Schedule UID = 7F6A5DF0-A68F-4B07-992F-B7595958061F

A small detail is that with the conversion the value is also converted to upper-case.

2017-04-29

T-SQL formatted duration

I have a database backup that takes more than two days, and I want to look at the duration. But looking at the result of a DATEDIFF the figures are difficult to compare direct.
That took me to format the duration to something readable. At first I wanted to format to ISO-8601, but that turned out to be too cumbersome in Transact-SQL. Especially getting the leading zeros was a challenge that I usually can handle in PowerShell or JavaScript, but T-SQL is not a programming language similar user friendly formatting…
Jeff Smith wrote back in 2007 a great article "Working with Time Spans and Durations in SQL Server", but I wanted to avoid the strange date-like part and the multiple columns he worked with.

To combine the different parts into one single-column answer I use part indicators like 'd' for days, 'h' for hours, 'm' for minutes and 's' for seconds. That I think is quite common indicators and should be immediately recognizable to most people. Also non-IT end users.

Most log solutions give a duration with a lot of seconds, like a SQL Server  database backup. But that can be difficult to comprehend and compare directly

DECLARE @duration INT = 221231;  -- seconds
SELECT CAST(@duration / 86400 AS varchar(3)) + 'd' + CAST((@duration % 86400) / 3600 AS varchar(2)) + 'h' + CAST((@duration % 3600) / 60 AS varchar(2)) + 'm' + CAST(@duration % 60 AS varchar(2)) + 's'

This gives the output
2d13h27m11s
That is 2 days, 13 hours, 27 minutes and 11 seconds.

The motivation for this blog entry is database backup history, and the formatting above can be used against the history
SELECT
  [database_name]
 ,backup_set_id, media_set_id, name
 ,backup_start_date, backup_finish_date
 ,CAST(DATEDIFF(SECOND, [backup_start_date], [backup_finish_date]) / 86400 AS varchar(3)) + 'd '
   + CAST((DATEDIFF(SECOND, [backup_start_date], [backup_finish_date]) % 86400) / 3600 AS varchar(2)) + 'h '
   + CAST((DATEDIFF(SECOND, [backup_start_date], [backup_finish_date]) % 3600) / 60 AS varchar(2)) + 'm '
   + CAST(DATEDIFF(SECOND, [backup_start_date], [backup_finish_date]) % 60 AS varchar(2)) + 's' AS [duration_formatted]
 ,(backup_size / 1024 / 1024 / 1024) as [backup_size_gb]
 ,(compressed_backup_size / 1024 / 1024 / 1024) as [compressed_backup_size_gb]
FROM msdb.dbo.backupset
--WHERE [database_name] = 'my_large_database'
ORDER BY [backup_finish_date] DESC

You can comment in or out lines in the statement above to get what you need in the given situation.

Maybe one can use STUFF to insert values in pre-formatted output, but that I could not get to work in first shot. And it did not really add significant value to the output...

2015-01-09

Leap Second and Day

Leap Second

A positive leap second 2015-06-30 has been announced by International Earth Rotation & Reference Systems Service:
hpiers.obspm.fr/iers/bul/bulc/bulletinc.dat
SQL Server gets the time from Windows, who knows how to handle a leap second (KB909614).
The leap second is „smeared“ so that the timestamps are not affected.
This gives that the leap second can not be registered.

In T-SQL it will look like this
(statement)
DECLARE @before_leap_second DATETIME = '2015-06-30 23:59:59'
SELECT @before_leap_second AS [normal_time];

(result)
normal_time
-----------------------
2015-06-30 23:59:59.000


(statement)
DECLARE @leap_second DATETIME = '2015-06-30 23:59:60';
SELECT @leap_second AS [leap_second];

(result)
Msg 242, Level 16, State 3, Line 1
The conversion of a varchar data type to a datetime data type resulted in an out-of-range value.

leap_second
-----------------------
NULL


Leap Day

A positive leap day is more precise defined. This gives that it can be defined in a data type, and calculations can be done correct. The Leap Day is nicely handled by T-SQL like this
(statement)
DECLARE @leap_day DATETIME = '2012-02-29';
SELECT @leap_day AS [leap_second];

(result)
leap_day
-----------------------
2012-02-29 00:00:00.000


Also a more tricky Leap Day is handled correct by T-SQL like this
(statement)
DECLARE @leap_day DATETIME = '2000-02-29';
SELECT @leap_day AS [leap_day];

(result)
leap_day
-----------------------
2000-02-29 00:00:00.000


An attempt to use a wrong Leap Day will give an error like above
(statement)
DECLARE @not_leap_day DATETIME = '2013-02-29'
SELECT @not_leap_day AS [not_leap_day];

(result)
Msg 242, Level 16, State 3, Line 11
The conversion of a varchar data type to a datetime data type resulted in an out-of-range value.

not_leap_day
-----------------------
NULL


History

2015-01-09 Blog entry about Leap Second.
2015-02-10 Blog entry added section about Leap Year.

2014-10-09

DBCC CHECKDB with PowerShell

Microsoft Transact-SQL (T-SQL) is really great for many things inside the SQL Server Database Engine, but automated maintenance with file handling, logging and other nice things is more of a challenge. This is why I and other fellow DBAs use PowerShell to automate tasks.

A standard DBA task is to check the databases, also their integrity with the console command DBCC CHECKDB.
The output like below is (somewhat) nicely formatted for human reading, but I would like to catch it inside the automation so that I can process and log the output.

Service Broker Msg 9675, State 1: Message Types analyzed: 14.
Service Broker Msg 9676, State 1: Service Contracts analyzed: 6.
Service Broker Msg 9667, State 1: Services analyzed: 3.
Service Broker Msg 9668, State 1: Service Queues analyzed: 3.
Service Broker Msg 9669, State 1: Conversation Endpoints analyzed: 0.
Service Broker Msg 9674, State 1: Conversation Groups analyzed: 0.
Service Broker Msg 9670, State 1: Remote Service Bindings analyzed: 0.
Service Broker Msg 9605, State 1: Conversation Priorities analyzed: 0.
DBCC results for 'sys.sysrscols'.
There are 1970 rows in 24 pages for object "sys.sysrscols".
DBCC results for 'sys.sysrowsets'.
There are 346 rows in 4 pages for object "sys.sysrowsets".
...
DBCC results for 'Person.vStateProvinceCountryRegion'.
There are 181 rows in 2 pages for object "Person.vStateProvinceCountryRegion".
DBCC results for 'sys.plan_persist_query'.
There are 0 rows in 0 pages for object "sys.plan_persist_query".
CHECKDB found 0 allocation errors and 0 consistency errors in database 'AdventureWorks2014'.
DBCC execution completed. If DBCC printed error messages, contact your system administrator.

(example on DBCC CHECKDB output from the database [AdventureWorks2014])

The PowerShell code is
$DatabaseName = 'AdventureWorks2014'
$Sql = "DBCC CHECKDB ([$DatabaseName]);"
$CheckDbMessages = @()
$CheckDbWatch = [System.Diagnostics.Stopwatch]::StartNew()
SQLCMD.EXE -E -Q $Sql |
ForEach-Object {
  $CheckDbMessages += $_
  "  {0:s}Z  $_" -f ([System.DateTime]::UtcNow)
}
$CheckDbWatch.Stop()

"{0:s}Z  Database [$DatabaseName] integrity check done in $($CheckDbWatch.Elapsed.ToString()) [hh:mm:ss.ddd]." -f ([System.DateTime]::UtcNow)
if ($CheckDbMessages[($CheckDbMessages.Count) - 2] -clike 'CHECKDB found 0 allocation errors and 0 consistency errors in database *') {
  "{0:s}Z  Database [$DatabaseName] integrity check is OK." -f ([System.DateTime]::UtcNow)
}
else {
  "{0:s}Z  Error in integrity check of the database [$DatabaseName]:`n  $($CheckDbMessages[($CheckDbMessages.Count) - 2])" -f ([System.DateTime]::UtcNow)
  throw "Integrity check of the database [$DatabaseName] failed."
}

(example on PowerShell script to execute DBCC CHECKDB)

I have put it inside a (advanced) function, but that is not shown here as is is the DBCC CHECKDB command execution that is the subject. I can only recommend that you take a serious look on PowerShell advanced functions. The best introduction that I still go back to is the book „Learn PowerShell Toolmaking in a Month of Lunches“ by Don Jones and Jeffery Hicks.
The variable $DatabaseName is a String object containing the name of the database to check.The script above does not check the prerequisites to the DBCC CHECKDB command.

  2014-10-09T17:55:04Z  DBCC results for 'AdventureWorks2014'.
  2014-10-09T17:55:04Z  Service Broker Msg 9675, State 1: Message Types analyzed: 14.
  2014-10-09T17:55:04Z  Service Broker Msg 9676, State 1: Service Contracts analyzed: 6.
  2014-10-09T17:55:04Z  Service Broker Msg 9667, State 1: Services analyzed: 3.
  2014-10-09T17:55:04Z  Service Broker Msg 9668, State 1: Service Queues analyzed: 3.
  2014-10-09T17:55:04Z  Service Broker Msg 9669, State 1: Conversation Endpoints analyzed: 0.
  2014-10-09T17:55:04Z  Service Broker Msg 9674, State 1: Conversation Groups analyzed: 0.
  2014-10-09T17:55:04Z  Service Broker Msg 9670, State 1: Remote Service Bindings analyzed: 0.
  2014-10-09T17:55:04Z  Service Broker Msg 9605, State 1: Conversation Priorities analyzed: 0.
  2014-10-09T17:55:04Z  DBCC results for 'sys.sysrscols'.
  2014-10-09T17:55:04Z  There are 1970 rows in 24 pages for object "sys.sysrscols".
  2014-10-09T17:55:04Z  DBCC results for 'sys.sysrowsets'.
  2014-10-09T17:55:04Z  There are 346 rows in 4 pages for object "sys.sysrowsets".
...
  2014-10-09T17:55:04Z  DBCC results for 'Person.vStateProvinceCountryRegion'.
  2014-10-09T17:55:04Z  There are 181 rows in 2 pages for object "Person.vStateProvinceCountryRegion".
  2014-10-09T17:55:04Z  DBCC results for 'sys.plan_persist_query'.
  2014-10-09T17:55:04Z  There are 0 rows in 0 pages for object "sys.plan_persist_query".
  2014-10-09T17:55:04Z  CHECKDB found 0 allocation errors and 0 consistency errors in database 'AdventureWorks2014'.
  2014-10-09T17:55:04Z  DBCC execution completed. If DBCC printed error messages, contact your system administrator.
2014-10-09T17:55:04Z  Database [AdventureWorks2014] integrity check done in 00:00:04.1890229 [hh:mm:ss.ddd].
2014-10-09T17:55:04Z  Database [AdventureWorks2014] integrity check is OK.

(example on DBCC CHECKDB output from script - AdventureWorks)

Using the good-old SQLCMD.EXE gives the output to the default output stream, where the output then can be processed in the automation by PowerShell.

The SQL Server PowerShell module SQLPS CmdLet Invoke-SqlCmd can also execute the command DBCC CHECKDB, and by setting the -Verbose flag the output is shown - but it is in the Verbose stream and can not be accessed direct in the automation for further processing.
Streaming the Verbose to a file with a redirection operator is possible, but introduces extra complexity...

With ADO.NET the challenge is the same as with the CmdLet Invoke-SqlCmd, and I guess that it is because the CmdLet is constructed in .NET using ADO.NET.

Actually it is a general challenge to catch T-SQL output shown as messages in SQL Server Management Studio. This is because the output is sent async as events.
It is possible to build a strict .NET solution by using SqlInfoMessageEventHandler but I find the solution with SQLCMD.EXE more simple, and that I do like.

The option TABLERESULTS to the command DBCC CHECKDB is not documented by Microsoft, but widely recognized. I do not use the TABLERESULTS option in this solution as the results are delivered during execution but af one answer when the execution is finish. This is the behavior in all cases, also with ADO.NET ExecuteReader.
I have some larger databases, where a check takes several hours and I would like to have a log of the execution. Is everything running? Any errors corrected up til now? and so on...
This is also why I add a timestamp to each message line from DBCC CHECKDB.

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-06-26

Logging in T-SQL scripts


I am working on a major version upgrade of a system that is using SharePoint and private databases. In both cases with 100+ GB data. Most database parts are scripted, and some tasks are running for hours.
Still it is important to the planning to know the execution time of the tasks and their steps.

This logging and timing I have done by wrapping the steps in some messages:
DECLARE @start datetime2 = SYSDATETIME();
DECLARE @errmsg nvarchar(2047) = CONVERT(nchar(23), @start, 126) + N'Z : Start';
RAISERROR(@errmsg,0,0) WITH NOWAIT;

-- Do something
WAITFOR DELAY '00:00:04';  -- HH:mm:ss

DECLARE @finish datetime2 = SYSDATETIME();
DECLARE @duration int = DATEDIFF(ms, @start, @finish);
SET @errmsg = CONVERT(nchar(23), @finish, 126) + N'Z : Finish after %i ms.';
RAISERROR(@errmsg, 0,0, @duration) WITH NOWAIT;


The duration of the step is in this case measured in milliseconds (ms), but could be measured in another unit. Unfortunately this unit can not be in a parameter, or as they say in the documentation on DATEDIFF() „User-defined variable equivalents are not valid.“.

I do prefer RAISERROR to PRINT to log in T-SQL. There are many discussions about this, but my take is that with RAISERROR ... WITH NOWAIT I will get the message immidiately and not when the batch block is finished and the PRINT–queue is processed.

PowerShell thoughts

To get a readable duration instead of a lot of ms like 56135000 you can create a TimeSpan object in PowerShell.
PS> \([System.TimeSpan]::FromMilliseconds(56135000)).ToString()
This will give a formatted timespan
15:35:35
Which is 15 hours, 35 minutes and 35 seconds.

If I have a larger script file with several steps, I would go for a PowerShell solution as I then would have better possibilities to log and use general parameters.

History

2012-06-26 Entry created.
2015-02-05 Section about TimeSpan object added.
2023-02-23 Formatting on @duration changed to conversion specification. And timestamp simplyfied.