Welcome to MSDN Blogs Sign in | Join | Help

Tone Poem

Listen to your heart
Tracking Handle Misuse Using Application Verifier and Windbg

In a recent MSDN forum post Connection Pooling randomly throwing COM exceptions I uncovered an issue where some code inside the process was closing handles owned by our pooling code.  This caused our pooling code to get into a bad state triggering a SemaphoreFullException every single time a caller attempted to open a connection from the pool.

The root cause of this problem was code calling the Win32 API CloseHandle on a handle that it did not own.   Since Windows can aggresively reuse handle values, it’s possible to hit a situation like below:

Thread1: CreateFile –> Get handle #1.

Thread1: CloseHandle(#1)

Thread2: CreateFile –> Get handle #1, store in member variable.

Thread1: CloseHandle (#1) <- Mistake in code.

Thread1: CreateEvent –> Get handle #1.

Now my code on Thread2 thinks it has a file handle, but it has an event handle!   Thread2 did not make any coding mistake, the Thread1 code corrupted Thread2’s handle value.

This is an inherent issue when using handles, they are inherently dangerous you have to be very careful to only call CloseHandle 1 time.  Now the operating system could mitigate this by handling out random values for handles, but in general the operating system does not always do this for performance reasons.  The tradeoff is fast performance for all applications that behave correctly.

Now if you have a process where you suspect handles are getting misused (leaked or double closed), you can use Application Verifier to help track this down very quickly, this is what I want to talk about.

First download both Microsoft Application Verifier and Debugging Tools for Windows, both are free downloads from Microsoft.  I would provide links but these always change, get the latest versions of both.  Get the version that matches your operating system bitness as well for best results.

Install Microsoft Application Verifier and Debugging Tools for Windows on the machine where you have the problem.  Both are very clean installers and remove easily so don’t worry about installing on production machine, they are easy to remove and don’t require any reboot during removal.   If you are really worried you can install them on a separate machine and xcopy the files to the production machine, this works as well.

Next, figure out what process you want to debug.  If you are running IIS application with .NET, most likely this is the w3wp.exe process.  You don’t need the process ID yet.

First run Application Verifier to setup handle tracking, it looks like below:

image

Not too fancy.  :)  You want to create the entry for the process name next, select File | Add Application.   Let’s do the demonstration using notepad.exe for now.   Just type in notepad.exe and click Open.  You do not have to find and select the correct binary, just typing in the process name is sufficient, it does not need the full path:

image

Now that you’ve added the process, go to the right and select ONLY handles under the Basics options, like below:

image

The reason I only select handles here is to reduce the performance implications of all the other tracking inside the process.  I just want to track handles, this is all.

Once you’ve selected handles only, click Save, then close Application Verifier.  You will see this message:

image

This is fine, we will do this work later on (attach debugger).  Click OK and exit App Verifier.

Now, VERY IMPORTANT!  Re-open App Verifier.  Verify you see your process name correctly and you see only Handles is checked.  Do this step as a sanity check to ensure you selected the right thing AND it was saved correctly to registry.

Exit App Verifier again.

If your process is currently running, stop and restart the process.   If for example you are using IIS, you want to run iisreset at this point to restart IIS.  This step is required as the process reads the Application Verifier flags ONLY during startup.

In our case we are debugging notepad, so lets startup an instance of notepad.exe at this point (Start|Run –> Notepad.exe)

Now open Windbg.exe (from Debugging Tools For Windows install).  Select File | Attach To Process…

VERY IMPORTANT!  First thing to do is check the Non-invasive check box on the Attach to Process dialog, as below:

image

You should ALWAYS check this when doing handle tracking work because this allows you to attach to the process in a special mode called non-invasive mode.  This allows the debugger to be later detached and the process will continue normally.  If you don’t check this checkbox, the debugger will fully attach to the process and you cannot shut down the debugger without terminating the process.

Next, locate your process, you will see here my process is notepad.exe, select this process:

image

Click OK to attach the debugger non-invasively.   Once you are attached, go to the command window (select View|Command) and run the following commands:

0:000> !htrace -enable
Handle tracing enabled.
Handle tracing information snapshot successfully taken.

This command is required to enable the tracing of handles.  Once this is set, you can exit the debugger by running the q (quit) command:

0:000:> q

At this point handle tracking is enabled for the process.  For this experiment, now go to notepad and open a single text file but do not exit notepad.exe yet.

Now we want to see what handle tracking can do for us.  Startup Windbg.exe again and attach to notepad again in non-invasive mode.  Run the following commands:

0:000> .dump /ma c:\temp\notepad.dmp
Creating c:\temp\notepad.exe - mini user dump
Dump successfully written

Note the command is .dump /ma <filename> where <filename> can be anything you want here.  I called my dump file c:\temp\notepad.dmp.

This creates a dump of the process.  Now again run q (quit) command to exit debugger.

Re-open Windbg again, we are next going to examine the dump file.

In Windbg select File | Open Crash Dump… and select c:\temp\notepad.dmp and click Open.

In the command window, run the following 2 commands to load symbols:

0:000> .sympath srv*http://msdl.microsoft.com/download/symbols
Symbol search path is: srv*http://msdl.microsoft.com/download/symbols
Expanded Symbol search path is: srv*http://msdl.microsoft.com/download/symbols
0:000> .reload /f
..........................................*** ERROR: Symbol file could not be found.  Defaulted to export symbols for AvCheck.dll -
.....
Loading unloaded module list

Note you may see errors here, this is fine for now.

Now we want to see a trace of our handle activity, run the !htrace command with no arguments:

0:000> !htrace

Next you will see tons of debugger spew like below:

--------------------------------------
Handle = 0x00000000000002f0 - OPEN
Thread ID = 0x0000000000001390, Process ID = 0x0000000000000b6c

0x0000000077835e3a: ntdll!ZwDuplicateObject+0x000000000000000a
0x00000000776148a8: kernel32!DuplicateHandle+0x0000000000000055
0x000007fefe6cb435: rpcrt4!THREAD::THREAD+0x00000000000000b5
0x000007fefe6cb35c: rpcrt4!ThreadSelfHelper+0x0000000000000028
0x000007fefe77444c: rpcrt4!NdrpClientCall2+0x0000000000000698
0x000007fefe774ddd: rpcrt4!NdrClientCall2+0x000000000000001d
0x000007fefe4c0e9a: ole32!BulkUpdateOIDs+0x000000000000008a
0x000007fefe4c0d89: ole32!CRpcResolver::BulkUpdateOIDs+0x0000000000000109
0x000007fefe4c0c36: ole32!CROIDTable::ClientBulkUpdateOIDWithPingServer+0x0000000000000224
0x000007fefe4c94c3: ole32!CROIDTable::WorkerThreadLoop+0x0000000000000057
0x000007fefe4c9406: ole32!CRpcThread::WorkerLoop+0x000000000000001e
0x000007fefe4c9682: ole32!CRpcThreadCache::RpcWorkerThreadEntry+0x000000000000001a
0x000000007761466d: kernel32!BaseThreadInitThunk+0x000000000000000d
0x0000000077818791: ntdll!RtlUserThreadStart+0x000000000000001d
--------------------------------------
Handle = 0x000000000000031c – OPEN

This shows you all the handle activity in the process.

You can locate a double close by searching for the CLOSE lines:

Handle = 0x000000000000033c - CLOSE

This will also have the stack trace of the code that closed the handle.

Now in my case what I did was gather a dump when some error case occurred in my process, then I examined the dump to determine what handle my code was using and then used !htrace to find out who closed it.  All of the information is kept in the crash dump nicely for you.

You can also pass a parameter to !htrace to dump activity for a single handle, like below:

0:000> !htrace 33c
--------------------------------------
Handle = 0x000000000000033c - CLOSE
Thread ID = 0x0000000000000744, Process ID = 0x0000000000000b6c

0x0000000077835faa: ntdll!ZwTerminateThread+0x000000000000000a
0x000000007780b508: ntdll!RtlExitUserThread+0x0000000000000048
0x000000007780b8a7: ntdll!TppWorkerThread+0x0000000000000a23
0x000000007761466d: kernel32!BaseThreadInitThunk+0x000000000000000d
0x0000000077818791: ntdll!RtlUserThreadStart+0x000000000000001d
--------------------------------------
Handle = 0x000000000000033c - OPEN
Thread ID = 0x0000000000000744, Process ID = 0x0000000000000b6c

0x000000007773d57a: user32!ZwUserCallOneParam+0x000000000000000a
0x000000007773d95f: user32!RealMsgWaitForMultipleObjectsEx+0x00000000000000b3
0x000000007773da2e: user32!MsgWaitForMultipleObjectsEx+0x0000000000000046
0x0000000077732af4: user32!MsgWaitForMultipleObjects+0x0000000000000020
0x000007fef5fbb198: browseui!CShellTaskScheduler::_TT_MsgWaitForMultipleObjects+0x0000000000000038
0x000007fef5fbb11d: browseui!CShellTaskScheduler::TT_TransitionThreadToRunningOrTerminating+0x00000000000000a1
0x000007fef5fbaea1: browseui!CShellTaskThread::ThreadProc+0x0000000000000076
--------------------------------------

You will notice a specific handle is closed and reopened many times over a period of time, this is normal.  What you want to look for is cases where CLOSE is called 2 times in a row to find cases of handle misuse.  Likewise if a handle is leaked you will not see a final CLOSE called, the last trace will be an OPEN.

Now, when you are finished debugging, BE ABSOLUTELY SURE to start App Verifier again and DELETE the process entry for your process!  You want to always do this since the App Verifier settings are persisted in the registry, they will survive even a server reboot.  Right click on the Image Name and select “Delete Application”.  Then click Save and close and re-open App Verifier to ensure that the entry is gone.  As well if you are debugging some service you want to restart the service to stop the tracking, run iisreset for example again to reset IIS to normal state if you are debugging IIS.

Hope this helps you debug the next handle misuse case you encounter, have fun!

Nice day

Yes.

IMG_9487

How to tell if binary is x86 or amd64?

First get dumpbin tool, ships with any Windows SDK.

Run dumpbin /headers on the binary, then look at the magic number.

This is an amd64 binary:

 

c:\>dumpbin /headers c:\amd64\msvcr100.dll | findstr magic
             20B magic # (PE32+)

This is a 32-bit binary:

 

c:\DPMedusa1>dumpbin /headers c:\x86\msvcr100.dll | findstr magic
             10B magic # (PE32)

 

dumpbin also works on executables, for example on my amd64 machine:

 

c:\>dumpbin /headers c:\Windows\System32\calc.exe | findstr magic
             20B magic # (PE32+)

 

c:\>dumpbin /headers c:\Windows\SysWOW64\calc.exe | findstr magic
             10B magic # (PE32)

TrustedInstaller

Just a note to self, when typing in TrustedInstaller into security dialogs in Vista/Windows 2008, be sure to prefix with:

    NT SERVICE\TrustedInstaller

C:\Windows>icacls c:\windows\winsxs
c:\windows\winsxs

                  NT SERVICE\TrustedInstaller:(OI)(CI)(F)
                  BUILTIN\Administrators:(OI)(CI)(RX)
                  NT AUTHORITY\SYSTEM:(OI)(CI)(RX)
                  BUILTIN\Users:(OI)(CI)(RX)

 

The security UI dialogs do not recognize TrustedInstaller just by itself (don't know why).

What is mscorwks_ntdef.dll?

Ok, file this one under debugger trivia. 

If you are debugging a 32-bit CLR process from a 64-bit native (Windbg) debugger, you will notice:

 

0:040> lmvm mscorwks_ntdef
start             end                 module name
00000000`69480000 00000000`69a10000   mscorwks_ntdef   (deferred)            
    Image path: mscorwks_ntdef.dll
    Image name: mscorwks_ntdef.dll
    Timestamp:        Fri Jul 25 06:58:48 2008 (4889DC18)
    CheckSum:         00597CC4
    ImageSize:        00590000
    File version:     2.0.50727.3053
    Product version:  2.0.50727.3053
    File flags:       0 (Mask 3F)
    File OS:          4 Unknown Win32
    File type:        2.0 Dll
    File date:        00000000.00000000
    Translations:     0409.04b0
    CompanyName:      Microsoft Corporation
    ProductName:      Microsoft® .NET Framework
    InternalName:     mscorwks.dll
    OriginalFilename: mscorwks.dll
    ProductVersion:   2.0.50727.3053
    FileVersion:      2.0.50727.3053 (netfxsp.050727-3000)
    FileDescription:  Microsoft .NET Runtime Common Language Runtime - WorkStation
    LegalCopyright:   © Microsoft Corporation.  All rights reserved.
    Comments:         Flavor=Retail

What is this mscorwks_ntdef?  It is debugger hocus pocus due to a bug.  Run this command to make it go away:

0:040> .reload /s
.....
Loading Wow64 Symbols
................................................................
................................................................
................................................................

 

Now you will see the correct output for mscorwks module:

 

0:040> lmvm mscorwks_ntdef
start             end                 module name
0:040> lmvm mscorwks
start             end                 module name
00000000`69480000 00000000`69a10000   mscorwks   (deferred)            
    Image path: C:\Windows\Microsoft.NET\Framework\v2.0.50727\mscorwks.dll
    Image name: mscorwks.dll
    Timestamp:        Fri Jul 25 06:58:48 2008 (4889DC18)
    CheckSum:         00597CC4
    ImageSize:        00590000
    File version:     2.0.50727.3053
    Product version:  2.0.50727.3053
    File flags:       0 (Mask 3F)
    File OS:          4 Unknown Win32
    File type:        2.0 Dll
    File date:        00000000.00000000
    Translations:     0409.04b0
    CompanyName:      Microsoft Corporation
    ProductName:      Microsoft® .NET Framework
    InternalName:     mscorwks.dll
    OriginalFilename: mscorwks.dll
    ProductVersion:   2.0.50727.3053
    FileVersion:      2.0.50727.3053 (netfxsp.050727-3000)
    FileDescription:  Microsoft .NET Runtime Common Language Runtime - WorkStation
    LegalCopyright:   © Microsoft Corporation.  All rights reserved.
    Comments:         Flavor=Retail

 

However, try to load sos and it will fail:

0:040> .loadby mscorwks sos
Unable to find module 'sos'

0:040> .load C:\Windows\Microsoft.NET\Framework64\v2.0.50727\sos.dll
0:040> !dumpstack -EE
Failed to load data access DLL, 0x80004005
Verify that 1) you have a recent build of the debugger (6.2.14 or newer)
            2) the file mscordacwks.dll that matches your version of mscorwks.dll is
                in the version directory
            3) or, if you are debugging a dump file, verify that the file
                mscordacwks_<arch>_<arch>_<version>.dll is on your symbol path.
            4) you are debugging on the same architecture as the dump file.
                For example, an IA64 dump file must be debugged on an IA64
                machine.

