SQL Server – Linked Server – TroubleShooting

Background

There are a variety of avenues for diagnosing Linked Server related connectivity issues.

 

Follow Up

As a quick follow up to earlier conversations on SQL Server and heterogeneous data sources:

  1. SQL Server / Linked Server – Oracle ODAC
    Link

 

Outline

Here are some of the tools for diagnosis heterogenous data related issues:

  1. Query
    • DBCC
      • Trace Flag 7300
  2. SQL Server Profiler
  3. Event Viewer
  4. SysInternals
    • Process Explorer

 

 

Query

DBCC

Trace Flag 7300

Query
Syntax

dbcc traceon(7300) 
	with no_infomsgs
	;
go

dbcc traceoff(7300)
	with no_infomsgs
	;
go


Sample

dbcc traceon(7300) 
	with no_infomsgs
	;
go

declare @linkedServer sysname

set @linkedServer = 'HRDB';

exec sp_tables_ex
		@table_server = @linkedServer

go

dbcc traceoff(7300)
	with no_infomsgs
	;
go


Sample – Grid
Sample – Textual

OLE DB provider "OraOLEDB.Oracle" for linked server "PRD" returned message "ORA-12170: TNS:Connect timeout occurred".
Msg 7303, Level 16, State 1, Procedure sp_tables_ex, Line 41 [Batch Start Line 4]
Cannot initialize the data source object of OLE DB provider "OraOLEDB.Oracle" for linked server "PRD".


Explanation
  1. Error Message
    • OLE DB provider “OraOLEDB.Oracle” for linked server “PRD” returned message
      • “ORA-12170: TNS:Connect timeout occurred”.
    • Cannot initialize the data source object of OLE DB provider “OraOLEDB.Oracle” for linked server “PRD”.
  2. Using DBCC TraceOn (7300)
    • Allows us to see that we are experiencing connection timeout to the Oracle Server
    • Likely means network or TNS configuation error

 

 

SQL Server Profiler

Trace Properties

Trace Event Selections

Here are the events that we will be tracing on…

Event Category Event Event Description
Errors and Warnings
ErrorLog  Indicates error events logged in the SQL Server error log.
EventLog  Indicates events logged in the Windows application event log.
Exception  Indicates that an exception has occurred in SQL Server.
Execution Warnings  Indicates any warnings that occurred during the execution of a SQL Server statement or stored procedure.
User Error Message  Displays the error message as seen by the user in the case or an error or exception. The error message text appears in the TextData field.
OLEDB
OLEDB Call Event Includes event classes produced by the execution of stored procedures.
OLEDB Data Read Event Displays OLE DB IRowset::GetData calls made by SQL Server for fetching row data for distributed queries and remote stored procedures.
OLEDB Errors Indicates that an OLE DB error has occurred.
OLEDB Provider Information Occurs when a distributed query is run and collects information corresponding to the provider connection. This event class contains all the properties collected from the remote provider using various property sets such as DBPROPSET_DATASOURCEINFO, SQLPROPSET_OPTHINTS, DBPROPSET_SQLSERVERDATASOURCEINFO (SQL Server only), DBPROPSET_SQLSERVERDBINIT (SQL Server only) and DBPROPSET_ROWSET and interface IDBInfo.
OLEDB Query Interface Event Displays OLE DB IUnknown::QueryInterface calls made by SQL Server for distributed queries and remote stored procedures.
Security Audit
Audit Login Collects all new connection events since the trace was started, such as when a client requests a connection to a server running an instance of SQL Server.
Audit Logout Collects all new disconnect events since the trace was started, such as when a client issues a disconnect command.
Stored Procedures
RPC:Completed Occurs when a remote procedure call has been completed.
TSQL
SQL:BatchCompleted Occurs when the Transact-SQL statement has completed.
SQL:BatchStarting Occurs when a Transact-SQL batch is starting.

 

 

Traces

Sample Traces

Sample Trace #01
Image – Full Conversation

