SQL in Stockholm

The end of the line

2011-02-04T10:26:15Z

Today is my last day at Microsoft. I’m off to do something completely different, joining a small Scandinavian tech company called Basefarm.

You can continue to find me online here:

http://se.linkedin.com/in/globalgoat

www.globalgoat.com

Enjoy your SQL Servers ! It’s been a pleasure.

Graham

SQL Server blocking caused by database mirroring wait type DBMIRROR_DBM_EVENT

2011-01-10T10:50:00Z

I was looking at a problem this morning about long blocking chains caused by the wait type DBMIRROR_DBM_EVENT, and it makes an interesting case study about database mirroring, blocking, undocumented wait types and general troubleshooting techniques for database mirroring. The information following relates ONLY to SQL 2005, SQL 2008 and SQL 2008 R2. However since the undocumented wait type is not supported, it is not guaranteed to be relevant to future versions higher than SQL 2008 R2 and considering the enhancements coming in this area of functionality, it may well be completely different.

First off some thoughts about looking at root cause analysis of database mirroring problems. We see quite a few of these and often people do not have the appropriate data with which is make a full analysis. Typical examples being unexpected failovers, slow performance and sometimes blocking. Obviously the more data you have the easier, but some of key parts for looking at DBM problems historically are this:

The perfmon counters in the SQLServer:Database Mirroring and SQLServer:Service Broker objects.

Default profiler trace files (people often forget these but they have very useful DBM state change audit information in them)

SQL Server Error Logs

windows event logs