You can also run the debugger command .cordll to control the debugger's
load of mscordacwks.dll.  .cordll -ve -u -l will do a verbose reload.
If that succeeds, the SOS command should work on retry.

If you are debugging a minidump, you need to make sure that your executable
path is pointing to mscorwks.dll as well.
0:040> .cordll -ve -u -l
CLRDLL: LoadLibrary(C:\Windows\Microsoft.NET\Framework\v2.0.50727\mscordacwks.dll) failed, Win32 error 193
CLRDLL: Unable to find mscordacwks_AMD64_x86_2.0.50727.3053.dll by mscorwks search
CLRDLL: Unable to find 'mscordacwks_AMD64_x86_2.0.50727.3053.dll' on the path
CLRDLL: Unable to get version info for 'c:\syms\mscorwks.dll\4889DC18590000\mscordacwks_AMD64_x86_2.0.50727.3053.dll', Win32 error 0n87
CLRDLL: ERROR: Unable to load DLL mscordacwks_AMD64_x86_2.0.50727.3053.dll, Win32 error 0n87
CLR DLL status: ERROR: Unable to load DLL mscordacwks_AMD64_x86_2.0.50727.3053.dll, Win32 error 0n87

 

Summary: Sos debugger extension will not work in "mixed bitness" debugging scenarios. 