Image – OLEDB Call Event
Explanation
  1. SQL:BatchStarting
    • Issues sp_tables_ex
    • Query Linked Server asking for a listing of tables
  2. OLEDB QueryInterface Event
    • IID_IDBProperties
      • <ppunk>0x0000003C47F941D8</ppunk>
        • Set ppunk to 0x0000003C47F941D8
  3. OLEDB Call Event
    • Property
      • DBPROP_INIT_TIMEOUT
      • DBPROP_INIT_GENERALTIMEOUT
      • DBPROP_INIT_DATASOURCE
      • DBPROP_AUTH_USERID
      • DBPROP_AUTH_PASSWORD
    • Result
      • hresult
        • 265946
          • ???
  4. OLEDB QueryInterface Event
    • IID_IDBInitialize
      • input
        • IID_IDBInitialize
      • hresult
        • 0
      • ppunk
        • <ppunk>0x0000003C47F941E0</ppunk>
          • returns 0x0000003C47F941E0
    • IID_ISSAsynchStatus
      • input
        • IID_ISSAsynchStatus
      • hresult
        • -2147467262
  5. OLEDB Errors
    • hresult
      • -2147467259
  6. OLEDB Query Interface Event
    • input
      • IID_ISupportErrorInfo
    • hresult
      • 0
    • outputs
      • 0x00000044686EBFC0
  7. OLEDB Call Event
    • input
      • IID_IDBInitialize
    • hresult
      • 0
  8. User Error Message
    • OLE DB provider “OraOLEDB.Oracle” for linked server “PRD” returned message “ORA-12170: TNS:Connect timeout occurred“.
  9. Exception
    • Cannot initialize the data source object of OLE DB provider “OraOLEDB.Oracle” for linked server “PRD”.
  10. User Error Message
    • Cannot initialize the data source object of OLE DB provider “OraOLEDB.Oracle” for linked server “PRD”.

 

Event Viewer

Security

Filter

Tabulate

Courtesy of SANS.org:

SANS Institute
InfoSec Reading Room
Windows Logon Forensics
Link

Event  ID = Windows XP / Windows 2000 Windows 2008/2012/2014, etc Event Description
 528 4624 Successful logon: A user successfully logged on to a computer. For
information about the type of logon, see the next section
 529 4625  Logon failure. A logon attempt was made with an unknown user name
or a known user name with a bad password. For Windows 2008 and
above, event ID 4625 logs every failed logon attempt with failure status
code regardless of logon type or type of account
530 4625 Logon failure for a logon attempt to log on outside of the allowed time
 531 4625  Logon failure for a logon attempt using a disabled account.
 532 4625  Displays the error message as seen by the user in the case or an error or exception. The error message text appears in the TextData field.
 533  4625 Logon failure. A logon attempt was made by a user who is not allowed
to log on at this computer.
 534 4625 Logon failure. The user attempted to log on with a type that is not allowed.
 535 4625 Logon failure. The password for the specified account has expired.
 536 4625 Logon failure. The Net Logon service is not active
 537 4634 Logon failure. The logon attempt failed for other reasons. In some
cases, the reason for the logon failure may not be known.
 538 4634 The logoff process was completed for a user.
 538/551 4647 A user initiated the logoff process. It is logged for Interactive and
RemoteInteractive logons in place of logoff event 538/4634.
 539 4625 Logon failure. The account was locked out at the logon
 540 4624 Successful network logon: A user successfully logged on over a
network.
 552 4648 A user successfully logged on to a computer using explicit credentials while already logged on as a different user
 638 4778 A user has reconnected to a disconnected terminal session.
 683 4625 A user disconnected a terminal session without logging off.

 

Image

 

Sample
Sample 01
Image – Top

Image – Bottom
Explanation
  1. Security ID
    • NULL SID
  2. Logon Type
    • Logon Type 3 is Network
  3. Impersonation Level
    • Impersonation
  4. New Logon
    • Security ID
      • LABdadeniji
    • Account Name
      • dadeniji
    • Account Domain
      • LAB
  5. Network Information
    • Workstation Name
      • DADENIJI
    • Source Network Address
      • w.x.y.z
    • Source Network Port
      • #####
  6. Detailed Authentication
    • Logon Type
      • NtLmSsp
    • Authentication Package
      • NTLM
    • Package Name (NTLM only)
      • NTLM V2
    • Key Length
      • 128

SysInternals

Process Explorer

Application Context

OLE-DB Provider can be configured to run in process or out of process.

If run in process we need to track the sql server service.

When ran out of process, we need to track via dllhost.exe

Sample

Sample – 01
Image

Explanation
  1. dllhost.exe
    • COM Class
      • MSDAINITIALIZE Class
      • c:program filescommon filessystem32ole dboledb32.dll
      • OLEDB Core Services

tasklist

Preface

The OLE-DB Provider can either be configured to run as in-process or out-of process.

When in process it runs within the sqlservr.exe address space.

When out of process, it runs within a surrogate process, dllhost.exe.

out of Process – dllhost.exe

syntax

tasklist /m /fi "Imagename eq dllhost.exe"

Output
Output # 01

Explanation
  1. We can see that Oracle dlls are loaded within the dllhost.exe

 

