SQL Server Query Optimization – Introduction

-> This is an Introduction blog post in a series of posts about optimizing SQL Server queries :-

-> SQL Server Parameter Sniffing
-> @@FETCH_STATUS -9
-> What DBCC SHOW_STATISTICS tells me
-> Trace Flag 7471
-> Tempdb contention
-> SQL Server Triggers and Insert performance
-> Optimize for ad hoc workloads
-> Why Bookmark Lookup is BAD?
-> Optimizing Queries using XML in SQL Server
-> Slow query performance with Table Spool operator

Thank You,
Vivek Janakiraman

Disclaimer:
The views expressed on this blog are mine alone and do not reflect the views of my company or anyone else. All postings on this blog are provided “AS IS” with no warranties, and confers no rights.

SQL Server Triggers and Insert performance

This is one of the blog post in a series of posts about optimizing SQL Server queries. A list of blog posts about query tuning can be found here – https://jbswiki.com/2021/04/15/sql-server-query-optimization-introduction/

-> Customer advised that insert performance on a database server is very bad. When checked further, I was able to understand that inserting 100 rows onto a table JB_Table1 took 252 Seconds,

INSERT INTO [dbo].[JB_Table1]([SNO],[firstname],[lastname],[age],[salary],[Lastsalary]) VALUES (1,'abc','def',34,54367.3,getdate())
go 100

-> I initially thought that there may be several indexes on the table that might be slowing down the inserts. Hence I checked the available indexes on the table and saw just 1 index,

-> You can download the Database backup file from here and try it in your lab.

-> I then executed a single insert statement with an execution plan,

-> From the execution plan it is clear that “Query cost” for Insert statement is 0%, but the update statement is 100%. But where is the update coming from, as we have not executed any updates.

-> That is when I realized that there is an underlying trigger that performs this update.

-> I captured a profiler trace using below events,

-> From the above screenshot we are clearly able to understand that Trigger “trg_jb_Table1_create_date” is utilizing all the resources. It executes for 2.3 seconds, performs close to 1.5 GB Reads and utilizes 2.3 Seconds of CPU. The time taken by the insert statement is high because we are executing the trigger for every insert.

-> Above execution plan shows a missing Index. Lets try creating it and check the performance,


USE [JBDB]
GO
CREATE NONCLUSTERED INDEX [IX_Test1] ON [dbo].[JB_Table1] ([CreateDate])
GO

-> Lets execute the insert statement and then capture a trace,

-> Single Insert statement is now just taking 30 MS duration, 440 KB reads and 0 CPU. This is much better.

-> Lets check the trigger definition,

-> Every time a row is inserted into Table JB_Table1, this trigger is used to update the “CreateDate” column with getdate(). I think this trigger can be replaced with a default constraint as below,

ALTER TABLE dbo.JB_Table1
  ADD CONSTRAINT DF_CreateDate_JB_Table1
  DEFAULT getdate() FOR CreateDate;
GO

-> Once the constraint is created. Backup the trigger and drop it,

USE [JBDB]
GO

DROP TRIGGER [dbo].[trg_jb_table1_create_date]
GO

-> Lets execute the insert statement and then capture a trace,

-> Now the insert statement takes just 1 MS Duration, 56 KB reads and 0 CPU. The best solution in this scenario will be to use default constraint and remove the trigger.

-> Dont forgot to remove Index IX_Test1 which was created to speed up trigger “trg_jb_Table1_create_date”.

USE [JBDB]
GO
DROP INDEX [IX_Test1] ON [dbo].[JB_Table1]
GO

-> Inserting 100 rows now completes in Milliseconds.

Thank You,
Vivek Janakiraman

Disclaimer:
The views expressed on this blog are mine alone and do not reflect the views of my company or anyone else. All postings on this blog are provided “AS IS” with no warranties, and confers no rights.

The connection to the primary replica is not active. The command cannot be processed. (Microsoft SQL Server, Error: 35250)

-> I was configuring Always On Availability group on Database Servers JBSAG1, JBSAG2 and JBSAG3 using the wizard. It all went fine and below is the screenshot,

-> Checked the Always On Availability Group dashboard and below was the status,

-> Checking from SQL Server Management Studio,

-> There is a warning sign under “Availability Databases” and the database is in restoring state on both the secondary replicas.

-> Below messages are found,

This secondary replica is not connected to the primary replica. The connected state is DISCONNECTED.

At least one availability database on this availability replica has an unhealthy data synchronization state. If this is an asynchronous-commit availability replica, all availability databases should be in the SYNCHRONIZING state. If this is a synchronous-commit availability replica, all availability databases should be in the SYNCHRONIZED state.

This secondary replica is not joined to the availability group. For an availability replica to be successfully joined to the availability group, the join state must be Joined Standalone Instance (1) or Joined Failover Cluster (2). For information about how-to join a secondary replica to an availability group, see SQL Server Books Online.

-> I tried to join the database JBDB to Availability group and got below message,

TITLE: Microsoft SQL Server Management Studio

Failed to join the database ‘JBDB’ to the availability group ‘JBAG’ on the availability replica ‘JBSAG2’. (Microsoft.SqlServer.Smo)