You must debug 32-bit CLR process using 32-bit native debugger in order to get sos to work properly.

Likewise if you are debugging 64-bit CLR process, use 64-bit debugger and 64-bit sos.dll.

How To Read Data From AD LDS Into Java

Just helping out the next person, this code took me all day to cobble together.

Key tricky part was how to connect to AD using an NT security account from Java.

 

public static String ReadBindingInfoFromAd() throws NamingException
{  
    Hashtable env = new Hashtable();   
    env.put(Context.INITIAL_CONTEXT_FACTORY, "com.sun.jndi.ldap.LdapCtxFactory");   
    env.put(Context.PROVIDER_URL, "LDAP://MyLdapServer:389");
    env.put(Context.SECURITY_AUTHENTICATION, "DIGEST-MD5"); // Use DIGEST-MD5, it works with Windows.
    env.put(Context.SECURITY_PRINCIPAL, "MyNtDomain\\MyNtUser");  // This is your nt domain and user.
    env.put(Context.SECURITY_CREDENTIALS, "MyPassword");    // Nt user account's password.
    DirContext context = new InitialDirContext(env); 
    
    SearchControls ctrl = new SearchControls();
    ctrl.setCountLimit(1);  // This is a good idea, limits result size. 
    ctrl.setSearchScope(SearchControls.ONELEVEL_SCOPE);
    ctrl.setReturningAttributes(new String [] {"serviceBindingInformation"});
    
    NamingEnumeration enumeration = context.search("CN=MyServer,CN=MyContainer", "(objectclass=serviceConnectionPoint)", ctrl);
    
    // My search should only return one value.
    if (enumeration.hasMore())
    {
        SearchResult result = (SearchResult) enumeration.next();
        Attributes attribs = result.getAttributes();
        NamingEnumeration values = ((BasicAttribute) attribs.get("serviceBindingInformation")).getAll(); 
        if (values.hasMore())
        {
            return values.next().toString();
        }
    }
    return "";  
}
Same code from C# is not as bad because it leverages current user's context:
 
public static string ReadBindingInfoFromAd()
{
    using (DirectoryEntry root = new DirectoryEntry("LDAP://MyLdapServer:389/CN=MyServer,CN=MyContainer"))
    {
        return (string)root.Properties["serviceBindingInformation"].Value;
    }
}
Chicken + Egg Problem With Hyper-V

When we neglect to port an old and crusty feature, one will always wave a few hands and say it's better in the end for the customer.  But sometimes it becomes a sticking point.  Today I am trying to setup VMs using Hyper-V on Windows 2008 and by default Hyper-V does not allow mouse to work with VMs over remote desktop unless you install VM additions on guest OS.  Virtual PC did not have this requirement, the mouse would work but in a horribly wild and wacky way, skittering left and right across the screen until you installed VM additions.  In most cases this was not a problem for me except for today, I'm working from home and I just need to send ONE mouse click in order to log into the guest OS to install VM additions.  The old wild and crazy VPC mouse click would suffice here!

 

HyperV

 

Arg.  I cannot log in because of one mouse click.   I will try rebooting.

Rebooted, managed to type in password behind SCM message box, and logged in.

Next my NIC does not work.  Ok, I cannot configure hyper-v over remote desktop and the NIC does not work by default.

Ok, fixed NIC, user error, I had to setup Legacy mode on the NIC, got this working.

Attempted to install hyper-v extensions, this failed with "An error has occurred:  The specified program requires a newer version of Windows."

hyperv2

Arg again.  I have to install Windows 2003 SP2 I suppose.  Trying this now.

What I need to do is create isos for Windows 2003 and Windows 2003 SP2, this would help speed things along.

SqlClient Timeouts Revealed

Just some notes from recent discussions internal and external of how timeouts work with SqlClient.  First a classification of where timeouts can occur with SqlClient:

  1. When attempting to get a connection from the SqlClient connection pool
  2. When attempting to create a new fresh connection to server (not getting one from pool)
  3. When sending a command explicitly to the server
  4. When sending commands with "context connection=true"
  5. When sending commands implicitly (under the covers) to the server
  6. When executing asynchronous commands (BeginExecute...)
  7. When waiting for attention acknowledgement from server (special rare case)
  8. When sending TM commands
  9. When fetching rows
  10. When uploading rows using bulk copy

I hope I did not miss a class of timeout here, if so, let me know.

First, the majority of these above listed timeouts leverage SqlConnection.ConnectionString's "Connect Timeout" and SqlCommand.CommandTimeout values in a logical and sensible manner.

Login Timeouts

For example 1 and 2 use "Connect Timeout", this makes sense to me.  We could have created a separate "get a live connection timeout" versus a "get connection from the pool timeout" but the utility of this does not over-ride the added complexity of having 2 timeouts here.  But say for example you happen to have an old ancient lost to the ages SQL Server that takes 1 minute to open a connection to over a slow WAN.  But once connections are in the pool you want to pull these out in a rapid fashion.   Ahh, it's just not worth it to add this feature for such an edge case.

With Connect Timeout, a value of 0 means "infinite" wait.  It's not truely infinite of course 0 is mapped to UInt32.MaxValue milliseconds underneath which is about 49 days.  Hope you don't have to wait that long for SQL to respond.