References

  1. Microsoft
    • Microsoft Developer
      • SQL BI / Data Access Technologies
        • Snehadeep
          • Troubleshooting “Cannot create an instance of OLE DB provider”
            Link
    • CSS SQL Server Engineers
      • pssql
        • How to get up and running with Oracle and Linked Servers
          Link
  2. Gianluca Sartori
    • Setting up linked servers with an out-of-process OLEDB provider.
      Link
  3. Sans Institute
    • Windows Login Forensics
      Link

SQL Server – RML Utility – Converting Extended Events to SQL Server Profiler Trace Files

Background

Extended Events is the modern way to collect events.  But, in some cases one might want to convert Extended Events to SQL Server Profiler Traces.

RML Utility

Reading through a blog post found out one can convert files generated through Extended Events into Profiler Trace Files.

Download Site

The latest version of RML Utility are available here.

Curiosity

The saying goes curiosity killed the cat.

Same here this last Monday in January.

 

Installation

Download and Installed RML Utilities.

Review Installation

Targeted Folder

The targeted folder is C:\Program Files\Microsoft Corporation\RMLUtils

ReadTrace

File Version

Image

Explanation

The file version is 9.4.51.0

 

Processing

Code


set "_folderReadTrace=C:\Program Files\Microsoft Corporation\RMLUtils\"

set "_xelFolder=Z:\Microsoft\SQLServer\ExtendedEvents\TraceFiles\replay"

set "_xelFileFirst=replay_0_131617352214050000.xel"

set "_xelFileTarget=%_xelFolder%\%_xelFileFirst%"

set "_tracefile=Z:\Microsoft\SQLServer\ProfileTrace\TraceFiles"

set "_sqlServer=DBLAB"

if not exist %_tracefile% mkdir %_tracefile%

"%_folderReadTrace%\readtrace.exe"  -S%_sqlServer% -a -I"%_xelFileTarget%" -MS -o"%_tracefile%"

 

Output

Image

Textual


01/29/18 16:29:39.892 [0X000015D8] I/O Completion manager started
01/29/18 16:29:39.893 [0X00002BE4] Attempting DOD5015 removal of [Z:\Microsoft\S
QLServer\ProfileTrace\TraceFiles\ReadTrace.log]
01/29/18 16:29:39.896 [0X00002BE4] Readtrace a SQL Server trace processing utili
ty.
Version 9.04.0051 built for x64.
Copyright ⌐ 1997-2014 Microsoft. All Rights Reserved
01/29/18 16:29:39.897 [0X00002BE4]             Computer: D-ITS-AYSOSQL02
01/29/18 16:29:39.897 [0X00002BE4]          Base Module: C:\Program Files\Micros
oft Corporation\RMLUtils\ReadTrace.exe
01/29/18 16:29:39.897 [0X00002BE4]           Process Id: 6480
01/29/18 16:29:39.898 [0X00002BE4]  Active proc mask(0): 0x0000000F
01/29/18 16:29:39.898 [0X00002BE4]         Architecture: 9
01/29/18 16:29:39.898 [0X00002BE4]            Page size: 4096
01/29/18 16:29:39.898 [0X00002BE4]                 CPUs: 4
01/29/18 16:29:39.899 [0X00002BE4]     Processor groups: 1
01/29/18 16:29:39.899 [0X00002BE4]         Highest node: 0
01/29/18 16:29:39.899 [0X00002BE4]   Proximity: 00  Node: 00
01/29/18 16:29:39.900 [0X00002BE4] ---------------------------------------
01/29/18 16:29:39.900 [0X00002BE4]                Group: 0
01/29/18 16:29:39.900 [0X00002BE4] ---------------------------------------
01/29/18 16:29:39.901 [0X00002BE4]         Processor(s): 0x00000001 Function uni
ts: Separated
01/29/18 16:29:39.901 [0X00002BE4]         Package mask: 0x00000003
01/29/18 16:29:39.901 [0X00002BE4]         Processor(s): 0x00000002 Function uni
ts: Separated
01/29/18 16:29:39.901 [0X00002BE4]         Processor(s): 0x00000004 Function uni
ts: Separated
01/29/18 16:29:39.902 [0X00002BE4]         Package mask: 0x0000000C
01/29/18 16:29:39.902 [0X00002BE4]         Processor(s): 0x00000008 Function uni
ts: Separated
01/29/18 16:29:39.902 [0X00002BE4]         Processor(s): 0x0000000F assigned to
Numa node: 0
01/29/18 16:29:39.907 [0X00002BE4] Current time bias: 480 minutes 8.00 hours DST
 Standard