backup of msdb database (this contains useful meta data such as the size of every log backup and the DBM monitor meta data if you've enabled it)

memory dumps (if any were produced)

Obviously if you've also proactively collected MPSReports or SQLDIAG as well, then this will be no bad thing. Back to my specific scenario.....

In this example the symptom was that a huge blocking chain built on a high volume OLTP database where all the head blockers were waiting on DBMIRROR_DBM_EVENT. Here is the sequence of events I went through:

1. Review the blocking chain itself - ho help here as all we can see is that we're waiting on DBMIRROR_DBM_EVENT

2. Review the source for the undocumented wait type. Obviously you can't do this outside of MS, but I can say that at the time of writing this wait type represents the wait used when the principal is waiting for the mirror to harden an LSN, meaning that the transaction it's part of cannot commit. This immediately points quite specifically to the problem that the principal cannot commit transactions as it's waiting on the mirror. Now we need to investigate why the mirror is not committing transactions or why the principal doesn't know whether it is.

3. Review the msdb system tables

(a) Look at the [backupset] table to see if the size of the logs produced at the time of the problem are significantly higher then normal. If they were exceptionally large it may be that the mirror was flooded with transactions and could simply not keep up with the volume. This is why books online will tell you sometimes to disable mirroring if you need to do an exceptionally large logged operation such as an index rebuild. (reference for why this is at http://technet.microsoft.com/en-us/library/cc917681.aspx). Here i used the following TSQL

SELECT backup_set_id,backup_start_date,database_name,has_bulk_logged_data,backup_size / 1000
FROM [backupset]
where backup_start_date between '2011-01-05 14:00:00' and '2011-01-05 19:30:00'
go

select round((AVG(backup_size)/1000),0)
FROM [backupset]
where database_name = 'mydatabase'

(b) secondly I looked at the data in the tables [dbm_monitor_data]. The key here is to locate the timeframe in which we had a problem and then see if we were significant experiencing changes in any of the following:

log_flush_rate
send_queue_size
send_rate
redo_queue_size
redo_rate

These are all indicators similar to part (a) in that they might show a component or piece of architecture that wasn't responding. For example if the send_queue suddenly starts to grow but the re_do queue doesn't grow, then it would imply that the the principal cannot send the log records to the mirror so you'd want to look at connectivity maybe, or the service broker queues dealing with the actual transmissions.

In this particular scenario we noted that all the counters appeared to have strange values, in that there were log backups going on of normal sizes, but there were no status changes, 0 send queue, 0 redo queue, a flat send rate and a flat redo rate. This is very strange as it implies that the DBM Monitor could not record any values from anywhere over the problem period.

4. Review the SQL Server error logs. In this case there were no errors or information messages whatsoever, but in other scenarios such as this, it’s very common for errors in the 1400 range to be reported, examples of which you can find in other places in my other mirroring blogs, such as this Error 1413 example

5. Review the default trace files – in this scenario I was not provided the default traces, however they are fantastic sources of DBM problem information, as they record state change events on all the partners.This is documented here:

Database Mirroring State Change Event Class

This often gives you a great picture of scenarios such as when network connectivity failed between one or all of the partners and then what the state of the partnership became afterwards.

CONCLUSIONS:

In this particular scenario I’m currently missing 2 key points of data, but that apart I can still make a reasonable hypothesis on the above information. We certainly can say that the blocking was caused by the fact that DBM was enabled to the due the blockers all waiting on the DBMIRROR_DBM_EVENT wait type. Since we know we didn’t flood the mirror with a large logged operation and that this deployment normally runs happily in this mode, we can exclude unusual large operations. This means that we have 2 potential candidates at this stage:

1. Hardware problems on the connectivity between some or all of the partners.

2. CPU exhaustion on the mirror server – simply unable to keep up with redos – the CPU exhaustion could itself be from a process outside of SQL Server or outside of the this mirror partnership.

3. A problem with the mirroring code itself (we’d really need some memory dumps to confirm this though).

Based upon experience I’d suspect 1 or 2, but I always keep an open mind about 3 as well, we’re trying to collect some more data now to look at this problem in more detail.

As a final note though I noted some similar scenarios on the forums, and one particular one of note where the poster said that everything worked fine until they enabled mirroring, at which point the system ground to a halt with this wait type. This is far more likely to be a non-optimal configuration where some section of the architecture can simply not keep up with the volume of requests required by the partnership, and is a perfect example of why one must benchmark mirror deployments very carefully. In that scenario you should review this KB first : http://support.microsoft.com/kb/2001270

Graham

Compatibility problems between DMO and SMO connectivity on newer versions of SQL Server

2011-01-05T15:22:00Z

We've recently been looking at a problem which triggered this error:

[Microsoft][ODBC SQL Server Driver][SQL Server]To connect to this server you must use SQL Server Management Studio or SQL Server Management Objects (SMO)

In our case it was actually being thrown by the SQL Server Web Data Administrator which is available on codeplex, but it could just as well be any application that you've written yourselves. In this case the application in question was running on an old Windows 2003 server and had been working fine for a long time, when connecting to old SQL 2000 instances. However when they started trying to connect to later versions of SQL they were getting the above error within the following stack:

at SqlAdmin.ISqlServer.Connect(Object ServerName, Object Login, Object Password)
at SqlAdmin.SqlServer.Connect()
at SqlWebAdmin.databases.Page_Load(Object sender, EventArgs e)
at System.Web.UI.Control.OnLoad(EventArgs e)
at System.Web.UI.Control.LoadRecursive()
at System.Web.UI.Page.ProcessRequestMain()

Being as you can check out the source of this application I did check it out, but excluded this as a problem fairly early on. We came back to focus on the SQLDMO.dll itself and via some rigorous structured testing in the lab we managed to reproduce the exact error and provide an appropriate solution. (If you wonder what I mean by rigorous structured troubleshooting, I mean that I build a windows 2003 virtual machine in a lab and then applied updates to it sequentially checkpointing everytime something changed, and testing various hypotheses that I had on each checkpoint. When you're working with DLL versioning problems I find this to be a very effective - and in my opinion necessary methodology).

Anyway the customer web server in question was runing the following version of SQLDMO.DLL on the web server

Module[945] [C:\PROGRAM FILES\WINDOWS\SYSTEM32\SQLDMO.DLL]
Company Name:      Microsoft Corporation
File Description: Distributed Management Objects OLE DLL for SQL Enterprise Manager
Product Version:   (8.0:760.0)
File Version:      (2000.80:760.0)
File Size (bytes): 4215360
File Date:         ti joulu 17 19:25:22 2002
    Module TimeDateStamp = 0x3dffbfbc - Wed Dec 18 02:22:20 2002
    Module Checksum      = 0x00411b8a
    Module SizeOfImage   = 0x00405000
Module Pointer to PDB = [dll\sqldmo.pdb]
    Module PDB Signature = 0x3dff938b
    Module PDB Age = 0x9e

(I was running MPSReports during my tests to extract and save exact configurations). This is a build from SQL Server 2000 SP3a, a fairly recognisable version number for those of us who have been around SQL for a few years!

To cut a long story short all SQL 2000 versions of this DLL are incompatible with higher major versions of SQL Server, and you need to patch this DLL. There are a number of articles about installing SQLDMO on the web, but I didn;t find any of them to be particularly 100% reliable for all circumstances, which is why I tested it so thoroughly. I wanted to be sure that I could patch this DLL and only this DLL without changing anything else on a production machine. (For example it was hypothesized that installing SQL2005 or higher would resolve the problem - this in fact turned out to be true, but we didn;t want to do this. I also didn't want to be manually registering DLLs.)

We instead used the backward compatibility MSI from SQL 2005, which can be downloaded and run indepently here:

Feature Pack for Microsoft SQL Server 2005 - November 2005

When running this we removed all the features apart from SQLDMO, and this ensured that we correctly upgraded SQLDMO.DLL (and its related objects such as SQLDMO.DLL) in the SQL 2000 directory here

C:\Program Files\Microsoft SQL Server\80\Tools\Binn

This upgrades SQLDMO.DLL to a version of this format

8.05.2312

The 05 being the key identifier here. Everything will then work fine.

The main point being here that one can install and run a version of DMO which will be compatible with all major versions of SQL higher than 2000, and you can do it in a controlled and easy manner, without resorting to the manual registrations listed in older KBs like these

http://support.microsoft.com/kb/326613
http://support.microsoft.com/kb/248241
http://msdn.microsoft.com/en-us/library/aa274817(v=sql.80).aspx

Hope this helps.

Graham

Extended Event to track and trace syntax errors

2010-12-10T13:17:00Z

This might sounds like a strange requirement, but it can be converted to do a number of different things. The scenario is that for reason I won't discuss here, I want to track any user / application which issues an SQL batch which contains invalid syntax. The value here is that this would be extremely difficult to do on this system with tools like profiler due to the large volumes going through the server. This XEVENT will happily sit and monitor all batches for the error codes 102, 447 and 448 which are various derivatives of invalid syntax or invalid language usage. The output is written to a binary file which can then be queried using standard TSQL / XQuery. Alternatively if you don't like the scripting part of this you could look to use the Extended Events SSMS Add in from code plex.

http://extendedeventmanager.codeplex.com/

and here is the piece of code

-- XEvent Session looking for errors 447,448 and 102
-- log examples to files so can be correlated back to netmon traces

if exists(select * from sys.server_event_sessions where name='SharePoint_Errors')
DROP EVENT SESSION SharePoint_Errors ON SERVER
go

CREATE EVENT SESSION SharePoint_Errors ON SERVER
ADD EVENT sqlserver.error_reported
(
ACTION
(
sqlserver.session_id,
sqlserver.tsql_stack,
sqlserver.sql_text,
sqlserver.client_hostname,
sqlserver.client_pid
)
WHERE error = 102
OR error = 447
OR error = 448
)
ADD TARGET package0.asynchronous_file_target(
SET filename='c:\temp\SharePoint_Errors.xet', metadatafile='c:\temp\SharePoint_Errors.xem')
WITH (MAX_MEMORY = 4096KB,
EVENT_RETENTION_MODE = ALLOW_MULTIPLE_EVENT_LOSS,
MAX_DISPATCH_LATENCY = 1 SECONDS,
MAX_EVENT_SIZE = 0KB,
MEMORY_PARTITION_MODE = NONE,
TRACK_CAUSALITY = OFF,
STARTUP_STATE = OFF)

ALTER EVENT SESSION SharePoint_Errors ON SERVER
state=start
go

--stop the session if necessary
--ALTER EVENT SESSION SharePoint_Errors ON SERVER
--state=stop

-- Cleanup the session
--drop EVENT SESSION SharePoint_Errors ON SERVER

********
and here is the sample script to query the output files
********

--get values from XET binary files

--straight select, view the XML manually
select CAST(event_data as XML) , *
from sys.fn_xe_file_target_read_file
(
'C:\temp\SharePoint_Errors_0_129291097895820000.xet',
'C:\temp\SharePoint_Errors_0_129291097896520000.xem',
null,
null
)

--details

SELECT --*
xdata.value('(/event/data[3]/@name)[1]', 'varchar(100)') AS [name],
xdata.value('(/event/action[@name="sql_text"]/value)[1]', 'varchar(max)') AS [name]

--insert other XML nodes from the output as required here
--you can then add condition checks on their values as well
FROM
(
  select CAST(event_data as XML)
  from sys.fn_xe_file_target_read_file
  (
  'C:\temp\SharePoint_Errors_0_129291097895820000.xet',
  'C:\temp\SharePoint_Errors_0_129291097896520000.xem',
  null,
  null
  )
) as xmlr(xdata)

*********
remember to change the file unique identifiers to those of your output files
*********

SQL Server performance problems due to high privileged CPU time when running Windows Server 2008 R2

2010-11-01T09:56:19Z

It's very rare that I tell people to blindy apply service packs or hotfixes (especially windows ones) without first analyzing where their performance problem lies, but if you are running SQL Server 2008 on Windows Server 2008 R2 (specifically this OS only) then you should absolutely ensure that you've installed the following fix:

976700 An application stops responding, experiences low performance, or experiences high privileged CPU usage if many large I/O operations are performed in Windows 7 or Windows Server 2008 R2
http://support.microsoft.com/default.aspx?scid=kb;EN-US;976700

In this scenario, the key symptom which you normally ought to notice is that you are getting high kernel times, which can you see in the followiing perfmon counter:

Process(sqlservr)\% Privileged Time

We've seen a trend of this issue in recent months, so it's something to look to apply in your next maintenance window if you can.

The Forefront TMG/UAG team in Stockholm is hiring

2010-09-27T09:49:25Z

Following the success of my previous post about recruitment, we're advertising another position from a different support group also located here in Stockholm. You can read the details here

http://blogs.technet.com/b/isablog/archive/2010/09/15/forefront-tmg-uag-help-wanted-at-microsoft-in-stockholm.aspx

....and you might notice the common language to my previous post :-)

Please don't contact me about this one though, ensure you email the contact listed in the new article.

The SQL Server Support Team in Stockholm is hiring

2010-06-22T13:25:00Z

Update 23th August

This position has now been filled - thanks for everything who submitted their CVs.

The Microsoft SQL Server support team in Stockholm is looking to hire a contractor to help out over the next year or so, to cover some staff absences. If you’d be interested to come and work with us and learn more about SQL Server internals than you probably would anywhere else in the world (apart form Redmond maybe), then this might be the contract for you.

Although you’ll get some training and access to innumerable amounts of internal only documentation, we’re looking for someone very experienced who can hit the ground running and could be expected to work the majority of our easier support cases without too much assistance. Therefore you’d need a minimum of 5 years experience (preferably more) working with SQL Server day to day in an administrative capacity (probably as a production DBA). Specialities of particular interest to us would be:

Setup / configuration / migration

Administration of HA solutions (clusters, DBM, replication etc)

Performance

Crashes, Hangs and Unexpected behaviour

Beyond that if you have experience of other Microsoft server products (Windows, SharePoint, BizTalk, SCCM, Navision), windbg, c# or c++, it won’t do you any harm.

If you think you’d be interested, then please send a brief summary (it’ll come out in plain text so keep it simple) of your experience via the “email blog author” section (to reduce my spam levels!). If we’re interested then we’ll get back to you with proper email details so you can send in a full CV and talk to our agency. You need to be resident in Sweden (Swedish language or other Nordic languages would be of use, but are not essential) and available to work full time in Kista / Akalla from some point around August.

Script to run in SQL Server Agent to monitor DMVs, log results and take action depending upon results

2010-06-11T20:06:00Z

Here’s a script to play with which is useful for simple management tasks. I wrote it to help someone with a TokenAndPermUserStore cache issue (http://support.microsoft.com/kb/927396/) which are relatively uncommon nowadays. I actually sent it to someone today which is why it came to mind, but it occurred to me that the template of the script itself is quite useful for any such TSQL SQL Agent based task, i.e. it does these tasks:

Runs a DMV query

Checks results of query and if appropriate takes an action

Writes what it did to the SQL error log as an info message

I use the theory for many different tasks. Feel free to use and alter it as you will, subject to the usual legal caveats of course!

Access Denied error when running SQL Server Transfer Objects Task with a Proxy Account

2010-03-12T13:56:00Z

Should you try to configure an SSIS package which uses the Transfer Objects Task, and then execute this package through SQL Agent, when you choose to run the task as a proxy credential, as opposed to the normal SQL Agent user, you may encounter a failure. The typical full text of the error message from the SQL Agent history is shown here.

Executed as user: GRAHAMK20\SSIS_Proxy. Microsoft (R) SQL Server Execute Package Utility Version 10.0.2531.0 for 64-bit Copyright (C) Microsoft Corp 1984-2005. All rights reserved. Started: 4:55:19 PM Error: 2010-02-04 16:55:19.65 Code: 0xC0016016 Source: Description: Failed to decrypt protected XML node "PassWord" with error 0x80070002 "The system cannot find the file specified.". You may not be authorized to access this information. This error occurs when there is a cryptographic error. Verify that the correct key is available. End Error Error: 2010-02-04 16:55:19.67 Code: 0xC0016016 Source: Description: Failed to decrypt protected XML node "PassWord" with error 0x80070002 "The system cannot find the file specified.". You may not be authorized to access this information. This error occurs when there is a cryptographic error. Verify that the correct key is available. End Error Error: 2010-02-04 16:55:20.00 Code: 0xC002F325 Source: Transfer SQL Server Objects Task Transfer SQL Server Objects Task Description: Execution failed with the following error: "Access to the path 'C:\Users\Default\AppData\Local\Microsoft\SQL Server\Smo' is denied.". End Error DTExec: The package execution returned DTSER_FAILURE (1). Started: 4:55:19 PM Finished: 4:55:20 PM Elapsed: 0.562 seconds. The package execution failed. The step failed.

Depending on how you view this message, you could decide it as being a number of different causes, but the actual important point to note is the red highlighted section. This is the lowest level error and the actual cause of the failure, the other errors are thrown further up the stack. You can confirm this by running Process Monitor on the server where the package is executing. You’ll see failures here

- C:\Users\Default\AppData\Local\Microsoft\SQL Server (create file)
- C:\Users\Default\AppData\Local\Microsoft\SQL Server\Smo (create file)

However if you run the same package, but in the context of the SQL Agent account, you will notice that the same create file runs on a different directory:

- C:\Users\<sqlagentuserid>\AppData\Local\Microsoft\SQL Server\Smo

The package requires a temporary location to process some files when it prepared to run and there is a bug in the way the proxy account credential decides where it should place these files. This has been passed to the product group and should be fixed in SQL 11.

The reason that it is not being fixed immediately is that there is a relatively simple workaround which is to manually create the directory structure in the default user profile directory, and grant write modify permissions to the user or group which represents the proxy credential account. So in my specific example I logged on with an adminstrator account to the server, created the following directory

C:\Users\Default\AppData\Local\Microsoft\SQL Server\Smo

and then granted the users group (of which my proxy credential account is a member of) the following permissions:

Modify, Write, Read & Execute

The package will then execute successfully under the proxy credential. This problem occurs on both SQL 2005 and SQL 2008.

Troubleshooting SQL Server Management Studio with SQL Profiler and Debugging Tools – Part 3

2010-02-03T15:47:00Z

(An alternate title for this post could be “How to debug SSMS managed code”)

In the first 2 posts of this topic we used SQL Profiler and some common sense to diagnose a problem within SSMS. Then we used DebugDiag to collect a memory dump when a specific exception was thrown. Now in the 3rd part we’ll analyze that dump used windbg and public symbols from the Microsoft symbols server.

This post assumes a certain familiarity with managed debugging using windbg. If you need some background on this topic, a good place to start is by reading the blog of Tess.

To understand the context of this debugging, you should really read the first 2 posts in the series, but as a brief reminder, we collect a dump of the SSMS process (ssms.exe in SQL 2008 and sqlwb.exe in SQL 2005) when a specific condition occurs – in this case an exception thrown when trying to view SQL Agent job history. The dump below is from a sqlwb.exe 2005 client, but the theory is identical. The main point which this post demonstrates is that unlike when debugging the database engine process of SQL Server (sqlservr.exe), using purely public symbols , interesting information can be gleaned from the dump because most of the interesting structures are in managed code which can be interpretted with the windbg extension sos.dll.

My base setup for this debugging:

A blank hyper-V machine running Windows 7 Ultimate, connected to the internet

A default installation of debugging tools for windows downloaded from here:

http://www.microsoft.com/whdc/devtools/debugging/installx86.Mspx

A symbol path set exactly as per the example “getting started” page here:

http://www.microsoft.com/whdc/devtools/debugging/debugstart.mspx

i.e. the symbol path used is:

SRV*c:\websymbols*http://msdl.microsoft.com/download/symbols

So here’s the debugging output with notes:

* First off we load the public sos.dll so we can do managed debugging

0:018> .load c:\windows\microsoft.net\framework\v2.0.50727\sos.dll

* We’ve opened directly to the thread where the exception occurred

* let’s look at the CLRSTACK

0:018> !clrstack

OS Thread Id: 0x6ac (18)

ESP EIP

0822ef3c 77e4bef7 [HelperMethodFrame: 0822ef3c]

0822efe0 799d766a System.DateTime.TimeToTicks(Int32, Int32, Int32)

0822eff0 2ec8e92c Microsoft.SqlServer.Management.Smo.PostProcessCreateDateTime.GetDateTime(System.Object, System.Object)

0822f010 2ec91584 Microsoft.SqlServer.Management.Smo.PostProcessJobActivity.GetColumnData(System.String, System.Object, Microsoft.SqlServer.Management.Smo.DataProvider)

0822f064 2ec86ced Microsoft.SqlServer.Management.Smo.DataProvider.ManipulateRowDataPostProcess()

0822f07c 2ec872b9 Microsoft.SqlServer.Management.Smo.DataProvider.GetTable()

0822f08c 2ec84436 Microsoft.SqlServer.Management.Smo.ExecuteSql.ExecuteWithResults(System.Collections.Specialized.StringCollection, System.Object, Microsoft.SqlServer.Management.Smo.StatementBuilder)

0822f098 2ec804db Microsoft.SqlServer.Management.Smo.SqlObjectBase.FillData(Microsoft.SqlServer.Management.Smo.ResultType, System.Collections.Specialized.StringCollection, System.Object, Microsoft.SqlServer.Management.Smo.StatementBuilder)

0822f0b8 2ec803c4 Microsoft.SqlServer.Management.Smo.SqlObjectBase.FillDataWithUseFailure(Microsoft.SqlServer.Management.Smo.SqlEnumResult, Microsoft.SqlServer.Management.Smo.ResultType)

0822f0f8 2ec80339 Microsoft.SqlServer.Management.Smo.SqlObjectBase.BuildResult(Microsoft.SqlServer.Management.Smo.EnumResult)

0822f138 2ec7fea3 Microsoft.SqlServer.Management.Smo.SqlObjectBase.GetData(Microsoft.SqlServer.Management.Smo.EnumResult)

0822f148 2eb5daf8 Microsoft.SqlServer.Management.Smo.Environment.GetData()

0822f178 2eb5da5c Microsoft.SqlServer.Management.Smo.Environment.GetData(Microsoft.SqlServer.Management.Smo.Request, System.Object)

0822f18c 2eb5caef Microsoft.SqlServer.Management.Smo.Enumerator.GetData(System.Object, Microsoft.SqlServer.Management.Smo.Request)

0822f1b0 2eb5ccd6 Microsoft.SqlServer.Management.Smo.Enumerator.Process(System.Object, Microsoft.SqlServer.Management.Smo.Request)

0822f1e4 30983b38 Microsoft.SqlServer.Management.SqlManagerUI.JobFetcher.FetchJobs(System.String)

0822f200 3098349a Microsoft.SqlServer.Management.SqlManagerUI.JobFetcher.FetchJobs(Microsoft.SqlServer.Management.SqlManagerUI.JobActivityFilter)

0822f214 3098230e Microsoft.SqlServer.Management.SqlManagerUI.JobsPanel.RefreshJobs()

0822f240 3097f028 Microsoft.SqlServer.Management.SqlManagerUI.JobActivityMonitor.Microsoft.SqlServer.Management.UI.ActivityMonitor.IActivityMonitor.RefreshSnapshot()

0822f244 053f08f7 Microsoft.SqlServer.Management.UI.ActivityMonitor.ActivityMonitorUserControl.WorkerEntryPoint(System.Object)

0822f280 792c9e4f System.Threading._ThreadPoolWaitCallback.WaitCallback_Context(System.Object)

0822f288 792f5681 System.Threading.ExecutionContext.runTryCode(System.Object)

0822f6b8 79e71b4c [HelperMethodFrame_PROTECTOBJ: 0822f6b8] System.Runtime.CompilerServices.RuntimeHelpers.ExecuteCodeWithGuaranteedCleanup(TryCode, CleanupCode, System.Object)

0822f720 792f5577 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)

0822f73c 792e01c5 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)

0822f754 792ca3b3 System.Threading._ThreadPoolWaitCallback.PerformWaitCallbackInternal(System.Threading._ThreadPoolWaitCallback)

0822f768 792ca249 System.Threading._ThreadPoolWaitCallback.PerformWaitCallback(System.Object)

0822f8f8 79e71b4c [GCFrame: 0822f8f8]

* this shows us some fairly expected output that we have a stack which indicates we are using SMO to populate some data to do with SQL Agent jobs (Microsoft.SqlServer.Management.SqlManagerUI.JobFetcher.FetchJobs)

* let’s look at the exception to check it’s what we wanted

* it shows the details of the exception which SSMS reported (Hour, Minute, and Second parameters describe an un-representable DateTime)

0:018> !pe

Exception object: 016588b4

Exception type: System.ArgumentOutOfRangeException

Message: Hour, Minute, and Second parameters describe an un-representable DateTime.

InnerException: <none>

StackTrace (generated):

<none>

StackTraceString: <none>

HResult: 80131502

* now we want to look at what these functions were actually doing

* dump all objects on the stack to look back through recent history (most recent is at the top)

* scanning down here to look for anything of interest

* we see that we have a System.DBNull sitting next to a System.String named NextRunDate – this might be of interest

* in addition to that we can see the server connection object which will contain the details of the connection and also the actual TSQL executed

0:018> !dso

OS Thread Id: 0x6ac (18)

ESP/REG Object Name

0822eed0 016588b4 System.ArgumentOutOfRangeException

0822ef1c 016588b4 System.ArgumentOutOfRangeException

0822ef60 016588b4 System.ArgumentOutOfRangeException

0822efbc 0156b85c System.String ArgumentOutOfRange_BadHourMinuteSecond

0822efc4 016588b4 System.ArgumentOutOfRangeException

0822efe0 016588b4 System.ArgumentOutOfRangeException

0822eff8 015cd46c Microsoft.SqlServer.Management.Smo.PostProcessJobActivity

0822effc 0165889c System.Int32

0822f00c 016588a8 System.Int32

0822f010 01658880 System.Data.RBTree`1+RBTreeEnumerator[[System.Data.DataRow, System.Data]]

0822f014 01603e84 System.Data.DataRow

0822f018 015cc064 System.String NextRunDate

0822f01c 015cd46c Microsoft.SqlServer.Management.Smo.PostProcessJobActivity

0822f044 015d34f0 System.Data.DataRow

0822f048 015cd46c Microsoft.SqlServer.Management.Smo.PostProcessJobActivity

0822f04c 015cdf84 Microsoft.SqlServer.Management.Smo.DataProvider

0822f05c 015cdf84 Microsoft.SqlServer.Management.Smo.DataProvider

0822f060 011ee95c System.DBNull

0822f064 015cc064 System.String NextRunDate

0822f068 01597a6c Microsoft.SqlServer.Management.SqlManagerUI.JobFetcher

0822f06c 015cdf84 Microsoft.SqlServer.Management.Smo.DataProvider

0822f094 015ccd18 Microsoft.SqlServer.Management.Smo.StatementBuilder

0822f0b0 01594dbc Microsoft.SqlServer.Management.Common.ServerConnection

0822f0c0 015cd964 System.Collections.Specialized.StringCollection

0822f0c4 015cca78 Microsoft.SqlServer.Management.Smo.SqlEnumResult

0822f0c8 015c8a00 Microsoft.SqlServer.Management.Smo.SqlObject

0822f0e0 01597a6c Microsoft.SqlServer.Management.SqlManagerUI.JobFetcher

0822f124 01597a6c Microsoft.SqlServer.Management.SqlManagerUI.JobFetcher

0822f148 015cc7bc System.Collections.ArrayList+ArrayListEnumeratorSimple

0822f14c 015cca78 Microsoft.SqlServer.Management.Smo.SqlEnumResult

0822f164 01597a6c Microsoft.SqlServer.Management.SqlManagerUI.JobFetcher

0822f168 015c462c Microsoft.SqlServer.Management.Smo.Environment

0822f188 01594dbc Microsoft.SqlServer.Management.Common.ServerConnection

0822f194 01594dbc Microsoft.SqlServer.Management.Common.ServerConnection

0822f19c 01597a6c Microsoft.SqlServer.Management.SqlManagerUI.JobFetcher

0822f1cc 01597a6c Microsoft.SqlServer.Management.SqlManagerUI.JobFetcher

0822f1e0 015c4590 Microsoft.SqlServer.Management.Smo.Request

0822f1e4 0150cb08 System.String /Job

0822f1e8 011d1198 System.String

0822f1ec 0158101c Microsoft.SqlServer.Management.SqlManagerUI.JobActivityFilter

0822f1f0 01597a6c Microsoft.SqlServer.Management.SqlManagerUI.JobFetcher

0822f204 01591e78 Microsoft.SqlServer.Management.SqlManagerUI.JobsPanel

0822f214 01591e78 Microsoft.SqlServer.Management.SqlManagerUI.JobsPanel

0822f21c 01217510 System.Runtime.CompilerServices.RuntimeHelpers+CleanupCode

0822f224 014f9c50 System.Threading.ExecutionContext

0822f250 015a5174 Microsoft.SqlServer.Management.UI.ActivityMonitor.ActivityMonitorUserControl+BackgroundRefreshJobDescription

0822f254 01581054 Microsoft.SqlServer.Management.UI.ActivityMonitor.ActivityMonitorUserControl

0822f344 012174f0 System.Runtime.CompilerServices.RuntimeHelpers+TryCode

0822f410 01217510 System.Runtime.CompilerServices.RuntimeHelpers+CleanupCode

0822f4b8 012174f0 System.Runtime.CompilerServices.RuntimeHelpers+TryCode

0822f638 01217510 System.Runtime.CompilerServices.RuntimeHelpers+CleanupCode

0822f6f4 012174f0 System.Runtime.CompilerServices.RuntimeHelpers+TryCode

0822f6f8 01217510 System.Runtime.CompilerServices.RuntimeHelpers+CleanupCode

0822f6fc 015a561c System.Threading.ExecutionContext+ExecutionContextRunData

0822f724 011f4ecc System.Threading.ContextCallback

0822f72c 014f9c50 System.Threading.ExecutionContext

0822f738 015a51cc System.Threading._ThreadPoolWaitCallback

0822f750 015a51cc System.Threading._ThreadPoolWaitCallback

* dump the server connection object – this is always a useful object to be able to locate and look at, because within it you can see all manner of properties about the connection and the batch executing

0:018> !do 01594dbc

Name: Microsoft.SqlServer.Management.Common.ServerConnection

MethodTable: 2e2bda28

EEClass: 2e283d48

Size: 144(0x90) bytes

(C:\WINDOWS\assembly\GAC_MSIL\Microsoft.SqlServer.ConnectionInfo\9.0.242.0__89845dcd8080cc91\Microsoft.SqlServer.ConnectionInfo.dll)

Fields:

MT Field Offset Type VT Attr Value Name

793044cc 4000036 40 System.Boolean 1 instance 1 m_BlockUpdates

79330a00 4000037 4 System.String 0 instance 01594eac m_ServerInstance

79330a00 4000038 8 System.String 0 instance 011d1198 m_Login

7995d420 4000039 c ...rity.SecureString 0 instance 00000000 m_Password

793044cc 400003a 41 System.Boolean 1 instance 1 m_LoginSecure

79330a00 400003b 10 System.String 0 instance 011d1198 m_ConnectAsUserName

79330a00 400003c 14 System.String 0 instance 011d1198 m_ConnectAsUserPassword

793044cc 400003d 42 System.Boolean 1 instance 0 m_ConnectAsUser

793044cc 400003e 43 System.Boolean 1 instance 1 m_NonPooledConnection

79332c4c 400003f 28 System.Int32 1 instance 0 m_PooledConnectionLifetime

79332c4c 4000040 2c System.Int32 1 instance 0 m_MinPoolSize

79332c4c 4000041 30 System.Int32 1 instance 100 m_MaxPoolSize

79332c4c 4000042 34 System.Int32 1 instance 15 m_ConnectTimeout

2e2bc5b4 4000043 38 System.Int32 1 instance 8 m_NetworkProtocol

79330a00 4000044 18 System.String 0 instance 01594e4c m_ApplicationName

79330a00 4000045 1c System.String 0 instance 011d1198 m_WorkstationId

79330a00 4000046 20 System.String 0 instance 011d1198 m_DatabaseName

79332c4c 4000047 3c System.Int32 1 instance 4096 m_PacketSize

7995d420 4000048 24 ...rity.SecureString 0 instance 00000000 m_ConnectionString

793044cc 4000049 44 System.Boolean 1 instance 0 m_MultipleActiveResultSets

793044cc 400004a 45 System.Boolean 1 instance 0 shouldEncryptConnection

6523d7a0 400004b 48 ...ent.SqlConnection 0 instance 01594f10 m_SqlConnectionObject

793044cc 400004c 46 System.Boolean 1 instance 1 m_InUse

79332c4c 400004d 68 System.Int32 1 instance 0 m_LoginFailedClients

2e2bc50c 400004e 4c ...ssageEventHandler 0 instance 00000000 m_RemoteLoginFailedHandler

656629a8 400004f 50 ...ssageEventHandler 0 instance 00000000 m_SqlInfoMessageHandler

2e2bd89c 4000050 54 ...ommon.CapturedSql 0 instance 01594ee0 m_CapuredSQL

2e2bc8d4 4000051 6c System.Int32 1 instance 1 m_AutoDisconnectMode

793044cc 4000052 47 System.Boolean 1 instance 0 bIsUserConnected

2e2be0b0 4000053 58 ...mon.ServerVersion 0 instance 015c172c m_serverVersion

79332c4c 4000054 70 System.Int32 1 instance 10 lockTimeout

2e2bc50c 4000055 5c ...ssageEventHandler 0 instance 00000000 ServerMessageInternal

2e2bc480 4000056 60 ...ementEventHandler 0 instance 00000000 StatementExecuted

2e2bc50c 4000057 64 ...ssageEventHandler 0 instance 00000000 RemoteLoginFailedInternal

79332c4c 400005b 80 System.Int32 1 instance 0 m_StatementTimeout

79330a00 400005c 74 System.String 0 instance 01428dcc m_BatchSeparator

79332c4c 400005d 84 System.Int32 1 instance 0 m_TransactionDepth

2e2bc6f4 400005e 88 System.Int32 1 instance 1 m_ExecutionMode

6523db4c 400005f 78 ...Client.SqlCommand 0 instance 01594f48 m_SqlCommand

79330a00 4000060 7c System.String 0 instance 015c1a70 m_TrueName

*dump the SqlCommand object

0:018> !do 01594f48

Name: System.Data.SqlClient.SqlCommand

MethodTable: 6523db4c

EEClass: 6515c250

Size: 132(0x84) bytes

(C:\WINDOWS\assembly\GAC_32\System.Data\2.0.0.0__b77a5c561934e089\System.Data.dll)

Fields:

MT Field Offset Type VT Attr Value Name

7933061c 400018a 4 System.Object 0 instance 00000000 __identity

7a5d2a58 40008c3 8 ...ponentModel.ISite 0 instance 00000000 site

7a5ecd2c 40008c4 c ....EventHandlerList 0 instance 00000000 events

7933061c 40008c2 108 System.Object 0 static 01201278 EventDisposed

79332c4c 40016e3 58 System.Int32 1 instance 58 ObjectID

79330a00 40016e4 10 System.String 0 instance 014e3850 _commandText

6523e698 40016e5 5c System.Int32 1 instance 0 _commandType

79332c4c 40016e6 60 System.Int32 1 instance 0 _commandTimeout

6565989c 40016e7 64 System.Int32 1 instance 3 _updatedRowSource

793044cc 40016e8 78 System.Boolean 1 instance 0 _designTimeInvisible

6567ecdc 40016e9 14 ...ent.SqlDependency 0 instance 00000000 _sqlDep

793044cc 40016ea 79 System.Boolean 1 instance 0 _inPrepare

79332c4c 40016eb 68 System.Int32 1 instance -1 _prepareHandle

793044cc 40016ec 7a System.Boolean 1 instance 0 _hiddenPrepare

6523e8b4 40016ed 18 ...rameterCollection 0 instance 00000000 _parameters

6523d7a0 40016ee 1c ...ent.SqlConnection 0 instance 01594f10 _activeConnection

793044cc 40016ef 7b System.Boolean 1 instance 0 _dirty

656616a4 40016f0 6c System.Int32 1 instance 0 _execType

793041d0 40016f1 20 System.Object[] 0 instance 00000000 _rpcArrayOf1

6524233c 40016f2 24 ...t._SqlMetaDataSet 0 instance 015f9100 _cachedMetaData

65241e94 40016f3 28 ...+CachedAsyncState 0 instance 015c19fc _cachedAsyncState

79332c4c 40016f4 70 System.Int32 1 instance -1 _rowsAffected

6567d4b8 40016f5 2c ...tificationRequest 0 instance 00000000 _notification

793044cc 40016f6 7c System.Boolean 1 instance 1 _notificationAutoEnlist

6567da8c 40016f7 30 ...nt.SqlTransaction 0 instance 00000000 _transaction

65659328 40016f8 34 ...letedEventHandler 0 instance 00000000 _statementCompletedEventHandler

65241814 40016f9 38 ...ParserStateObject 0 instance 00000000 _stateObj

793044cc 40016fa 7d System.Boolean 1 instance 0 _pendingCancel

793044cc 40016fb 7e System.Boolean 1 instance 0 _batchRPCMode

00000000 40016fc 3c 0 instance 00000000 _RPCList

793041d0 40016fd 40 System.Object[] 0 instance 00000000 _SqlRPCBatchArray

00000000 40016fe 44 0 instance 00000000 _parameterCollectionList

79332c4c 40016ff 74 System.Int32 1 instance 0 _currentlyExecutingBatch

656732b0 4001700 48 ...miRequestExecutor 0 instance 00000000 _smiRequest

65672df8 4001701 4c ...Server.SmiContext 0 instance 00000000 _smiRequestContext

6567e144 4001702 50 ...+CommandEventSink 0 instance 00000000 _smiEventSink

65672f4c 4001703 54 ...DeferedProcessing 0 instance 00000000 _outParamEventSink

79332c4c 40016e2 878 System.Int32 1 static 59 _objectTypeCount

793041d0 4001704 78c System.Object[] 0 static 01427968 PreKatmaiProcParamsNames

793041d0 4001705 790 System.Object[] 0 static 014279b4 KatmaiProcParamsNames

* dump the command text

0:018> !do 014e3850

Name: System.String

MethodTable: 79330a00

EEClass: 790ed64c

Size: 68(0x44) bytes

(C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll)

String: exec msdb.dbo.sp_help_job

Fields:

MT Field Offset Type VT Attr Value Name

79332c4c 4000096 4 System.Int32 1 instance 26 m_arrayLength

79332c4c 4000097 8 System.Int32 1 instance 25 m_stringLength

793316e0 4000098 c System.Char 1 instance 65 m_firstChar

79330a00 4000099 10 System.String 0 shared static Empty

>> Domain:Value 001831e0:011d1198 <<

79331630 400009a 14 System.Char[] 0 shared static WhitespaceChars

>> Domain:Value 001831e0:011d17d4 <<

* and we have now managed to get the actual TSQL batch executed by SSMS which caused the exception to happen

* this would be enough information to then leave the debugging and go and investigate this from another direction.

* this is effectively what we did in post of the series, by tracing the command through SQL Profiler

So we've seen that we've managed to get the code which is executing, and we've also noted that there is a System.DBNull on the stack next to the NextRunDate object. The point here really though is that because we're dealing with the managed code within SSMS alot more is exposed to us using a memory dump. In this case you could continue the debugging to look at the actual data table which is returned by the stored procedure, and then read through it see which row of the data table contains the Null, which then leads you right back to the source data corruption.

The thing that should be really occurring to you now though is that you can get all others sorts of information out , from this simple example, or from any dump which you might trigger of SSMS, if you ever get unexpected behavior.

For example, imagine the problem you had captured a dump for was more complex involving connections to multiple servers, you can review some of the other structures in the Connection object.

* dump the connection object again to remind us of its contents