If the connection pool is full, attempts to get a connection from the pool will block until Connect Timeout expires, this makes sense.

If you have to open a new connection, there are many activities that occur underneath that could take time.  We have to open a socket to the server, this could be blocked by networking layer for a long time.  Next we have to send prelogin packet to server to negotiate packet size and get server version, and here we wait for a prelogin response from the server.  Once we process prelogin, we then have to send a login packet and this can get complicated.  First we have to negotiate with SQL Server to get SSL setup for encrypting the login packet.  Once we have SSL setup, which can entail multiple trips back and forth to server,  we can then send the login packet.  If you use integrated authentication, we also have to setup the SSPI channel and this could take a few round trips as well.  Ok, once all this is done we get a login acknowledgement from the server and we are "logged in" and hand back control to the caller.  All of this occurs under Connect Timeout period of time during SqlConnection.Open, if any leg in the process takes too long, the timeout expires and exception is thrown.

Note if you do get lots of login timeout failures, this can be indicative of poor pooling performance.  Logins can timeout due to high CPU on server side as well -- if for example the server just does not have enough CPU to process the login quickly enough.  In any case Connect Timeout in SqlClient controls this timeout.

Logins are slightly more complicated when you are connecting to a mirrored SQL Server.  If you are doing this you will have "Failover Partner" specified in the ConnectionString.  When connecting to a mirrored server we alternately attempt to open connections to primary and secondary back and forth until timeout expires.  Overall the same timeout provided by "Connect Timeout" applies in the end.

Explicit Command Execution Timeouts

When executing commands using SqlCommand, the CommandTimeout is used.  A CommandTimeout of 0 means "infinite" again (a.k.a 49 days).  If you don't set CommandTimeout, a default of 30 seconds is used.

Looks simple on the surface but now the fun begins.  What precisely does "the command completed" really mean?  Does it mean the server processed the query and sent back the first byte of response?  Does it mean the time until the entire response is drained?  The help topic for SqlCommand.CommandTimeout indicates:

This property is the cumulative time-out for all network reads during command execution or processing of the results. A time-out can still occur after the first row is returned, and does not include user processing time, only network read time.

This can be important if you are reading millions of rows using a SqlDataReader.  As you read more and more rows you are chewing away at this cumulative time, and the time can run out in theory. 

Note that when reading data from the server, SqlClient reads data in packets (called TDS packets) and these are 8000 bytes each by default.  We don't do any readahead, we just read 8K at a time.  Hence reading a series of rows in a resultset in turn reads a series of 8K packets from the server.  If you are curious about this you can use SQL Server Management Studio and turn on the "Include Client Statistics" feature (it's on the toolbar):

clientstats

You can see here I read 1000 rows, 1306 TDS packets (8000 bytes each) and total of 4MB of data.  This boils down to 1306 network reads of 8K.  In most cases the network reads are very fast, however you could hit one or more locked rows half-way through reading the results which could accumulate more time.  A locked row means the client blocks waiting for the row lock to become available, eating up more of your CommandTimeout.

Hence CommandTimeout covers all the time spend making all these 8k reads, including the first 8K read which is most likely the longest wait as it's waiting for the server to process the query and send back the first bytes of response.

Some customers have complained about this behavior, they think that once the initial read completes then subsequent row fetches should not time out.  The command has completed in other words, why time out reading rows?  In reality, the command may or may not be completed when the first 8K read is returned to the client.  For example you could send a batch of commands and the first command may be completed but subsequent commands in the batch have not even started executing yet.  I suppose we could have a row read timeout and a command timeout to allow more granular control here, but it is really such an edge case that it's not worth cluttering the API with multiple and thus more confusing timeout settings (most customers would never need to set RowReadTimeout).

SqlConnection and "context connection=true"

If you never write CLR code that runs inside SQL Server, you can skip this section.  If you do write code that runs inside SQL Server (CLR stored procedures or functions) then there is a feature called "context connection=true" that allows you to open a loopback SqlConnection to current SQL Server database.  This loopback connection ignores all command timeouts since it is running in the context of a sql batch already and the client controls the timeout.

Implicit Command Timeouts

In some rare cases SqlClient code needs to execute internal commands behind the scenes to fetch metadata etc..., these are "implicit commands".  Some cases of SqlConnection implicit commands:

  • SqlConnection.GetSchema - Internally creates a SqlCommand and executes a metadata query.
  • SqlConnection.ChangeDatabase - Sends a "use [<databasename>]" command under the covers.
  • SqlConnection.BeginTransaction - Sends a "begin transaction" command or other transaction manager command under the covers.

These SqlConnection methods don't have access to any pre-existing SqlCommand object to obtain a CommandTimeout, hence they were written to use Connect Timeout.  Ok, to be honest I am not sure if this makes total sense, but this is how we did it.  Think of "Connect Timeout" as the timeout that applies to all things SqlConnection (login, implicit commands) then it makes sense.   Big note: SqlConnection.GetSchema currently has a bug where it uses a hard-coded 180 second timeout,the plan is to fix this to be consistent and use Connect Timeout some time in the future.

Now SqlCommand does not have any implicit commands it runs, but if it did, it would use CommandTimeout.

SqlDataReader does have an implicit command --> SqlDataReader.GetSchemaTable.  GetSchemaTable uses the CommandTimeout from it's parent SqlCommand object since SqlDataReader does not have a settable timeout.

I classify TM commands as another form of implicit command executed by the driver under the covers.  What is a TM command?  TM stands for transaction manager.  A TM command is a special command sent to SQL Server to request changes in transaction state from the client.  Commands like SqlConnection.BeginTransaction and SqlConnection.EnlistTransaction and SqlConnection.EnlistDistributedTransaction send these TM commands.  All of these use the parent SqlConnection's "Connect Timeout".

Asynchronous Command Execution Timeout

SqlClient does not enforce any timeouts on asynchronously executed commands.  They can run forever in theory.  Note this is not the 49 day forever but the real forever.  Asynchronous commands include SqlCommand.BeginExecuteReader, BeginExecuteNonQuery, and BeginExecuteReader.

Ok, you might be a little shocked by this behavior, but this is how it works.  The idea of asynchronous command execution is you send off the command and then are notified via an event when it completes.  You can implement your own timeout if needed, for example you could start a timer that checks if the command is completed after a period of time and if not then cancels it.

The bottom line is IF we wanted to implement CommandTimeout in this case we would just do the same thing, spin up a timer with a handle to the executing command and cancel it if the timer expires and the command has not completed. 

Cancel Timeout (attention acknowledgement timeout)

Ok, this is a very rare edge case, you can probably forget about this one, but if you are really bored, read on.  Suppose you execute a command, then the command times out.  When this happens the SqlClient driver sends a special  8 byte packet to the server called an attention packet.  This tells the server to stop executing the current command.  When we send the attention packet, we have to wait for the attention acknowledgement from the server and this can in theory take a long time and time out.  You can also send this packet by calling SqlCommand.Cancel on an asynchronous SqlCommand object.  This one is a special case where we use a 5 second timeout.  In most cases you will never hit this one, the server is usually very responsive to attention packets because these are handled very low in the network layer.