01/29/18 16:29:39.907 [0X00002BE4] -SDBLAB
01/29/18 16:29:39.908 [0X00002BE4] -a
01/29/18 16:29:39.908 [0X00002BE4] -IZ:\Microsoft\SQLServer\ExtendedEvents\Trace
Files\replay\replay_0_131617352214050000.xel
01/29/18 16:29:39.908 [0X00002BE4] File mirroring enabled, with single file targ
et
01/29/18 16:29:39.909 [0X00002BE4] -MS
01/29/18 16:29:39.909 [0X00002BE4] -oZ:\Microsoft\SQLServer\ProfileTrace\TraceFi
les
01/29/18 16:29:39.910 [0X00002BE4] Using language id (LCID): 1024 [English_Unite
d States.1252] for character formatting with NLS: 0x0006020E and Defined: 0x0006
020E
01/29/18 16:29:39.911 [0X00002BE4] Attempting to cleanup existing RML files from
 previous execution
01/29/18 16:29:39.991 [0X00002BE4] Detecting list of matching XEL files in the s
ame directory
01/29/18 16:29:40.039 [0X00002BE4]  INFO: Using additional file system cache rea
d ahead for XEL input
01/29/18 16:29:40.046 [0X00002BE4] XEL READER ERROR: The tookLock argument must
be set to false before calling this method.
01/29/18 16:29:40.048 [0X00002BE4] XEL READER ERROR: Attempt to open file Z:\Mic
rosoft\SQLServer\ExtendedEvents\TraceFiles\Replay\replay_0_131617352214050000.XE
L failed, see previous error(s) for more details.
01/29/18 16:29:40.049 [0X00002BE4] ERROR: Attempt to open Z:\Microsoft\SQLServer
\ExtendedEvents\TraceFiles\Replay\replay_0_131617352214050000.XEL failed.
01/29/18 16:29:40.050 [0X00002BE4] ERROR: Unable to construct proper base metada
ta generation for Z:\Microsoft\SQLServer\ExtendedEvents\TraceFiles\Replay\replay
_0_131617352214050000.XEL
01/29/18 16:29:40.053 [0X00002BE4] ERROR: Attempt to determine list of .XEL file
s failed.
01/29/18 16:29:40.057 [0X00002BE4] *** ERROR: Attempt to initialize trace file r
eader failed with operating system error 0x80070006 (The handle is invalid)
01/29/18 16:29:40.061 [0X00002BE4] Reads completed - Global Error Status 0xfffff
ffe
01/29/18 16:29:40.062 [0X00002BE4] Signaling worker threads to complete final ac
tions.
01/29/18 16:29:40.067 [0X00002BE4] Waiting for the worker threads to complete fi
nal actions.
01/29/18 16:29:40.069 [0X00002BE4] Performing general cleanup actions.
01/29/18 16:29:40.072 [0X00002BE4] Performing final mirroring actions.
01/29/18 16:29:40.075 [0X00002BE4] Total Events Processed: 0
01/29/18 16:29:40.076 [0X00002BE4]  Total Events Filtered: 0
01/29/18 16:29:40.077 [0X00002BE4] =============================================
=
01/29/18 16:29:40.079 [0X00002BE4] WARNING: A significant portion of the events
where filtered.
01/29/18 16:29:40.086 [0X00002BE4]          You may want to check the filtering
criteria.
01/29/18 16:29:40.088 [0X00002BE4] =============================================
=
01/29/18 16:29:40.090 [0X00002BE4] *********************************************
**********************************
* ReadTrace encountered one or more ERRORS. An error condition typically      *
* stops processing early and the ReadTrace output may be unusable.            *
* Review the log file for details.                                            *
*******************************************************************************
01/29/18 16:29:40.094 [0X00002BE4] ***** ReadTrace exit code: -2
01/29/18 16:29:40.097 [0X00002BE4]  INFO: Max set-aside XEL event hash table ent
ry count: 0
01/29/18 16:29:40.131 [0X00002BE4]
01/29/18 16:29:40.134 [0X00002BE4] INFO: Cleaning up connection info hash table
>

Explanation