For help, click: https://go.microsoft.com/fwlink?ProdName=Microsoft+SQL+Server&ProdVer=16.100.46041.41+(SMO-master-A)&EvtSrc=Microsoft.SqlServer.Management.Smo.ExceptionTemplates.FailedOperationExceptionText&LinkId=20476

ADDITIONAL INFORMATION:

An exception occurred while executing a Transact-SQL statement or batch. (Microsoft.SqlServer.ConnectionInfo)

The connection to the primary replica is not active. The command cannot be processed. (Microsoft SQL Server, Error: 35250)

-> Checking SQL Server Error log in JBSAG2,

2021-04-12 16:01:56.190 spid54 ALTER DB JBDB with AGNAME:JBAG
2021-04-12 16:01:56.190 spid54 ALTER DB param option: SET
2021-04-12 16:02:44.280 spid48s Always On Availability Groups connection with primary database terminated for secondary database ‘JBDB’ on the availability replica ‘JBSAG1’ with Replica ID: {81ddde84-4546-47f7-b78b-6de341c46f34}. This is an informational message only. No user action is r
2021-04-12 16:02:44.280 spid54 State information for database ‘JBDB’ – Hardened Lsn: ‘(130:102920:1)’ Commit LSN: ‘(0:0:0)’ Commit Time: ‘Apr 12 2021 9:46AM’
2021-04-12 16:02:44.290 spid54 State information for database ‘JBDB’ – Hardened Lsn: ‘(130:102920:1)’ Commit LSN: ‘(0:0:0)’ Commit Time: ‘Apr 12 2021 9:46AM’
2021-04-12 16:02:44.290 spid54 Starting up database ‘JBDB’.
2021-04-12 16:02:44.300 spid54 The database ‘JBDB’ is marked RESTORING and is in a state that does not allow recovery to be run.
2021-04-12 16:02:44.310 spid54 State information for database ‘JBDB’ – Hardened Lsn: ‘(130:102920:1)’ Commit LSN: ‘(0:0:0)’ Commit Time: ‘Apr 12 2021 9:46AM’
2021-04-12 16:02:44.310 spid54 State information for database ‘JBDB’ – Hardened Lsn: ‘(130:102920:1)’ Commit LSN: ‘(0:0:0)’ Commit Time: ‘Apr 12 2021 9:46AM’
2021-04-12 16:02:44.310 spid54 Starting up database ‘JBDB’.
2021-04-12 16:02:44.320 spid54 The database ‘JBDB’ is marked RESTORING and is in a state that does not allow recovery to be run.

-> Checking SQL Server Error log in JBSAG3,

2021-04-12 15:46:53.000 Backup Database was restored: Database: JBDB, creation date(time): 2021/04/12(09:06:02), first LSN: 130:102896:1, last LSN: 130:102920:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {‘\JBS-SQL-DC\Backup\JBDB.bak’}). Informational message.
2021-04-12 15:46:53.020 Backup RESTORE DATABASE successfully processed 461154 pages in 167.666 seconds (21.487 MB/sec).
2021-04-12 15:46:53.650 Backup Log was restored. Database: JBDB, creation date(time): 2021/04/12(09:06:02), first LSN: 130:102816:1, last LSN: 130:102920:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {‘\JBS-SQL-DC\Backup\JBDB.trn’}). This is an informational mes

-> Messages/errors in SQL Server error log did not provide any clue.

-> Executing below query on each of the instances,

select r.replica_server_name, r.endpoint_url,
rs.connected_state_desc, rs.last_connect_error_description,
rs.last_connect_error_number, rs.last_connect_error_timestamp
from sys.dm_hadr_availability_replica_states rs join sys.availability_replicas r
on rs.replica_id=r.replica_id
where rs.is_local=1

Primary – JBSAG1

Synchronous Secondary – JBSAG2

Error Message,
Connection attempt failed with error: ‘10060(A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond.)’.

Asynchronous Secondary – JBSAG3

Error Message,
Connection attempt failed with error: ‘10060(A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond.)’.

-> The error message refers to a connection issue between the primary and secondaries.

-> Endpoint uses port 5022. Lets check if port 5022 is not blocked using telnet.

‘telnet’ is not recognized as an internal or external command,
operable program or batch file.

-> Execute below command in powershell to enable telnet.

Install-WindowsFeature -name Telnet-Client

-> Telnet is not working for port 5022. It proves that port 5022 is not open.

-> Let us create a firewall rule to open port 5022.

-> Open “Windows Firewall with Advanced Security” and open “Inbound Rules” on JBSAG1, JBSAG2 and JBSAG3.

-> Wait for 5 mins and check the status now by executing below query,

select r.replica_server_name, r.endpoint_url,
rs.connected_state_desc, rs.last_connect_error_description,
rs.last_connect_error_number, rs.last_connect_error_timestamp
from sys.dm_hadr_availability_replica_states rs join sys.availability_replicas r
on rs.replica_id=r.replica_id
where rs.is_local=1

-> After opening port 5022, We couldn’t see that error anymore.

-> Let’s try joining the database again and it works fine this time,

Thank You,
Vivek Janakiraman

Disclaimer:
The views expressed on this blog are mine alone and do not reflect the views of my company or anyone else. All postings on this blog are provided “AS IS” with no warranties, and confers no rights.