Now there is a really rare edge case where you send an attention but the server has already completed the operation.  What happens in this case?  In this case SqlClient just drains the response for you silently and still throws the timeout exception.  This brings up a good point -- there is a slim sliver of a possibility if you cancel a command or it times out it may actually complete on the server side prior to the attention signal, please keep this in mind.   This is a small gotcha that exists when using automatic transactions and a timeout or cancel occurs.  If you use a manual transaction then you can always roll back after handing the timeout exception to ensure you get into a consistent state.

Summary

In general the parent objects timeout is used in most cases, this is the easiest thing to remember.  If parent is SqlConnection then Connect Timeout is used, if the parent object is SqlCommand or SqlDataReader, then the SqlCommand.CommandTimeout is used.   There are a few minor exceptions that don't really add up to much for most scenarios.

If I missed anything here, let me know.  Matt

Why Can't I Log Into SQL Server?

Even though I've been working on the SQL Server protocol layer for the past 3 years I still have those days where I scratch my head because I cannot connect to my SQL Server.   I have to agree it can be frustrating sometimes.  Usually, once you get it working, it stays working, which is a good thing.   If any of you out there hit any other "head smacking" gotchas, let me know.

1. SSL Self-Signed Cert Does Not Work When Forcing Encryption From Client

Today I forgot that I checked the "Encrypt Connection" checkbox in SQL Server Management Studio while trying to verify that an SSL certificate I installed on a SQL 2000 box a day before was working.  Then I attempted to connect to my SQL 2008 server that is using self-signed certificate (which is default behavior in SQL 2005 and later).  When you do this, you get the following error:

"A connection was successfully established with the server, but then an error occurred during the pre-login handshake. (provider: SSL Provider, error: 0 - The certificate chain was issued by an authority that is not trusted.) (Microsoft SQL Server, Error: -2146893019)

This error makes sense if you realize that a self-signed certificate does not have a trusted root (everyone knows this, right?).  Anyway, if you see this one, now you will remember.  This can occur with SQL 2005 and SQL 2008, both of these will load a self-signed certificate during startup time if an appropriate SSL certificate is not setup on the machine.

Thing to remember:  If you want full client side forced SSL encryption to work properly with SQL Server, you need to configure a real SSL certificate that the client trusts.   The self-signed cert is only useful for encrypting login packets and is not fully trusted by the client since it does not have a trusted root authority.

2. I'm A Vista Admin But Cannot Login To My Local SQL Server

Another good one:  Attempt to login to your local SQL Server on Vista from non-elevated command prompt or non-elevated SSMS.  Login failed for user domain\username!  But I'm logged in as an admin!  You are not admin if you don't elevate.  This one get's me about once every 3 months or so.

3. Cannot Connect To A Clustered SQL Server Named Instance From A Vista Client (submitted by Andy Babiec, thanks!)

This is technically speaking not a Vista specific issue, but it is seen more often on Vista clients because of it's advanced (a.k.a. more secure) firewall configuration.

The basic problem is when the client needs to determine the port of any SQL Server named instance, it will send a UDP packet on port 1434 to the target server and then wait for a response on UDP 1434.  The response packet will have instance name and port number.  Now the issue arises with Windows Cluster where our SQL Browser service gets the incoming  UDP packet then posts a response.  The incoming UDP packet comes in on the virtual cluster IP, but when we send a response, the packet is tagged with the local machine's IP.  Hence a more aggressive client firewall may block the response UDP packet since it has a different IP from the outbound request packet.

This can cause clients on Vista such as SQL Server Management Studio and also Sql Profiler to fail to connect to the clustered named instance.

There are various workarounds, one is to add SSMS.exe and SqlProfiler.exe to firewall exclusion list.  Another is to specify the tcp port in the connection string when connecting.  I tend towards the latter, but then again I am a protocols geek and I setup my servers with known port numbers.  We're working with the Windows Cluster team for a solution to this one.  Here is a more detailed blog on the subject from Xinwei, one of our protocols guru:

http://blogs.msdn.com/sql_protocols/archive/2006/02/27/unable-to-connect-to-a-sql-server-named-instance-on-a-cluster.aspx

 

4. User Does Not Have Right To Log Into Their Default Database

I have seen this a few times on the newsgroups, so adding this one too.  When you create new users in SQL Server, be sure to allow them access to their designated default database, otherwise they cannot log in! 

For example, create a junk1 user like so:

use master
go
create database junk1
go
use junk1
go
create login junk1 with password=N'junk1',
default_database=junk1, check_expiration=off, check_policy=off
go

Now attempt to log in using osql:

C:\>osql -Ujunk1 -Pjunk1 -S.
Login failed for user 'junk1'.
Cannot open user default database. Login failed.

If you examine the errorlog in SQL 2008, you see:

Error: 18456, Severity: 14, State: 40.
Login failed for user 'junk1'. Reason: Failed to open the database specified in the login properties. [CLIENT: 123.23.123.12]
 

We actually did a ton of work in SQL 2008 to make these 18456 login errorlog messages more human understandable in SQL 2008, so this is nice feature for dba who is wondering "who is trying to log into my server?".  In SQL 2005 you need the special 18456 decoder ring:

secretcodering

Sharing IE Links With Live Mesh

In case you have not heard the buzz, we have this new thing called Live Mesh that is pretty awesome.  I found out about it whist trying to figure out how to share my Links (c:\users\...\Favorites\Links) folders across multiple machines.  I talked to one of my IE buds and he indicated Live Mesh might be the ticket.

With Live Mesh you can add each computer as a node in your mesh.  Then you can share folders from your computer into the mesh (and it shares these across all your computers).

To share my Links, I had to play some tricks with Live Mesh, but nothing too serious.

I setup Live Mesh on multiple computers, then on primary computer right clicked on C:\Users\MattN\Favorites\Links and shared it to the Mesh (note these computers are Vista, Live Mesh works on Vista and XP for now).  On XP this would be C:\Documents And Settings\MattN\Favorites\Links.  I shared my Links folder on one and only one machine (and also at this point consolidated all my actual links on the one primary machine).

Next on secondary machines what will happen is a new shortcut named Links will appear on your desktop once Live Mesh syncs up.

I then closed all IE instances on secondary machines, renamed existing Links to Links1.

Then go to link on desktop, right click and select Live Mesh Options... Change Sync Settings...

This will give you an option on where you want the link to reside, change it to C:\Users\Mattn\Favorites\Links, the folder will move automatically and now you have a shared Links folder, pretty cool!

Going to let this run for a few weeks and see how it works out.

Finding Locals In CLR

Today I'm looking at a few Watson dumps trying to determine why SqlConnection is failing to connect to SQL Server and hanging.

I see stack like below:

0:000> k
0021dc5c 79f40778 kernel32!SleepEx+0x62
0021dc90 7a0561d7 mscorwks!EESleepEx+0xa3
0021dc9c 7a12fc71 mscorwks!CExecutionEngine::ClrSleepEx+0xd
0021dcac 7a0e4d7c mscorwks!ClrSleepEx+0x13
0021dce8 7a082a5f mscorwks!Thread::UserSleep+0x63
0021dd88 652e94cd mscorwks!ThreadNative::Sleep+0xce
0021ddc8 652e9283 System_Data_ni!System.Data.SqlClient.SqlInternalConnectionTds.LoginNoFailover
0021de20 652e83ff System_Data_ni!System.Data.SqlClient.SqlInternalConnectionTds.OpenLoginEnlist

 