Key details:

  1. [0X00002138] Detecting list of matching XEL files in the same directory
  2. [0X00002138] INFO: Using additional file system cache read ahead for XEL input
  3. [0X00002138] XEL READER ERROR: The tookLock argument must be set to false before calling this method.
  4. [0X00002138] XEL READER ERROR: Attempt to open file Z:\Microsoft\SQLServer\ExtendedEvents\TraceFies\Replay\replay_0_131617352214050000.XEL failed, see previous error(s) for more details.
  5. ERROR: Attempt to open Z:\Microsoft\SQLServer\ExtendedEvents\TraceFiles\Replay\replay_0_131617352214050000.XEL failed.
    [0X00002138] ERROR: Unable to construct proper base metadata generation for Z:\Microsoft\SQLServe
    \ExtendedEvents\TraceFiles\Replay\replay_0_131617352214050000.XEL
  6. [0X00002138] ERROR: Attempt to determine list of .XEL files failed.
  7. [0X00002138] *** ERROR: Attempt to initialize trace file reader failed with operating system error 0x80070006 (The handle is invalid)
  8. [0X00002138] Reads completed – Global Error Status 0xfffffffe
  9. [0X00002138] ***** ReadTrace exit code: -2

 

TroubleShooting

ReadTrace

Code


"C:\Program Files\Microsoft Corporation\RMLUtils\readtrace.exe" /?

Output

Explanation

  1. -I File name of the first .TRC or .XEL file to process [REQUIRED]. Note: XEL processing is ‘BETA’ and limited.
    • Clearly states that XEL ( Extended Events ) processing is in BETA mode and limited

SysInternals

Process Monitor

Captured Events
Image

Explanation

Confirmed that the extended event file was located and opened successfully.

 

Summary

It appears that readtrace at Version 9.4.51.0, last modified on Dec 10,2014 is starting to show its age.

BTW, in SQL Server parlance 9.x.y.z is MS SQL Server v2005.

SQL Server Agent – Error – “Failed to initialize sqlcmd library with error number -2147467259”

Background

Experienced error running SQL Server Agent job that we are developing.

Error

Error Image

Error Message

Executed as user: LAB\mssql. @profileName :- DBA Mail [SQLSTATE 01000] (Message 0) @recipientsTo :- daniel@lab.org [SQLSTATE 01000] (Message 0) @subject :- Privilege Users on HRDB [SQLSTATE 01000] (Message 0) Failed to initialize sqlcmd library with error number -2147467259. [SQLSTATE 42000] (Error 22050) @body :- [SQLSTATE 01000] (Error 0). The step failed.

Explanation

  1. The error message states “Failed to initialize sqlcmd library with error number -2147467259.
  2. Unfortunately the error message is not precise

 

TroubleShooting

SQL Server Profiler

Trace Definition

Events Selection

Image

Trace Captured

Image

Explanation

  1. Event
    • Event Class :- User Error Message
    • TextData :- The EXECUTE permission was denied on the object ‘sp_DBRoleMembersList’, database ‘master’, schema ‘dbo’.
    • Application Name :- SQLCMD
    • Error :- 229

SQL Server Agent

SQL Server Agent Account

Let us get SQL Server Agent Account

SQL


select 
        tblSDSS.[servicename]
      , tblSDSS.[service_account]
from   sys.dm_server_services tblSDSS

Output

Explanation

  1. We have the service accounts that we are using for the SQL Server Engine and Agent

Remediation

Grant “SQL Server Agent” service account execute permission on targeted object.

.Net / SQL Server–Transaction Isolation Level–Tracking thru Profiler

Background

As said in the past one of the areas to familiarize oneself with when experiencing deadlocks and timeouts is the Application’s default Isolation Level.

Developers are also able to change and revert Isolation Level during the course of an Application.

Lineage

Here are previous posts on Isolation Levels

  1. Entity Framework & Isolation Levels
    Link

Lab

In the code that we will be profiling, we requested an isolation Level of Serializable.

TroubleShooting

DBA

The SQL Server DBA has various tools to track Transaction Isolation level.

Inclusive are:

  1. Querying the Dynamic Management Views ( DMV )
  2. SQL Server Profiler

Dynamic Management Views

Supporting View

constant.vw_IsolationLevel
Overview

We use the Constant.vw_IsolationLevel view to convert the numeric IsolationLevel to its String equivalence.

Btw, at a session level the Isolation Level is exposed via the sys.dm_exec_sessions DMV; specifically the transaction_isolation_level column.

Code

use master
go


if schema_id('constant') is null
begin

	exec('create schema [constant] authorization [dbo]')
end

go
if object_id('[constant].[vw_IsolationLevel]') is null
begin

	exec('create view [constant].[vw_IsolationLevel] as select [shell] = 1/0');

end
go


 alter view [constant].[vw_IsolationLevel]
 as

	select 
			  [id] = 0
			, [literal] = 'Unspecified'

	union all

    select
		     [id] = 1
		   , [literal] = 'ReadUncommitted'

	union all

    select
		     [id] = 2
		   , [literal] = 'ReadCommitted'

	union all

    select
		     [id] = 3
		   , [literal] = 'RepeatableRead'

	union all

    select
		     [id] = 4
		   , [literal] = 'Serializable'

	union all

    select
		     [id] = 5
		   , [literal] = 'Snapshot'