I need to look at CLR locals in SqlClient.SqlInternalConnectionTds.LoginNoFailover, and these locals are intrinsic CLR type long (Int64).

Where does CLR hide these frame local long values?

Using the sos extension I see !dso does not dump intrinsic locals.

!clrstack, wow the output is completely wrong and bizarre.

!dumpstack, !dumpstack -EE, broken.

kP works, somewhat reasonably.

Time to get ugly.

Ok, I locate start of assembly for SqlInternalConnectionTds.LoginNoFailover in debugger and just dump the raw assembly.

I know my variable is passed into function ADP.TimerRemainingMilliseconds, so my plan is to locate this call in unassembly and see how the assembly code packs the value passed to this function, this will give me a clue on where the value is held.

I find it here:

652e942f ff75d8          push    dword ptr [ebp-28h]
652e9432 ff75d4          push    dword ptr [ebp-2Ch]
652e9435 e8d2c3f3ff      call    System_Data_ni!System.Data.Common.ADP.TimerRemainingMilliseconds(Int64) (6522580c)

Good, I see ebp-offset, this looks like stack local.  I use kvn to get frame number.

0:000> kvn 10
# ChildEBP RetAddr  Args to Child             
...
07 0021dd88 652e94cd 06bf6a58 06bf3f90 06bf67cc mscorwks!ThreadNative::Sleep+0xce (FPO: [Non-Fpo]) (CONV: fastcall) [f:\whidbeyrtmlhs\ndp\clr\src\vm\comsynchronizable.cpp @ 964]
08 0021ddc8 652e9283 00000000 00000000 00000000 System_Data_ni!System.Data.SqlClient.SqlInternalConnectionTds.LoginNoFailover(System.String, System.String, Boolean, System.Data.SqlClient.SqlConnection, System.Data.SqlClient.SqlConnectionString, Int64)+0x215 (Managed) [f:\WhidbeyRTMlhs\ndp\fx\src\Data\System\Data\SqlClient\SqlInternalConnectionTds.cs @ 862]

Set the frame:

0:000> .frame 8
08 0021ddc8 652e9283 System_Data_ni!System.Data.SqlClient.SqlInternalConnectionTds.LoginNoFailover(System.String, System.String, Boolean, System.Data.SqlClient.SqlConnection, System.Data.SqlClient.SqlConnectionString, Int64)+0x215 [f:\WhidbeyRTMlhs\ndp\fx\src\Data\System\Data\SqlClient\SqlInternalConnectionTds.cs @ 862]

I then look at registers for frame 8:

0:000> r
Last set context:
eax=00000000 ebx=00000000 ecx=00000000 edx=00000000 esi=0021dc38 edi=00000000
eip=77520f34 esp=0021dbf4 ebp=0021dc5c iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00200202
ntdll!KiFastSystemCallRet:
77520f34 c3              ret

Ok, then 0021dc5c -28 and 0021dc5c -2c should be the 2 DWORDs that compose my Int64 value:

0:000> dd 0021dc5c-2c
0021dc30  76f16110 00000000

For real?  I am really not sure.  I'll try it on a live debug to be sure.

Connection Pooling, ADO.NET, SPIDs

If you have pooling issues with ADO.NET (leaking connections, pool size exceeded, etc...) one way to slice and dice these with SQL 2005 is to use the SQL 2005 system DMVs.

 

You can locate leaked connections like so:

 

select 
session_id, 
datediff(s,last_read,getdate()) as SecondsSinceLastRead,
datediff(s,last_write,getdate()) as SecondsSinceLastWrite,
(select text from sys.dm_exec_sql_text(dec.most_recent_sql_handle)) as LastSqlStatment
from sys.dm_exec_connections dec

 

The idea being if the connection is properly pooled then last_read and last_write should always be active.  Leaked connections will go into garbage collector and sit there for a while still open but not reading and writing.

 

Next suppose you find leaked ones, how can you correlate these with client code?  Here is one way:

select 
session_id as Spid, 
(select login_name from sys.dm_exec_sessions where session_id=dec.session_id) as UserName,
datediff(s,last_read,getdate()) as SecondsSinceLastRead,
datediff(s,last_write,getdate()) as SecondsSinceLastWrite,
text as LastSqlStatment
from sys.dm_exec_connections dec
cross apply sys.dm_exec_sql_text(dec.most_recent_sql_handle)

 

This will dump out each SPID and also the last TSQL statement to run on the SPID.  Then search your source code for the TSQL to locate which part of your code leaked the connection.  Not a perfect solution but should get you pretty close.

 