go

grant select on [constant].[vw_IsolationLevel] to [public]
go


Query

The SQL code below queries the Dynamic Management Views and identifies the data listed below:

  1. sys.dm_exec_sessions
    • login_name
  2. [master].[constant].[vw_IsolationLevel]
    • isolation level literal
  3. sys.dm_exec_requests
  4. sys.dm_tran_session_transactions
    • transaction_descriptor
    • transaction_id
    • is_user_transaction
  5. sys.dm_tran_active_transactions
    • Transaction Name
      • user_transaction
      • <Name> if named transaction
Code

select 

		  tblDES.[session_id]

		--, tblDES.[is_user_process]
		, tblDES.[login_name]

		, tblDES.[host_name]

		, tblDES.[program_name]

		, tblDES.[transaction_isolation_level]

		, [transactionIDRequest]
			= tblDER.[transaction_id]

		, [transactionDescriptor]
			= tblDMTST.transaction_descriptor

		, [transactionIDTransaction]
			= tblDMTST.[transaction_id]		

		--, tblDMTST.is_enlisted
		--, tblDMTST.is_bound
		, [isUserTransaction]
			= tblDMTST.is_user_transaction

		, vwIL.[literal]

		, [transactionName]
			= tblSMTAT.[name]

		, tblDES.[open_transaction_count]

		, tblDER.[command]

		, [sessionState]
			= tblDES.[status]

from   sys.dm_exec_sessions tblDES

left outer join [master].[constant].[vw_IsolationLevel] vwIL
		on tblDES.transaction_isolation_level = vwIL.[id]

left outer join sys.dm_exec_requests tblDER
		on tblDES.[session_id] = tblDER.[session_id]

left outer join sys.dm_tran_session_transactions  tblDMTST
		on tblDES.[session_id] = tblDMTST.[session_id]

left outer join sys.dm_tran_active_transactions tblSMTAT
		on tblDMTST.[transaction_id] = tblSMTAT.transaction_id

where  (
	
			( tblDES.session_id >= 50)
	   )

and   (
			( tblDES.[login_name] != SYSTEM_USER )
	  )

order by
		  vwIL.[literal] desc
		, tblDES.[session_id] asc

Query Result

 

SQL Server Profiler

Trace File Properties

Image

Here are the events that we are Tracing On.

And, the properties that we watching.

Events Captured

Tabulate
Event Class Payload
 Audit Login set transaction isolation level read committed
 TM: Begin Tran starting Begin Transaction
 SQLTransaction
 TM: Begin Tran completed  Begin Transaction
 RPC:Completed  exec sp_executesql N’SELECT
[Limit1].[C1] AS [C1]
FROM ( SELECT TOP (1)
[Extent1].[sequenceNbr] AS [C1]
FROM [dbo].[TVF_TraceFlagSource_GetSequenceNbrMax](@traceID) AS [Extent1]
) AS [Limit1]’,N’@traceID int’,@traceID=2551
 Audit Logout
 RPC: Completed  exec sp_reset_connection
 Audit Login set transaction isolation level read committed
 RPC:Completed  exec sp_executesql N’INSERT [dbo].[traceFlagSource]([id], [sequenceNbr], [status],

, [title], [url], [addedBy], [dateAdded])
VALUES (@0, @1, @2, @3, @4, @5, @6, @7)
‘,N’@0 int,@1 tinyint,@2 bit,@3 varchar(100),@4 varchar(100),@5 varchar(200),@6 nvarchar(128),@7 datetime2(7)’,@0=2551,@1=9,@2=1,@3=’msft’,@4=’caps’,@5=’http://&#8217;,@6=N’LAB\dadeniji’,@7=’2017-06-08 19:58:00.3960092′

 Audit Logout
 RPC: Completed  exec sp_reset_connection
 TM: Commit Tran starting COMMIT TRANSACTION
 SQLTransaction
 TM: Commit Tran completed COMMIT TRANSACTION

 

 

Screen Capture

Screen Capture :- 001 – TraceStart

Screen Capture :- 002 – SQLTransaction

 

Screen Capture :- 003 — SQLTransaction

Screen Capture :- 004 – Audit Login

Image

Explanation

The Audit Login event captures the following:

  1. The session’s event such as
    • set transaction isolation level read committed

Screen Capture :- 005 — “TM: Begin Tran starting”

Image

 

Explanation

The “TM: Begin Tran starting” event

  1. Contains the “Begin Transaction” payload

 

Screen Capture :- 006 — “SQLTransaction”

Image

Explanation

The “SQLTransaction” event

  1. Requests for Sql Server to start a new transaction

 

Screen Capture :- 007 — “TM: Begin Tran completed”

Image

 

Explanation

The “TM: Begin Tran completed” event

  1. The Transaction Manager confirmed that the transaction has began

 

Screen Capture :- 008 — “RPC: Completed”

Image

Explanation

The “RPC:Completed” event

  1. The SQL to get the current max sequenceNbr is completed

 

Screen Capture :- 010 — “Audit Logout”

Image

 

Explanation

The “Audit Logout” event

  1. Connection Logged out

 

Screen Capture :- 010 — “RPC: Completed”

Image

Explanation

The “RPC:Completed” event

  1. The SQL to reset the connection is completed
    • The payload is “exec sp_reset_connection

 

Screen Capture :- 011 –Audit Login

Image

 

Explanation

The “Audit Login” event

  1. Connection request processed
  2. Set statements processed
    • set transaction isolation level serializable

Screen Capture :- 012 — TransactionLog

Image

 

Screen Capture :- 013 — TransactionLog

Image

 

 

Screen Capture :- 014 — “RPC: Completed”

Image

 

 

Explanation

The “RPC:Completed” event

  1. Insert statement completed as a “Remote Procedure Call” (RPC)

 

Screen Capture :- 015 — “Audit Logout”

Image

 

Screen Capture :- 016 — “RPC: Completed”

Image

Explanation

The “RPC:Completed” event

  1. The SQL to reset the connection is completed
    • The payload is “exec sp_reset_connection

 

Screen Capture :- 017 — “Audit Login”

Image

 

Explanation

The “Audit Login” event

  1. Connection request processed
  2. Set statements processed
    • set transaction isolation level serializable

 

 

Screen Capture :- 018 — “TM: Commit Tran starting”

Image

 

Explanation

The “TM: Commit Tran starting” event

  1. The Transaction Manager started the commit process
    • The payload is “COMMIT TRANSACTION

Screen Capture :- 021 — “TM: Commit Tran completed”

Image

The “TM: Commit Tran completed” event

  1. The Transaction Manager completed the commit process
    • The payload is “COMMIT TRANSACTION
    • Unfortunately, the “Transaction ID” is not registered

Conclusion

Here is what we are able to track:

  1. SQLTransaction
  2. Batch — 01
    • Audit Login
      • set transaction isolation level committed
    • TM: (Transaction Management)
      • TM: Begin Tran starting
        • BEGIN TRANSACTION
      • SQLTransaction
      • TM: Begin Tran completed
        • BEGIN TRANSACTION
    • RPC:Completed
  3. Batch — 02
    • RPC:Completed
      • Query for Max Sequence Number
    • Audit Logout
    • RPC:Completed
      • exec sp_reset_connection
  4. Batch — 03
    • Audit Login
      • set transaction isolation level committed
    • RPC:Completed
      • Insert SQL Statement
    • Audit Logout
    • RPC:Completed
      • exec sp_reset_connection
  5. Batch — 04
    • Audit Login
      • set transaction isolation level committed
    • TM: (Transaction Management)
      • TM: Commit Tran starting
        • COMMIT TRANSACTION
      • SQLTransaction
      • TM: Commit Tran completed
        • COMMIT TRANSACTION

Summary

Based on our quick study, we can see that SQL Server Profiler is a very capable tool for monitoring Transaction Isolation Levels.

To do so, please include the following events in the list of Events you are monitoring:

  1. Audit Login
    • Text Data
      • Syntax
        • set transaction isolation level [isolation level]
      • Sample
        • set transaction isolation level read committed

 

Sql Server – Integration Services – SSIS Catalog ( SSISDB ) – Metadata – List Parameters

Introduction

Microsoft continues to build out Sql Server Integration Services (SSIS).

There is support for various package repositories; inclusive are Flat files, MSDB, and SSIS DB.

SSIS Catalog / SSISDB

If you go with SSISDB, it is easy to review the package configuration data.

 

SQL


use [SSISDB]
go