Suppose you are really stumped and cannot correlate the TSQL.   You can get a full memory dump of the client process (I'm assuming like an ASP.NET application here) and then dig through this using the sos debugger extension.  I'll post on this later.

Debugging .NET Code

Some days I wonder how customers debug .NET code.

I've been debugging CLR for many years using a mix of techniques (VS.NET debugger and Windbg and logging of course).  To be honest I hate debugging in VS.NET, the debugger just annoys me to no end except for very simple debugging scenarios.  Once you go Windbg it is hard to go back.

But Windbg and CLR debugging are not a match made in heaven.  They work together like Frankenstein's monster and the angry mob work together.

Today I am debugging System.Data.SqlClient and transaction behavior inside CLR stored procedures and TDS protocol.

I know that transaction state flows over TDS protocol using a combination of TDS ENVCHANGE tokens (server->client) plus TDS mars header (client -> server).

What I see is proper setup of transaction state here:


- Tds: Response from server, Version=7.2
  + TDSHeaderFirst: 0x1
  - TDSServerResponseData:
     TokenType: ENVCHANGE
   - TokenData:
      Length: 11 (0xB)
      EnvChangeType: Begin Transaction
      NewValueLength: 8 (0x8)
      NewValue: 223338299393 (0x3400000001)
      OldValueLength: 0 (0x0)
     TokenType: DONE
   + TokenData:

0x3400000001 is my transaction id (descriptor).  I see it going out on the next request:


- Tds: Query, Version=7.2
  + TDSHeaderFirst: 0x1
  - SqlBatchData:
   - AllHeadersData:
      TotalLength: 22 (0x16)
      HeaderLength: 18 (0x12)
      HeaderType: MARS Header
      TransactionDescriptor: 223338299393 (0x3400000001)
      OutstandingRequestCount: 1 (0x1)
     SQLText: exec ClrProc2 N'123'

Next my CLR sproc inserts data into a table which in turn fires a trigger which in turn rolls back the transaction ->

create trigger trig1 on t1 for insert, update as
begin
    insert t2 (f1) values (1)
    select * from t2
    rollback tran
end

It is not recommended to do this in a trigger of course!  This is only my little test to see TDS protocol behavior.  The CLR sproc is supposed to surpress TDS tokens for internally run commands, which is a nice feature.  But how does it do this and keep transaction state consistent with client?  I expected it to send back a rollback transaction state ENVCHANGE.  I don't see it over the wire.

I do see an ERROR token of state 16 coming back and I suspect this is telling SqlClient to reset transaction state.

Ok, back to debugging CLR.  I need to know when this TDS response comes back, how it resets the transaction internal state of SqlClient.  I know little to nothing about the internals of how it works, but need to figure it out and debug it quickly without wasting time.  Via some digging I found this _currentTransaction was getting set and reset when the ENVCHANGEs come in.

Now, how do I set a breakpoint on the change of _currentTransaction in VS.NET debugger?

Let the fun begin.

First, note that I have a debug version of SqlClient that I just freshly built out of my enlistment and shoved into the GAC.  This is one important way to please the temperamental gremlin living inside VS.NET debugger.  Ok, crank up debugger.

Ok, get to my code, try to step into SqlCommand.ExecuteNonQuery.   Debugger does not step into it.

Tools | Options... Debugging | General-> "Enable Just My Code" checkbox is clear.  Why does it not step in?

Ok, the gremlin does not like my System.Data.dll.  VS.NET cannot find the symbols for a dll I just build on my local machine.  The trick to fix this is to place the symbols right next to the dll so that the debugger does not have to look too hard for symbols. Or you can modify symbol path in VS.NET.  I choose to place symbols next to dll, the reload symbols from module window.

Cool, got it working.  Now how do I set a bp on change of _currentTransaction?  This seems to be the tricky part in CLR.  In Windbg I would locate address of _currentTransaction and set a ba w4 <address> on it and call it a day.  In CLR there is no equivalent as far as I can tell.  Yes, I suppose I can manually set breakpoints on every method of the class that _currentTransaction uses in hopes that the methods are used but this is difficult to do in CLR as well (in Windbg I can set breakpoint on all class methods using a wildcard in one command).  It is time to go beg the VS.NET debugger gurus to see if they can help me.

Not yet.  Let me try this VS.NET 2008 immediate window, I have been meaning to give it a try.

!help
'!help': not available while Managed only debugging.

Arg.  I found a few basic commands that work, but most Windbg commands don't work:

?_currentTransaction
null
?poi(_currentTransaction)
The name 'poi' does not exist in the current context

Ok, I give up for now. I talked to CLR folks and they indicated VS.NET does not have data breakpoints for managed code yet.  Bummer.

Writing CLR Stored Procedures

I'm trying to write some CLR sprocs to test out the TDS behavior of CLR sprocs versus T-SQL sprocs for TDS protocol documentation purposes.  If you are not aware, we now have the TDS protocol spec on MSDN for your bedtime reading: 

http://msdn2.microsoft.com/en-us/library/cc448435.aspx

Note I'm also finishing up a full blown netmon parser for TDS as part of the protocol documentation effort.  To ensure this works well I'm investigating the dusty corners of TDS protocol stream behavior to ensure we have it properly spec' d and my parser works too.

On to CLR sprocs topic.  First thing I did was crank up VS.NET 2008 and try to create a database project so I can upload some test CLR sprocs.  It doesn't work because VS.NET 2008 is smart and detects the target SQL Server is 2008 and not 2005 so it refuses to co-operate and create a nice little CLR project for me.  I suppose I could use a 2005 server but I'm lazy.

No worries, I know how to manually upload CLR sprocs with all the magic T-SQL incantations.

Next I do this:

create assembly ClrTestJunkAssembly from N'C:\Project\ADONet\TranStress\bin\Debug\TranStress.exe' WITH PERMISSION_SET=SAFE
go

Msg 10301, Level 16, State 1, Line 1
Assembly 'TranStress' references assembly 'system.enterpriseservices, version=2.0.0.0, culture=neutral, publickeytoken=b03f5f7f11d50a3a.', which is not present in the current database. SQL Server attempted to locate and automatically load the referenced assembly from the same location where referring assembly came from, but that operation has failed (reason: 2(The system cannot find the file specified.)). Please load the referenced assembly into the current database and retry your request.

Note yes I am really really lazy and don't want to create a separate clean library project with my CLR stored proc in it.  I just want to upload my test client exe that also just happens to have the sproc class in it and get on with my life.  My other non-sproc test code happens to ref System.EnterpriseServices.  Arg.

Can I just shovel EnterpriseServices in?

create assembly EnterpriseServicesAssemblyForSQLServerWhoIsTooLazyToLookInGac from N'e:\WINNT\Microsoft.NET\Framework\v2.0.50727\System.EnterpriseServices.dll' WITH PERMISSION_SET=EXTERNAL_ACCESS
go

Warning: The Microsoft .Net frameworks assembly 'system.enterpriseservices, version=2.0.0.0, culture=neutral, publickeytoken=b03f5f7f11d50a3a, processorarchitecture=x86.' you are registering is not fully tested in SQL Server hosted environment.
Warning: The Microsoft .Net frameworks assembly 'system.directoryservices, version=2.0.0.0, culture=neutral, publickeytoken=b03f5f7f11d50a3a, processorarchitecture=msil.' you are registering is not fully tested in SQL Server hosted environment.
Msg 6218, Level 16, State 2, Line 1
CREATE ASSEMBLY for assembly 'System.EnterpriseServices' failed because assembly 'System.DirectoryServices' failed verification. Check if the referenced assemblies are up-to-date and trusted (for external_access or unsafe) to execute in the database. CLR Verifier error messages if any will follow this message
[ : System.DirectoryServices.DirectorySearcher::SetSearchPreferences][mdToken=0x60000f8][offset 0x0000050E][found address of value 'System.DirectoryServices.Interop.AdsSortKey'] Expected numeric type on the stack.
[ : System.DirectoryServices.SearchResultCollection::RetrieveDirectorySynchronizationCookie][mdToken=0x60001c6][offset 0x00000023][found address of value 'System.DirectoryServices.Interop.AdsSearchColumn'] Expected numeric type on the stack.
[ : System.DirectoryServices.SearchResultCollection::RetrieveVLVResponse][mdToken=0x60001c7][offset 0x00000023][found address of value 'System.DirectoryServices.Interop.AdsSearchColumn'] Expected numeric type on the stack.
[ : System.DirectoryServices.SearchResultCollection+ResultsEnumerator::GetCurrentResult][mdToken=0x60001d4][offset 0x00000033][found address of Native Int] Expected numeric type on the stack.

Arg,  you don't have to tell me everything twice, work with me brother.  Ok, I didn't like System.EnterpriseServices anyway, it was highly over-rated, so I removed it from my other code (I wasn't using it anymore anyway).

create assembly ClrTestJunkAssembly from N'C:\Project\ADONet\TranStress\bin\Debug\TranStress.exe' WITH PERMISSION_SET=SAFE
go

Msg 6212, Level 16, State 1, Line 1
CREATE ASSEMBLY failed because method 'Main' on type 'TranStress.Program'  in safe assembly 'TranStress' is storing to a static field. Storing to a static field is not allowed in safe assemblies.

Ok, ok, SQL, I know this game.  I'm starting to get offended.

create assembly ClrTestJunkAssembly from N'C:\Project\ADONet\TranStress\bin\Debug\TranStress.exe' WITH PERMISSION_SET=UNSAFE
go

Msg 10327, Level 14, State 1, Line 1
CREATE ASSEMBLY for assembly 'TranStress' failed because assembly 'TranStress' is not authorized for PERMISSION_SET = UNSAFE.  The assembly is authorized when either of the following is true: the database owner (DBO) has UNSAFE ASSEMBLY permission and the database has the TRUSTWORTHY database property on; or the assembly is signed with a certificate or an asymmetric key that has a corresponding login with UNSAFE ASSEMBLY permission.

Ok, let me try this but it makes me feel strange:

alter database transtress set trustworthy on
go
create assembly ClrTestJunkAssembly from N'C:\Project\ADONet\TranStress\bin\Debug\TranStress.exe' WITH PERMISSION_SET=UNSAFE
go

Ahh!  Now that was easy.  Next, I have to expose my function as a stored proc.  I created my CLR proc like so:

class CLRTestJunk
{
    [Microsoft.SqlServer.Server.SqlProcedure]
    public static void ClrProc1(string param1)
    {
        using(SqlConnection conn = new SqlConnection("Context Connection=true;"))
        {
            conn.Open();
            using (SqlCommand cmd = conn.CreateCommand())
            {
                int v = -1;
                int.TryParse(param1, out v);
                cmd.Parameters.Add("@p1", SqlDbType.Int);
                cmd.Parameters[0].Value = v;
                cmd.CommandText = "insert t1 (f1) values (@p1)";
                cmd.ExecuteNonQuery();
            }
        }
    }
}

Next I run this:

create procedure ClrProc1 as external name ClrTestJunkAssembly.CLRTestJunk.ClrProc1
go

Msg 6505, Level 16, State 2, Procedure ClrProc1, Line 1
Could not find Type 'CLRTestJunk' in assembly 'TranStress'.

Ok, now what?  I crank up reflector to see if it's there, yes it's there.

Maybe because I forgot to add the param:

create procedure ClrProc1(@param1 varchar(max)) as external name ClrTestJunkAssembly.CLRTestJunk.ClrProc1
go

Msg 6505, Level 16, State 2, Procedure ClrProc1, Line 1
Could not find Type 'CLRTestJunk' in assembly 'TranStress'.

No. no. no.  I'm not beaten yet.  Go search around web for 6505, try this:

create procedure ClrProc1(@param1 varchar(max)) as external name [TranStress.ClrTestJunkAssembly].CLRTestJunk.ClrProc1
go

No dice.  Ok SQL CLR, you win, I strip out a separate library class with my code.  Same problem:

create assembly ClrClassLibraryAssembly from N'C:\Project\ADONet\ClrClassLibrary\bin\Debug\ClrClassLibrary.dll' WITH PERMISSION_SET=SAFE
go
create procedure ClrProc1 as EXTERNAL NAME ClrClassLibraryAssembly.ClrClassLibrary.ClrProc1
go

Msg 6505, Level 16, State 2, Procedure ClrProc1, Line 1
Could not find Type 'ClrClassLibrary' in assembly 'ClrClassLibrary'.

Ok, SQL CLR you are making me feel stupid, I thought I was a kick butt dba until today, now you are just mocking me, thanks a ton.  I found another newsgroup entry that gave me an idea:

create procedure ClrProc1 as EXTERNAL NAME ClrClassLibraryAssembly.[ClrClassLibrary.ClrClassLibrary].ClrProc1
go

Msg 6576, Level 16, State 4, Procedure ClrProc1, Line 1
Type 'ClrClassLibrary.ClrClassLibrary' in assembly 'ClrClassLibrary' is not public.

Ohhh!  I am getting closer.  Here is my class now for reference:

namespace ClrClassLibrary
{
    class ClrClassLibrary
    {
        [Microsoft.SqlServer.Server.SqlProcedure]
        public static void ClrProc1(string param1)
        {

To reference this in SQL Server I have to say ClrClassLibraryAssembly.[ClrClassLibrary.ClrClassLibrary].ClrProc1, not bloody intuitive but ok, I can guess why we did it this way (SQL Server's 4 part naming convention probably won out over CLR).

Ok, make my class public and away I go:

create procedure ClrProc1 as EXTERNAL NAME ClrClassLibraryAssembly.[ClrClassLibrary.ClrClassLibrary].ClrProc1
go

Msg 6550, Level 16, State 2, Procedure ClrProc1, Line 1
CREATE PROCEDURE failed because parameter counts do not match.

Ok, I forgot to add back my param:

create procedure ClrProc1(@param1 varchar(max)) as EXTERNAL NAME ClrClassLibraryAssembly.[ClrClassLibrary.ClrClassLibrary].ClrProc1
go

Msg 6552, Level 16, State 3, Procedure ClrProc1, Line 1
CREATE PROCEDURE for "ClrProc1" failed because T-SQL and CLR types for parameter "@param1" do not match.

Ok, I think I have performed full code coverage for all CLR error messages by now, one more try, the winner is:

create procedure ClrProc1(@param1 nvarchar(max)) as EXTERNAL NAME ClrClassLibraryAssembly.[ClrClassLibrary.ClrClassLibrary].ClrProc1
go

Yes!  Now to call my CLR stored procedure:

exec ClrProc1 N'123'

Msg 6263, Level 16, State 1, Line 1
Execution of user code in the .NET Framework is disabled. Enable "clr enabled" configuration option.

Whoops.  Ok, need to enable CLR:

sp_configure 'clr enabled',1
go
reconfigure with override
go

Ok, one more time:

exec ClrProc1 N'123'

Works!  Looks like VS.NET does quite a bit of nasty CLR grunt work for me.  But overall what have we learned about CLR stored procedures?

  1. Make sure your class is public.
  2. Avoid references to CLR modules like System.EnterpriseServices, try to keep your code as reference free as possible.
  3. Avoid namespaces.
  4. Ensure you enable CLR on the server.
  5. Probably best to have it in it's own class library to keep things as simple as possible.
  6. Don't change versions of SQL Server or VS.NET will no longer work.
  7. Always learn how to do it using T-SQL versus rely on VS.NET if you want it to work anyway.

You can always sniff the TSQL that VS.NET uses to configure your CLR sproc using SQL Profiler and save this.

Why does Windows Always Want To Hide Things From Me?

Over the years, I find more and more of the Windows UI is designed to hide things like where the files are coming from, file extensions, etc... from me. Why is this?  I want to see this stuff. 

For example, why can't I get the full path to a file easily?  I have to open Run box, then drag and drop file into the Run box, then select file name, then copy it, then go paste it where I need it.   I've probably done this a million times in my life.

I found in Vista recently that drag+drop to a console window no longer works, I was heart broken, this saves me tons of time.  But I found a cool feature in Vista that makes up for it.

Hold down shift key and right-click on file and you will see a few new options on the menu bar.  See the Copy as Path below, this is the one you want.  Saves you having to pop the Run menu, very nice!

image

Hey, I was excited. :)

I found on Vista that whenever I had a networking problem, the Vista UI was trying very hard to hide all networking information from me.  The best it can muster is this insult to my networking abilities:

image

Why? This is all you have for me Vista, I ask?  I want to see random Matrix like diagnostic spew and perl scripts scrolling across the screen like in the Hollywood movies.  This will tell me Vista is doing something purposeful.  Maybe next version.

More Posts Next page »
Page view tracker