SELECT 
		  [folder] 
			= folders.folder_id

		, [folderName]
			 = folders.[name]

		, [projectName] 
			= projects.[name]

		, [packageName]
			= [packages].[name]

		, [objectType]
			 = case

				when ([paras].[object_type] = 20) then 'Project'
				when ([paras].[object_type] = 30) then 'Package'
				else cast
						(
							[paras].[object_type] 
								as varchar(30)
						)

			   end	

		, [parameterName]
			= [paras].parameter_name

		, [parameterDataType]
			= [paras].data_type

		, [designeDefaultValue]
			= [paras].[design_default_value]

		, [defaultValue]
			= [paras].[default_value]

		, [valueSet]
			= case
				when ([paras].[value_set] =1) then 'Yes'
				else 'No'
		      end

		, [projectDeployTime]
			= convert(varchar(30), [projects].[last_deployed_time], 100)

FROM   [catalog].[folders] folders

INNER JOIN [catalog].[projects] projects 

	ON projects.[folder_id]=folders.[folder_id]

INNER JOIN [catalog].[packages] packages 
	ON packages.[project_id]=projects.[project_id]

INNER JOIN [catalog].[object_parameters] paras 
	ON  ( paras.[object_name]=packages.[name] )
	AND ( paras.[project_id]=packages.[project_id])

 

 

Output

Acknowledgment

Nothing here original.

Trained SQL Server Profiler and catch the SQL it is using.

SQL Server – “Lock Timeouts” – Trigger Timeouts – SSMS – Table Designer

Background

In our initial post we spoke about experiencing an Outage.

Our Clients in the Development side of the house explained they have been experiencing “Lock Timeouts“.

We wanted to see what tools we can use to detect similar occurrences on the DB.  And, we cited SQL Server Profiler as one of those tools.

In this post, we will attempt to simulate time outs due to expired Lock requests and see how well SQL Server Profiler performs.

 

Lab

Outline

  1. Start SQL Server Profiler and set to capture event
  2. Create a bare minimum table
  3. Add data
    • Start Transaction
    • Add a couple of records
    • Temporarily leave Transaction Uncommitted
  4. In another session, return to Table designer & initiate changes
    • Add one or two new columns, attempting to make design changes

Steps

SQL Server Profiler

Here are the events that we said we will capture:

Image

Image – Events Selection

Image – Edit Filter

 

Tabulation

Tabulation – Events Selection
Event Category Event
 Locks  Lock:Cancel
 Stored Procedures  RPC:Completed
 TSQL  SQL:Batch Completed

 

 

Tabulation – Filter
Column Value
 Duration  30000

 

 

Create a Bare Minimum Table

Image

Explanation

In the screen above, we have created a table and added a couple of columns ( personID and personName).

 

Attempt to add data

Script


set nocount on
go
set XACT_ABORT on
go

use [DBLab]
go

declare @transactionComplete bit

set @transactionComplete = 0

begin tran

	insert into [dbo].[person]
	default values;

 

Table Designer

Table Designer – Adding new column – dateAdded

Image

 

Table Designer – Execution Timeout Expired

Image

Textual

'person' table
- Unable to modify table.
Execution Timeout Expired. The timeout period elapsed prior to completion of the operation or the server is not responding.

 

SQL Server Profiler

Image

Lock:Cancel

Tabulated
Event Category Event Columns Values
 Lock  
 Lock:Cancel
 TextData
 Application  Microsoft SQL Server Management Studio
 NTUserName  dadeniji
 Duration  29999
 StartTime  2017-03-25 16:23:18.190
 EndTime  2017-03-25 16:23:18.190
 Mode  2-SCH-M
 ObjectID 110623437
 ObjectID2  110623437
 OwnerID  1-TRANSACTION
 DatabaseID  7
 DatabaseName  DBLAB
 Hostname  DADENIJI
 IntegerData2  0-LOCK

 

 

Explanation
  • You want to pay attention to ObjectID and Database ID
    • Those two will lead you to Database, Schema, and Object name
  • Mode
    • Will lead you to desired Lock
      • In our case, 2-SCH-M or Schema Modification Lock
  • And, of course Application, Host, and Username, and TextData
    • Determine causation and forensics

 

SQL: Batch Completed

Tabulated
Event Category Event Columns Values
 T-SQL  
SQL: Batch Completed
 TextData  ALTER TABLE dbo.person ADD dateAdded null
 Application  Microsoft SQL Server Management Studio
 NTUserName  dadeniji
 Duration  29999
 StartTime  2017-03-25 16:22:48.190
 EndTime  2017-03-25 16:23:18.190

 

 

Explanation
  • You want to pay attention to ObjectID and Database ID
    • Those two will lead you to Database, Schema, and Object name
  • Mode
    • Will lead you to desired Lock
      • In our case, 2-SCH-M or Schema Modification Lock
  • And, of course Application, Host, and Username, and TextData
    • Determine causation and forensics

 

 

Dedicated

Dedicated to MSFT’s SQL Server Team.