Welcome to MSDN Blogs Sign in | Join | Help

La bodeguita de Nacho

SQL Server Troubleshooting Stories - "y una ración de bravas"
TMP/TEMP/USERPROFILE environment variables: the closer they point to, the better

One recent discovery I wanted to eventually share here. Many more programs than you would expect, store information in temporary files. If you configure your environment so that those temporary files get created in a remote location, you will suffer the painful performance effect.

I had no idea this worked this way behind the scenes.

When we run a query from SSMS and the results are presented in a grid (Query -> Results To -> Results To Grid), every row we receive from the server, we serialize it to a temporary file on disk, and when results have been received completely from the SQL Server instance, then SSMS maps those results to as many grids as resultsets were received. Eventually, you could receive an error like “An error occurred while executing batch. Error message is: There is not enough space on the disk”, if the disk where the file was located runs out of space in the middle of the query execution.

To avoid the problem, either make some room so that the whole resultset fits in the disk pointed by the buffer returned by GetTempPath, or change your environment variable TMP to point to a volume where you have plenty of room. After changing the environment variable, you have to restart SSMS so that the change takes effect. That’s because the PEB (process environment block) of the existing process doesn’t get updated every time you change, delete or add an environment variable.

It's also worth mentioning that this could even cause performance problems if the Temp path is located on a remote share whose response time is slow.

I ran a test to proof that. I ran a select * from a one char(10) column table filled with 110681 rows. I changed my relevant environment variables so that GetTempPath returns \\farawayhost\share\IALONSO a remote path in Texas (I'm located in Madrid). As you can see below, it takes quite a few hops and a reasonable amount of time for my packets to get there (Madrid-London-Redmond-Irving) :-)

Following are the different scenarios and performance results:

1) With Results To Text (no matter what GetTempPath returns), it completes in less than one second.

2) With Results To Grid, with GetTempPath returning \\farawayhost\share\IALONSO, it completes only after 57 seconds.

3) With Results To Grid, with GetTempPath returning C:\Users\IALONS~1.EUR\AppData\Local\Temp, it completes in one second.

Notice the effect on performance can be very important. The longer SSMS takes consuming the rows returned from the server, the longer it takes for the server to release the resources it has locked to satisfy the query.

 

Following is some data I collected while understanding how this worked, and while running the performance test:

 

Output from tracert to the host where I had decided to point my TMP variable to:

Tracing route to FARAWAYHOST

over a maximum of 30 hops:

  1     2 ms     2 ms     2 ms  MADRID-1.network.microsoft.com

  2     2 ms     1 ms     1 ms  MADRID-2.network.microsoft.com

  3    26 ms    26 ms    25 ms  LONDON-1.network.microsoft.com

  4   228 ms   228 ms   227 ms  REDMOND-1.network.microsoft.com

  5   311 ms   227 ms   227 ms  REDMOND-2.network.microsoft.com

  6   230 ms   229 ms   227 ms  REDMOND-3.network.microsoft.com

  7   294 ms   293 ms   293 ms  IRVING-1.network.microsoft.com

  8   292 ms   292 ms   291 ms  IRVING-2.network.microsoft.com

  9   292 ms   291 ms   291 ms  IRVING-3.network.microsoft.com

10   292 ms   291 ms   292 ms  FARAWAYHOST.northamerica.corp.microsoft.com

Trace complete.

 

Managed stack of the thread which is creating that temporary spool used by the Results to Grid functionality.

0:003> !clrstack

OS Thread Id: 0x1690 (3)

ESP       EIP    

08bbefe0 764fcfaa [NDirectMethodFrameSlim: 08bbefe0] Microsoft.Win32.Win32Native.GetTempPath(Int32, System.Text.StringBuilder)

08bbeff0 793b5c0b System.IO.Path.GetTempPath()

08bbf004 793b5b39 System.IO.Path.GetTempFileName()

08bbf018 09465031 Microsoft.SqlServer.Management.UI.Grid.DiskDataStorage.InitStorage(System.Data.IDataReader)

08bbf028 094644fd Microsoft.SqlServer.Management.QueryExecution.QEResultSet.Initialize(Boolean)

08bbf064 09464314 Microsoft.SqlServer.Management.QueryExecution.ResultsToGridBatchConsumer.OnNewResultSet(System.Object, Microsoft.SqlServer.Management.QueryExecution.QESQLBatchNewResultSetEventArgs)

08bbf094 0946415e Microsoft.SqlServer.Management.QueryExecution.QESQLBatch.ProcessResultSet(System.Data.IDataReader)

08bbf0f4 09463ca9 Microsoft.SqlServer.Management.QueryExecution.QESQLBatch.DoBatchExecution(System.Data.IDbConnection, System.String)

08bbf170 0946390f Microsoft.SqlServer.Management.QueryExecution.QESQLBatch.Execute(System.Data.IDbConnection, Microsoft.SqlServer.Management.QueryExecution.QESQLBatchSpecialAction)

08bbf1ac 094636a4 Microsoft.SqlServer.Management.QueryExecution.QEOLESQLExec.DoBatchExecution(Microsoft.SqlServer.Management.QueryExecution.QESQLBatch)

08bbf1f0 09463357 Microsoft.SqlServer.Management.QueryExecution.QESQLExec.ExecuteBatchCommon(System.String, Microsoft.SqlServer.Management.QueryExecution.ITextSpan, Boolean ByRef)

08bbf238 09463154 Microsoft.SqlServer.Management.QueryExecution.QEOLESQLExec.ExecuteBatchHelper(System.String, Int32, Int32)

08bbf268 0946300e Microsoft.SqlServer.Management.QueryExecution.QEOLESQLExec.ProcessBatch(System.String, Int32)

08bbf27c 08536faf <Module>.BatchParser.ThunkCommandExecuter.ProcessBatch(BatchParser.ThunkCommandExecuter*, UInt16*, Int32)

08bbf308 033df418 [PInvokeCalliFrame: 08bbf308]

08bbf320 08536a75 <Module>.BatchParser.ExecutionContext.ProcessWhatsLeftInBatch(BatchParser.ExecutionContext*)

08bbf374 08532b2e <Module>.BatchParser.BatchParserInternal.Parse(BatchParser.BatchParserInternal*, BatchParser.ParserState*, Boolean)

08bbf40c 085329ca ManagedBatchParser.Parser.Parse()

08bbf630 09462e5c Microsoft.SqlServer.Management.QueryExecution.QEOLESQLExec.DoScriptExecution(Microsoft.SqlServer.Management.QueryExecution.ITextSpan)

08bbf65c 09461a1b Microsoft.SqlServer.Management.QueryExecution.QESQLExec.StartExecuting()

08bbf694 793b0d1f System.Threading.ThreadHelper.ThreadStart_Context(System.Object)

08bbf69c 79373ecd System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)

08bbf6b4 793b0c68 System.Threading.ThreadHelper.ThreadStart()

 

Managed stack of a thread serializing one row to the temporary file.

0:003> g;!clrstack

Breakpoint 4 hit

OS Thread Id: 0x1690 (3)

ESP       EIP    

08bbeea0 764f24b5 [NDirectMethodFrameStandaloneCleanup: 08bbeea0] Microsoft.Win32.Win32Native.WriteFile(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte*, Int32, Int32 ByRef, IntPtr)

08bbeebc 79398282 System.IO.FileStream.WriteFileNative(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte[], Int32, Int32, System.Threading.NativeOverlapped*, Int32 ByRef)

08bbeef0 793982f3 System.IO.FileStream.WriteCore(Byte[], Int32, Int32)

08bbef10 79398343 System.IO.FileStream.FlushWrite(Boolean)

08bbef1c 793a8058 System.IO.FileStream.Flush()

08bbef24 0946cfc0 Microsoft.SqlServer.Management.UI.Grid.FileStreamWrapper.FlushBuffer()

08bbef30 0946cf6d Microsoft.SqlServer.Management.UI.Grid.FileStreamWriter.FlushBuffer()

08bbef34 0946c6cc Microsoft.SqlServer.Management.UI.Grid.DiskDataStorage.SerializeData()

08bbf018 0946b18a Microsoft.SqlServer.Management.QueryExecution.QEDiskDataStorage.SerializeData()

08bbf04c 0946b138 Microsoft.SqlServer.Management.QueryExecution.QEDiskDataStorage.StartStoringData()

08bbf054 0946ae19 Microsoft.SqlServer.Management.QueryExecution.QEResultSet.StartRetrievingData(Int32, Int32)

08bbf064 09464366 Microsoft.SqlServer.Management.QueryExecution.ResultsToGridBatchConsumer.OnNewResultSet(System.Object, Microsoft.SqlServer.Management.QueryExecution.QESQLBatchNewResultSetEventArgs)

08bbf094 0946415e Microsoft.SqlServer.Management.QueryExecution.QESQLBatch.ProcessResultSet(System.Data.IDataReader)

08bbf0f4 09463ca9 Microsoft.SqlServer.Management.QueryExecution.QESQLBatch.DoBatchExecution(System.Data.IDbConnection, System.String)

08bbf170 0946390f Microsoft.SqlServer.Management.QueryExecution.QESQLBatch.Execute(System.Data.IDbConnection, Microsoft.SqlServer.Management.QueryExecution.QESQLBatchSpecialAction)

08bbf1ac 094636a4 Microsoft.SqlServer.Management.QueryExecution.QEOLESQLExec.DoBatchExecution(Microsoft.SqlServer.Management.QueryExecution.QESQLBatch)

08bbf1f0 09463357 Microsoft.SqlServer.Management.QueryExecution.QESQLExec.ExecuteBatchCommon(System.String, Microsoft.SqlServer.Management.QueryExecution.ITextSpan, Boolean ByRef)

08bbf238 09463154 Microsoft.SqlServer.Management.QueryExecution.QEOLESQLExec.ExecuteBatchHelper(System.String, Int32, Int32)

08bbf268 0946300e Microsoft.SqlServer.Management.QueryExecution.QEOLESQLExec.ProcessBatch(System.String, Int32)

08bbf27c 08536faf <Module>.BatchParser.ThunkCommandExecuter.ProcessBatch(BatchParser.ThunkCommandExecuter*, UInt16*, Int32)

08bbf308 033df418 [PInvokeCalliFrame: 08bbf308]

08bbf320 08536a75 <Module>.BatchParser.ExecutionContext.ProcessWhatsLeftInBatch(BatchParser.ExecutionContext*)

08bbf374 08532b2e <Module>.BatchParser.BatchParserInternal.Parse(BatchParser.BatchParserInternal*, BatchParser.ParserState*, Boolean)

08bbf40c 085329ca ManagedBatchParser.Parser.Parse()

08bbf630 09462e5c Microsoft.SqlServer.Management.QueryExecution.QEOLESQLExec.DoScriptExecution(Microsoft.SqlServer.Management.QueryExecution.ITextSpan)

08bbf65c 09461a1b Microsoft.SqlServer.Management.QueryExecution.QESQLExec.StartExecuting()

08bbf694 793b0d1f System.Threading.ThreadHelper.ThreadStart_Context(System.Object)

08bbf69c 79373ecd System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)

08bbf6b4 793b0c68 System.Threading.ThreadHelper.ThreadStart()

 

We use System.IO.Path.GetTempFileName to initialize the file name (and location) of that temp file, which uses System.IO.Path.GetTempPath:

public static string GetTempFileName()

{

    string tempPath = GetTempPath();

    new FileIOPermission(FileIOPermissionAccess.Write, tempPath).Demand();

    StringBuilder tmpFileName = new StringBuilder(260);

    if (Win32Native.GetTempFileName(tempPath, "tmp", 0, tmpFileName) == 0)

    {

        __Error.WinIOError();

    }

    return tmpFileName.ToString();

}

System.IO.Path.GetTempPath uses the native API GetTempPath:

public static string GetTempPath()

{

    new EnvironmentPermission(PermissionState.Unrestricted).Demand();

    StringBuilder buffer = new StringBuilder(260);

    uint tempPath = Win32Native.GetTempPath(260, buffer);

    string path = buffer.ToString();

    if (tempPath == 0)

    {

        __Error.WinIOError();

    }

    return GetFullPathInternal(path);

}

Next week (Tue 26th/Wed 27th), you cannot miss it! See you at Microsoft TechDays {The Evolution Show} in Madrid

I'll be there, morning to evening, both days (26th and 27th) responsible for an area we have called "Rincón técnico de SQL Server" (SQL Server Technical Corner) where "Ask The Expert" sessions will be running virtually non-stop.

I'll also be participating in a few sessions. One of them (26th @ 12:30 AM in the Expo Autitorium) where a panel of SQL Server technology experts will be answering all those interesting questions which I'm sure you, the audience, will bring with and ask that day. A second session (26th @ 4:00 PM in the Expo Auditorium) I'll be delivering about how can you accomplish a painless upgrade to SQL Server 2008. The last formal session I'll be presenting (26th @ 4:25 PM in the Expo Auditorium) is about performance optimization and improvements introduced with SQL Server 2008.

For the remaining of the event, I'll spend most of the time around the SQL Server Ask The Experts zone, where my co-workers from SQL Server support will be delivering in-depth chat talks on very interesting and specific topics like: backup compression, table/index partitioning, Reporting Services improvements, Performance Data Collector, Best Design Practices for RS reports, troubleshooting most typical Kerberos authentication/delegation issues, learning from accumulated experience on the top 10 issues encountered when using VS TFS (Visual Studio Team Foundation Server), etc.

So, whether you want to come and join us in these pre-defined sessions or simply want to approach us to and bring us your experience with the product and invaluable feedback, you'll be more than welcome.

Further information about this fantastic event you can find on this page (content only available in Spanish).

I'm looking forward to meet you all next week!

What does it mean that BACKUP TABLE / RESTORE TABLE are not "yet" implemented?

Say you are one of those users who have been using SQL Server since 6.x days. And say you remember that in those versions there was the possibility to backup or restore a single table. Let's try hard to imagine your memory is good enough to be able to recall the exact syntax you used to accomplish that task. And finally, let's also imagine you're a perseverant person who has been testing it on every new major version of SQL Server released since 7.0, to only confirm whether it was supported again, finally dropped off or still in "not yet implemented" status. :-)

Well, coincidentally I know somebody who is a Microsoft MVP and works in Solid and accumulates all those attributes, and this person asked me to investigate why SQL Server continues raising a 3015 exception, after nine years since those four major releases (7.0, 8.0, 9.0 and almost 10.0) have seen the light.

The point is that if you attempt running either of the following two TSQL statements:

BACKUP TABLE ThisTable TO DISK = 'c:\dummy.bak'

GO

RESTORE TABLE ThisTable FROM DISK = 'c:\dummy.bak'

you get the following errors, respectively, back from the server:

Msg 3015, Level 16, State 4, Line 1
BACKUP TABLE is not yet implemented.

Msg 3015, Level 16, State 3, Line 1
RESTORE TABLE is not yet implemented.

It happens that starting with SQL Server 7.0 SQL Server's T-SQL syntactic parser/analyzer continues accepting the BACKUP TABLE / RESTORE TABLE syntax, and we create specific command nodes in the query tree for those two statements, which we even compile to specialized compiled statement classes. But, in the end, when the relational engine invokes the actual execution of the compiled statement, there is no code implementation in there apart from the raising of the 3015 exception.

I approached the PMs in the Relational Engine team to see what were the future plans around this area, and it happens there are no plans to implement this. In fact, I've just filed a Work Item for somebody to finally remove that code in a future release and simply consider those two constructs syntactically incorrect.

Was this post helpful, I'm hundred percent positive it was not, but I hope it was, at least, entertaining. :-)

I just had to re-publish a previous post because I had made an important mistake

In red I highlighted the changes I've introduced to explain what was wrong in the original version of A tale about solving "Cannot generate SSPI context" and later "[DBNETLIB][ConnectionRead(recv()).] General network error. Check your network documentation" in a shot

Sorry for any inconveniences this mistake could have caused.

A tale about solving "Cannot generate SSPI context" and later "[DBNETLIB][ConnectionRead(recv()).] General network error. Check your network documentation" in a shot

I had a customer who was receiving the "Cannot generate SSPI context error" when one, and only one, of his users with a specific domain account tried to log into a SQL Server 2005 using TCP network library and Windows Authentication. It ended up being caused by the fact that the default MaxTokenSize of 12,000 set in the workstation from where he was trying to connect to SQL wasn't big enough to hold the kerberos token generated during authentication because he belonged to many Windows security groups, as explained in KB327825. We solved that one out by finding (with the help of tokensz.exe) what was the minimum size we needed to set MaxTokenSize so that the preallocated buffer could hold the complete token of this particular user account.

After we created the MaxTokenSize DWORD under HKEY_LOCAL_MACHINE\System\CurrentControlSet\Control\Lsa\Kerberos\Parameters and we set it to 13,500 (our user token was 13,336 bytes long), we rebooted the client machine for the change to take effect, and on the next connection attempt after reboot, it began failing with "[DBNETLIB][ConnectionRead(recv()).] General network error. Check your network documentation".

This time, we went to the server searching for any information that could be related to this error on the client side, and found the following error reported in ERRORLOG, every time the client had tried to connect:

17828 - The prelogin packet used to open the connection is structurally invalid; the connection has been closed. Please contact the vendor of the client library.%.*ls

Re-publishing this blog to correct a mistake I made here. We don't report error 17828 mentioned above, but this one instead:

17832 - The login packet used to open the connection is structurally invalid; the connection has been closed. Please contact the vendor of the client library.%.*ls

After further code analysis on the server side, I discovered the server network library was limiting the maximum token size that would be accepted from a client to the MaxTokenSize set in the server box where SQL Server was running. Since it was a Windows Server 2003 + SP2 and it hadn't been explicitly specified, it was using the default value of 12,000. Since, during the PreLoginHandshake phase, this particular client was presenting us with a token larger than that size, SQL Server considers the packet is invalid and reports that error mentioned above.

So, to solve this second issue, we had to explicitly set the MaxTokenSize setting on the server to 13,500 and reboot the box as well. Why 13,500, because we knew SQL Server could now receive login attempts from clients which could present him a token as big as that.

Hope it helps somebody to solve these two issues.

While troubleshooting this issue, I also found interesting reading Addressing Problems Due To Access Token Limitation.

How an apparently innocent antivirus could kill your SSIS package performance?

Interesting story this one. I've been working with a customer who had a very simple package which consisted of a Sequence Container including an Execute SQL Task (which truncates the destination table) followed by a Data Flow Task. The Data Flow Task contained an OLE DB Source (a SQL Server 2000) and an OLE DB Destination (a SQL Server 2005). When the package was run from either of the two 64-bit boxes which were part of a cluster they had, it took over 80 minutes for the package to complete, while when it was run from other boxes in their infrastructure (no matter whether they were 32-bit or 64-bit boxes) it finished moving the same data across the two OLE DB endpoints in no more than 300 seconds.

It happened that an internal component of SSIS execution pipeline which is the Buffer Manager, allocates memory where it will later copy the input rows, but when it comes to storing BLOB (image, text or ntext) columns in those buffers, it normally ends up spooling those BLOBs to external temporary files, which then releases (i.e. close the file and automatically delete it since it was created with the FILE_FLAG_DELETE_ON_CLOSE flag) when the buffer containing the rows is also released.

The point here was that this customer had installed a well known antivirus software and he had enabled the On Access Scan feature (sort of real time scanning) which was introduce the huge delay that in the end summed up the big resulting difference.

The typical stack you would see in a case like this, every time you break DTEXEC.exe execution would look like this:

0:017> kL
Child-SP          RetAddr           Call Site
00000000`1e34fc68 00000000`77d6e314 ntdll!NtClose+0xa
00000000`1e34fc70 00000000`2359d623 kernel32!CloseHandle+0x5f
00000000`1e34fca0 00000000`2359bfe9 DTSPipeline!CInMemBuffer::ReleaseBLOBDescriptors+0xd3
00000000`1e34fcf0 00000000`23591357 DTSPipeline!CInMemBuffer::ReleaseMemory+0x69
00000000`1e34fd20 00000000`2359c2b1 DTSPipeline!CDTSBufferManager::RemoveBuffer+0xf7
00000000`1e34fdc0 00000000`235c37a4 DTSPipeline!CInMemBuffer::Release+0x31
00000000`1e34fdf0 00000000`235be7b0 DTSPipeline!CWorkThread::DoInputLoop+0x424
00000000`1e34fef0 00000000`781337a7 DTSPipeline!CWorkThread::ThreadProcedure+0x70
00000000`1e34ff20 00000000`78133864 msvcr80!_callthreadstartex+0x17
00000000`1e34ff50 00000000`77d6b6da msvcr80!_threadstartex+0x84
00000000`1e34ff80 00000000`00000000 kernel32!BaseThreadStart+0x3a

As you can see, it's stuck trying to close the handle to the temporary file used to spool the BLOB data for a given row.

So, we tested it after having disabled On Access Scan and it worked like a champ. Customer had heard this was a known issue with that particular build of the antivirus in x64. Meanwhile, before the AV manufacturer could provide them with a long term solution, they could exclude from the AV realtime analysis the directory where these files were created, which you can specify by using the BLOBTempStoragePath property.

That was it, after a long time not having showed around here.

SQL Server performance counters' library improvement

It seems Cumulative Update 6 (due in mid Feb 08) for SQL Server 2005 Service Pack 2 will include a code change so that performance counters show current performance values while the service is running, no matter what the service state was when perfmon was initially started up. The effect of that original design I explained in this previous post.

SQL Server performance counters DLL works in two modes: static and server interaction. Static meaning that the DLL cannot communicate with SQL Server (because the service is stopped). In this mode, we only show counter names but all counter values are set to zero. Server interaction mode is the mode where the library can communicate with SQL Server (because it is up and running). In build before CU6, the DLL behaved so that in static mode it wasn't able to recover and switch to server interaction mode. The workaround, as explained in the previous post described above, was to restart Perfmon. Hopefully, starting with CU6, that workaround won't be required any longer, since it will be able to dynamically switch between static and server mode.

Cheers,
Nacho

Good News!

I've just discovered that Cumulative Update 6 (due in mid Feb 08) for SQL Server 2005 Service Pack 2 will include a fix for the Analysis Services Redirector reliability issue I explained in my previous post.

How to rebuild your master database in MSDE when it became corrupted?

Let's imagine that your instance of MSDE cannot be brought online because of any reason, like when your master database became corrupted or the their files are unavailable. Under such circumstances, if you try to rebuild the master database with a command line similar to this one

setup INSTANCENAME="MYINSTANCE" SAPWD="mySAPWd" REINSTALL=ALL REINSTALLMODE=a /I Setup\SqlRun01.msi /L*v c:\FailingAttempt.log

 

the setup it will appear to be hung for a while, you will notice that the ERRORLOG files for that instance cycles twice and that it shows some sort of severe error which prevented the SQL Server service to come online:

 

2008-01-16 14:26:34.53 server    Microsoft SQL Server  2000 - 8.00.760 (Intel X86)
    Dec 17 2002 14:22:05
    Copyright (c) 1988-2003 Microsoft Corporation
    Desktop Engine on Windows NT 5.2 (Build 3790: Service Pack 2)

2008-01-16 14:26:34.55 server    Copyright (C) 1988-2002 Microsoft Corporation.
2008-01-16 14:26:34.55 server    All rights reserved.
2008-01-16 14:26:34.55 server    Server Process ID is 900.
2008-01-16 14:26:34.55 server    Logging SQL Server messages in file 'C:\Program Files\Microsoft SQL Server\MSSQL$MYINSTANCE\LOG\ERRORLOG'.
2008-01-16 14:26:34.55 server    initconfig: Error 2(The system cannot find the file specified.) opening 'C:\Program Files\Microsoft SQL Server\MSSQL$MYINSTANCE\Data\master.mdf' for configuration information.

 

If, after the installation finally fails, you open the Windows Installer log (c:\FailingAttempt.log) you specified in the previous command line you wanted to obtain, you will notice that setup tried to run one Windows Installer Custom Action called UpgDetectBlankSaLogin and it failed to connect because SQL service wasn't running (see the information marked in red below):

 

=== Verbose logging started: 1/16/2008  14:26:18  Build type: SHIP UNICODE 3.01.4000.4042  Calling process: C:\WINDOWS\system32\msiexec.exe ===
MSI (c) (5C:F4) [14:26:18:785]: Resetting cached policy values
MSI (c) (5C:F4) [14:26:18:785]: Machine policy value 'Debug' is 0
MSI (c) (5C:F4) [14:26:18:785]: ******* RunEngine:
           ******* Product: Setup\SqlRun01.msi
           ******* Action:
           ******* CommandLine: **********
MSI (c) (5C:F4) [14:26:18:815]: Machine policy value 'DisableUserInstalls' is 0
MSI (c) (5C:F4) [14:26:18:875]: Cloaking enabled.
MSI (c) (5C:F4) [14:26:18:875]: Attempting to enable all disabled priveleges before calling Install on Server
MSI (c) (5C:F4) [14:26:18:875]: End dialog not enabled
MSI (c) (5C:F4) [14:26:18:875]: Original package ==> D:\MSDERelA\Setup\SqlRun01.msi
MSI (c) (5C:F4) [14:26:18:875]: Package we're running from ==> C:\WINDOWS\Installer\7ee98.msi
MSI (c) (5C:F4) [14:26:18:885]: APPCOMPAT: looking for appcompat database entry with ProductCode '{E09B48B5-E141-427A-AB0C-D3605127224A}'.
MSI (c) (5C:F4) [14:26:18:885]: APPCOMPAT: no matching ProductCode found in database.
MSI (c) (5C:F4) [14:26:18:895]: MSCOREE not loaded loading copy from system32
MSI (c) (5C:F4) [14:26:18:925]: Note: 1: 2205 2:  3: MsiFileHash
MSI (c) (5C:F4) [14:26:18:925]: Machine policy value 'DisablePatch' is 0
MSI (c) (5C:F4) [14:26:18:925]: Machine policy value 'AllowLockdownPatch' is 0
MSI (c) (5C:F4) [14:26:18:925]: Machine policy value 'DisableLUAPatching' is 0
MSI (c) (5C:F4) [14:26:18:925]: Machine policy value 'DisableFlyWeightPatching' is 0
MSI (c) (5C:F4) [14:26:18:925]: APPCOMPAT: looking for appcompat database entry with ProductCode '{E09B48B5-E141-427A-AB0C-D3605127224A}'.
MSI (c) (5C:F4) [14:26:18:925]: APPCOMPAT: no matching ProductCode found in database.
MSI (c) (5C:F4) [14:26:18:925]: Transforms are not secure.
MSI (c) (5C:F4) [14:26:18:925]: Note: 1: 2262 2: Control 3: -2147287038
MSI (c) (5C:F4) [14:26:18:925]: Command Line: INSTANCENAME=MYINSTANCE SA...
MSI (c) (5C:F4) [14:26:18:925]: PROPERTY CHANGE: Adding PackageCode property. Its value is '{D29DCF7A-8199-4373-BA0D-2F3635EC940C}'.
MSI (c) (5C:F4) [14:26:18:925]: Product Code passed to Engine.Initialize:           '{E09B48B5-E141-427A-AB0C-D3605127224A}'
MSI (c) (5C:F4) [14:26:18:925]: Product Code from property table before transforms: '{E09B48B5-E141-427A-AB0C-D3605127224A}'
MSI (c) (5C:F4) [14:26:18:925]: Product Code from property table after transforms:  '{E09B48B5-E141-427A-AB0C-D3605127224A}'
MSI (c) (5C:F4) [14:26:18:925]: Product registered: entering maintenance mode
MSI (c) (5C:F4) [14:26:18:925]: PROPERTY CHANGE: Adding ProductState property. Its value is '5'.
MSI (c) (5C:F4) [14:26:18:925]: PROPERTY CHANGE: Adding ProductToBeRegistered property. Its value is '1'.
.
.
.
Starting custom action UpgDetectBlankSaLogin()
Entering Function MyMsiEvaluateCondition
MsiEvaluateCondition for VersionNT returned TRUE
End Function MyMsiEvaluateCondition
Unable to connect as the SQL service is not running.
.
.
.

 

It happens that since SP3, the MSDE setup incorporated that custom action which would try to detect if the password for the SA login was blank and if that would be the case, then it would fail straight away. So, in order to rebuild your system database setup had to detect if the password for SA was blank, and to be able to complete such check the service had to be healthy enough as to come online. Then, how could you leave this endless loop?

Well, it happens that another Windows Installer property was also implemented to make this possible. Its external name is BLANKSAPWD and you must set it to 1 if you want that detection to be skipped. Therefore, the following command line would allow you to successfully rebuild the system database when it was corrupted or unavailable:

setup BlankSAPwd=1 INSTANCENAME="MYINSTANCE" SAPWD="mySAPWd" REINSTALL=ALL REINSTALLMODE=a /I Setup\SqlRun01.msi /L*v c:\WorkingAttempt.log

 

And the newly generated Windows Installer log would show this new information in it:

 

=== Verbose logging started: 1/16/2008  14:38:53  Build type: SHIP UNICODE 3.01.4000.4042  Calling process: C:\WINDOWS\system32\msiexec.exe ===
MSI (c) (90:D0) [14:38:53:971]: Resetting cached policy values
MSI (c) (90:D0) [14:38:53:971]: Machine policy value 'Debug' is 0
MSI (c) (90:D0) [14:38:53:971]: ******* RunEngine:
           ******* Product: Setup\SqlRun01.msi
           ******* Action:
           ******* CommandLine: **********
MSI (c) (90:D0) [14:38:54:001]: Machine policy value 'DisableUserInstalls' is 0
MSI (c) (90:D0) [14:38:54:011]: Cloaking enabled.
MSI (c) (90:D0) [14:38:54:011]: Attempting to enable all disabled priveleges before calling Install on Server
MSI (c) (90:D0) [14:38:54:021]: End dialog not enabled
MSI (c) (90:D0) [14:38:54:021]: Original package ==> D:\MSDERelA\Setup\SqlRun01.msi
MSI (c) (90:D0) [14:38:54:021]: Package we're running from ==> C:\WINDOWS\Installer\7ee98.msi
MSI (c) (90:D0) [14:38:54:041]: APPCOMPAT: looking for appcompat database entry with ProductCode '{E09B48B5-E141-427A-AB0C-D3605127224A}'.
MSI (c) (90:D0) [14:38:54:041]: APPCOMPAT: no matching ProductCode found in database.
MSI (c) (90:D0) [14:38:54:051]: MSCOREE not loaded loading copy from system32
MSI (c) (90:D0) [14:38:54:081]: Note: 1: 2205 2:  3: MsiFileHash
MSI (c) (90:D0) [14:38:54:081]: Machine policy value 'DisablePatch' is 0
MSI (c) (90:D0) [14:38:54:081]: Machine policy value 'AllowLockdownPatch' is 0
MSI (c) (90:D0) [14:38:54:081]: Machine policy value 'DisableLUAPatching' is 0
MSI (c) (90:D0) [14:38:54:081]: Machine policy value 'DisableFlyWeightPatching' is 0
MSI (c) (90:D0) [14:38:54:081]: APPCOMPAT: looking for appcompat database entry with ProductCode '{E09B48B5-E141-427A-AB0C-D3605127224A}'.
MSI (c) (90:D0) [14:38:54:081]: APPCOMPAT: no matching ProductCode found in database.
MSI (c) (90:D0) [14:38:54:081]: Transforms are not secure.
MSI (c) (90:D0) [14:38:54:081]: Note: 1: 2262 2: Control 3: -2147287038
MSI (c) (90:D0) [14:38:54:081]: Command Line: BlankSA...
MSI (c) (90:D0) [14:38:54:081]: PROPERTY CHANGE: Adding PackageCode property. Its value is '{D29DCF7A-8199-4373-BA0D-2F3635EC940C}'.
MSI (c) (90:D0) [14:38:54:081]: Product Code passed to Engine.Initialize:           '{E09B48B5-E141-427A-AB0C-D3605127224A}'
MSI (c) (90:D0) [14:38:54:081]: Product Code from property table before transforms: '{E09B48B5-E141-427A-AB0C-D3605127224A}'
MSI (c) (90:D0) [14:38:54:081]: Product Code from property table after transforms:  '{E09B48B5-E141-427A-AB0C-D3605127224A}'
MSI (c) (90:D0) [14:38:54:081]: Product registered: entering maintenance mode
MSI (c) (90:D0) [14:38:54:081]: PROPERTY CHANGE: Adding ProductState property. Its value is '5'.
MSI (c) (90:D0) [14:38:54:081]: PROPERTY CHANGE: Adding ProductToBeRegistered property. Its value is '1'.
.
.
.
MSI (s) (44:10) [14:40:21:306]: Skipping action: UpgDetectBlankSaLogin.2D02443E_7002_4C0B_ABC9_EAB2C064397B (condition is false)
.
.
.
=== Logging stopped: 1/16/2008  14:41:02 ===
MSI (c) (90:D0) [14:41:02:776]: Note: 1: 1728
MSI (c) (90:D0) [14:41:02:796]: Product: Microsoft SQL Server Desktop Engine -- Configuration completed successfully.

MSI (c) (90:D0) [14:41:02:806]: Grabbed execution mutex.
MSI (c) (90:D0) [14:41:02:806]: Cleaning up uninstalled install packages, if any exist
MSI (c) (90:D0) [14:41:02:806]: MainEngineThread is returning 0
=== Verbose logging stopped: 1/16/2008  14:41:02 ===

 

And that's all about it. Hope it's useful for somebody.

Scared because SQL Server seems to be running a DBCC CHECKDB on some of your databases on every startup?

A colleague approached me yesterday because he was finding the following entry (marked in red below) in his ERRORLOG, and he was worried because he thought the recovery of the ABC database was taking longer because a CHECKDB was run on it during the recovery process:

 

2008-01-15 13:13:04.97 Server      Microsoft SQL Server 2005 - 9.00.3200.00 (X64)
    Oct  2 2007 12:23:02
    Copyright (c) 1988-2005 Microsoft Corporation
    Enterprise Edition (64-bit) on Windows NT 5.2 (Build 3790: Service Pack 2)

2008-01-15 13:13:04.97 Server      (c) 2005 Microsoft Corporation.
2008-01-15 13:13:04.97 Server      All rights reserved.
2008-01-15 13:13:04.97 Server      Server process ID is 5720.
.
.
.
2008-01-15 13:13:10.56 spid16s     Starting up database 'master'.
2008-01-15 13:13:10.65 spid16s     Recovery is writing a checkpoint in database 'master' (1). This is an informational message only. No user action is required.
2008-01-15 13:13:10.75 spid16s     SQL Trace ID 1 was started by login "sa".
2008-01-15 13:13:10.80 spid16s     Starting up database 'mssqlsystemresource'.
2008-01-15 13:13:10.80 spid16s     The resource database build version is 9.00.3200. This is an informational message only. No user action is required.
2008-01-15 13:13:11.00 spid16s     Server name is 'MYSERVER\MYINSTANCE'. This is an informational message only. No user action is required.
2008-01-15 13:13:11.00 spid16s     The NETBIOS name of the local node that is running the server is 'MYSERVER'. This is an informational message only. No user action is required.
2008-01-15 13:13:11.00 spid22s     Starting up database 'model'.
2008-01-15 13:13:11.09 spid22s     Clearing tempdb database.
.
.
.
2008-01-15 13:13:11.23 Server      SQL Server is now ready for client connections. This is an informational message; no user action is required.
2008-01-15 13:13:11.25 spid26s     Starting up database 'msdb'.
2008-01-15 13:13:11.25 spid22s     Starting up database 'tempdb'.
2008-01-15 13:13:11.25 spid25s     Starting up database 'ABC'.
2008-01-15 13:13:11.25 spid30s     Starting up database 'XYZ'.
2008-01-15 13:13:11.25 spid29s     Starting up database 'CAT'.
2008-01-15 13:13:11.25 spid31s     Starting up database 'DataWarehouse'.
2008-01-15 13:13:11.25 spid33s     Starting up database 'Recording'.
2008-01-15 13:13:11.25 spid36s     Starting up database 'FIMD'.
2008-01-15 13:13:11.25 spid28s     Starting up database 'FWCDG'.
2008-01-15 13:13:11.25 spid34s     Starting up database 'Safe'.
2008-01-15 13:13:11.25 spid35s     Starting up database 'General'.
2008-01-15 13:13:11.25 spid27s     Starting up database 'AdministrationDB'.
2008-01-15 13:13:11.26 spid32s     Starting up database 'MKTMaps'.
2008-01-15 13:13:11.28 spid22s     Analysis of database 'tempdb' (2) is 100% complete (approximately 0 seconds remain). This is an informational message only. No user action is required.
2008-01-15 13:13:11.36 spid37s     The Service Broker protocol transport is disabled or not configured.
2008-01-15 13:13:11.36 spid37s     The Database Mirroring protocol transport is disabled or not configured.
2008-01-15 13:13:11.36 spid37s     Service Broker manager has started.
2008-01-15 13:14:47.94 spid25s     CHECKDB for database 'ABC' finished without errors on 2008-01-15 12:09:50.173 (local time). This is an informational message only; no user action is required.
2008-01-15 13:17:08.97 spid16s     Recovery is complete. This is an informational message only. No user action is required.

 

In the header of the primary data file, SQL Server stores a structure containing information about the database. This has been the case in previous versions of the product as well (at least 7.0 and 2000). In SQL Server 2005, that structure extended its fields to include, among others, the date and time of the last time a DBCC CHECKDB was successfully completed against that database.

During database startup, if that field contains a valid date and is not the default construction date ('1900-01-01 00:00:00.000'), then we write informational message 17573 (from sys.messages "CHECKDB for database '%ls' finished without errors on %ls (local time). This is an informational message only; no user action is required.") into ERRORLOG.

If your database is has its autoclose option enabled, the you would see this message every time the database is brought online. Just like this:

2008-01-16 11:39:49.740                                spid51       Starting up database 'ABC'.
2008-01-16 11:39:49.980                                spid51       CHECKDB for database 'ABC' finished without errors on 2008-01-16 11:38:56.793 (local time). This is an informational message only; no user action is required.
2008-01-16 11:44:11.770                                spid92       Starting up database 'ABC'.
2008-01-16 11:44:12.010                                spid92       CHECKDB for database 'ABC' finished without errors on 2008-01-16 11:38:56.793 (local time). This is an informational message only; no user action is required.
2008-01-16 11:44:38.320                                spid65       Starting up database 'ABC'.
2008-01-16 11:44:38.490                                spid65       CHECKDB for database 'ABC' finished without errors on 2008-01-16 11:38:56.793 (local time). This is an informational message only; no user action is required.

This is not the case in Express or Desktop editions. Those editions won't show this message.

That was it for now.

Have a good day!

Conocer el valor de la Edición Enterprise a través de sencillos ejemplos

This is the Spanish version of this other post.

Esta vez sólo deseo anunciar que mi compañero Jorge "George" Pérez Campo y yo mismo tenemos planes para comenzar una serie de artículos con ejemplos simples que demuestren, desde un punto de vista práctico, los enormes beneficios proporcionados por aquellas funciones que están sólo disponible en la Edición Enterprise de SQL Server 2005.

Últimamente, hemos escuchado con más frecuencia a los usuarios decir: “¿Por qué habría de elegir la Edición Enterprise de SQL Server 2005? Por lo que recuerdo de versiones anteriores, el único beneficio de la Edición Enterprise, en comparación con la Estándar, era la posibilidad de instalación en clúster y ahora, con SQL Server 2005, la edición Estándar ya incorpora esta funcionalidad; no necesito “gastar” un dinero extra adquiriendo una licencia de la Edición Enterprise.”

Sinceramente, esta afirmación me deja un tanto descolocado. :-P

En primer lugar, no es cierto que el soporte de clúster fuese la única diferencia entre la versión Estándar y la Enterprise en versiones anteriores. Había mucho más que eso. Pero no comentaremos cuestiones sobre SQL Server 2000 ahora, más de 7 años después de que fuese publicado. Esto no te aportaría demasiado valor. En su lugar, preferimos centrarnos inicialmente en SQL Server 2005 y posiblemente extender el estudio a SQL server 2008 más adelante.

En 2005 hay tanto valor añadido en la Edición Enterprise que preferimos creer que aquellos usuarios que están de acuerdo con el enunciado anterior lo están porque no han recibido la información suficiente acerca del valor del producto, cuáles son sus implicaciones y como pueden ellos beneficiarse realmente de las mismas.

Por esa razón, nos sentimos en la obligación de mostrarte todos estos beneficios, usando ejemplos sencillos y claros, con el ánimo de ayudarte a tomar mejores decisiones en el momento de elegir la edición de SQL Server más apropiada para satisfacer las necesidades de tu negocio.

Permanece atento y no pierdas ninguna de estas entregas si quieres tomar las mejores decisiones. ;-)

Understanding the value of the Enterprise Edition with simple examples

Ésta es la versión en inglés de este otro artículo.

This time I just wanted to announce that my colleague Jorge "George" Pérez Campo and myself have plans to start posting some simple examples to demonstrate, from a practical standpoint, the huge benefits provided by all the features which are only available with the Enterprise Edition of SQL Server 2005.

Recently, we have been, more and more, hearing SQL Server users saying: "Why would I want to choose the Enterprise Edition in SQL Server 2005? It sounds to me that from previous versions of the product, the only benefit I got from the Enterprise edition, compared to the Standard, was that it was cluster aware, and now in SQL Server 2005, the Standard edition also supports failover clustering, therefore I don't need to "waste" any extra money in buying an Enterprise edition license."

To be honest, that assertion knocks me out. :-P

First of all, it isn't true that failover clustering support was the only difference between Standard and Enterprise editions in previous versions. There was much more than that. But we won't touch the SQL Server 2000 topic nowadays, after over seven years since it was released. That wouldn't be of too much value for you. Instead, we prefer to focus in SQL Server 2005 initially, and will possibly extend it to cover SQL Server 2008 as well.

In 2005, there is so much extra value in the Enterprise Edition, that we prefer to believe that those users who agree with the statement above, is just because they haven't really been explained what all that value is, which form it adopts within the product, and how they can actually benefit from it.

For that reason, we feel it's our obligation to show you all these benefits, using simple and clear examples, with the aim of helping you to take better decisions when it comes to choosing the most appropriate edition of SQL Server to satisfy your business requirements.

So, keep tuned and don't miss any of those deliveries if you want to make the best decisions. ;-)

What's special with the BULK provider when loading LOB character columns using OPENROWSET?

This is another problem I've been working on recently, whose resolution I felt could be interesting to share here.

Let's first reproduce the errors, before trying to explain anything. So, please, connect to your instance of SQL Server 2005 and run this:

CREATE DATABASE TestDatabase
GO
USE TestDatabase
GO
CREATE TABLE [dbo].[TestTable] ([TestColumn] nvarchar(max) NULL)
GO

Now, using the DataFile.dat and FormatFile.fmt files compressed in a single zip and attached to this post, run this statement and notice how it works with no error, and it inserts the data available in the .dat file, without any truncation or any error.

BULK INSERT dbo.TestTable FROM 'c:\DataFile.dat'
WITH
(
FORMATFILE = 'c:\FormatFile.fmt'
)

Finally, run the following statement and see how it doesn't work:


INSERT INTO dbo.TestTable
SELECT [TestColumn]
FROM OPENROWSET (BULK 'c:\DataFile.dat',
FORMATFILE = 'c:\FormatFile.fmt')
AS c([TestColumn])

instead of completing successfully, it throws the following errors:

Server: Msg 4866, Level 16, State 7, Line 1
The bulk load failed. The column is too long in the data file for row 1, column 1. Verify that the field terminator and row terminator are specified correctly.
Server: Msg 7399, Level 16, State 1, Line 1
The OLE DB provider "BULK" for linked server "(null)" reported an error. The provider did not give any information about the error.
Server: Msg 7330, Level 16, State 1, Line 1
Cannot fetch a row from OLE DB provider "BULK" for linked server "(null)".

You might also try to import the data using the bcp utility (%programfiles%\Microsoft SQL Server\90\Tools\Binn\bcp.exe) and you will also see that it works fine, as you would expect:

bcp TestDatabase.dbo.TestTable in c:\DataFile.dat -S.\yukon -T -f c:\FormatFile.fmt

My FormatFile.fmt looks like this:

9.0
1
1    SQLNVARCHAR    8       0    "~R~"    1    TestColumn    SQL_Latin1_General_CP1_CI_AS

So, what's the reason why it only fails when using the OPENROWSET clause?

Well, it happens to be caused by the way our syntactic parser is implemented (and its relationship with the relational engine). Let me give you more details about it.

When you issue a BULK INSERT, at parse time, we know what's the name of the table/view where you plan to bulk insert your data into. So, we pass the name of that table to into the constructor of the class which takes care of all the bulk load functionality (i.e. parsing the format file, reading the data from the data file, converting the data if required, etc.) With that information (i.e. the name of the target object), the relational engine can infer the data type, length, scale, precission and the like, of the target columns (all that information is stored by the relational engine - sys.columns). This way, in our example, SQL can infer our target column TestTable.dbo.TestColumn is a wide char BLOB column (nvarchar(max)), and therefore, it assumes that what is being loaded from the data file is a blob and can exceed the limit of 8000 bytes.

With the bcp utility, it's a similar story, but it uses the bcp APIs implemented in the ODBC native driver available in our SQL Native Client library. But, in the end, a similar thing happens: it retrieves the metadata of the target object and based on that information, it accepts source strings that exceed the 8KB limit.

On the other hand, when you issue the INSERT INTO ... SELECT ... FROM OPENROWSET, and the syntactic parser is parsing the OPENROWSET, it doesn't even know, in that context, that the results of the OPENROWSET will be used as the input source of an INSERT, so it cannot infer any metadata from any target object, and it ends up assuming the max length is 8000 bytes (4000 characters for wide char data types like SQLNCHAR and 8000 characters for single byte characters like SQLCHAR).

So... Is there any way around this? Of course there is. :-)

You can specify in your format file max length column any value bigger than 8000 bytes, like this:

9.0
1
1    SQLNVARCHAR    8    8001    "~R~"    1    TestColumn    SQL_Latin1_General_CP1_CI_AS

It's also worth reminding you that, in case you are still using the old-style format files, you should start familiarizing with the new XML format. Sooner than later, the old-style format files will be deprecated and will be replaced by this new format introduced with SQL Server 2005. Using this new format, the format file I used in my previous examples, would look like this:

<?xml version="1.0"?>
<BCPFORMAT xmlns="http://schemas.microsoft.com/sqlserver/2004/bulkload/format" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
<RECORD>
  <FIELD ID="1" xsi:type="NCharPrefix" PREFIX_LENGTH="8" COLLATION="SQL_Latin1_General_CP1_CI_AS"/>
</RECORD>
<ROW>
  <COLUMN SOURCE="1" NAME="TestColumn" xsi:type="SQLNVARCHAR"/>
</ROW>
</BCPFORMAT>

And this one would be the variation which explicitly defines the max length attribute so that it works when used with OPENROWSET:

<?xml version="1.0"?>
<BCPFORMAT xmlns="http://schemas.microsoft.com/sqlserver/2004/bulkload/format" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
<RECORD>
  <FIELD ID="1" xsi:type="NCharPrefix" MAX_LENGTH="8001" PREFIX_LENGTH="8" COLLATION="SQL_Latin1_General_CP1_CI_AS"/>
</RECORD>
<ROW>
  <COLUMN SOURCE="1" NAME="TestColumn" xsi:type="SQLNVARCHAR"/>
</ROW>
</BCPFORMAT>

Hopes this saved you some time.

SQL Server 2005 Service Pack 2 failing to install due to an error in Do_sqlGroupMember custom action

One colleague reported to me that one of his customers was getting the following error message when trying to install SQL Server 2005 Service Pack 2:

Func Name='RestoreSetupParams'>
Failed to find installation media path due to datastore exception
in FindSetupFolder()
MSI (s) (C0!C0) [12:50:39:060]: Note: 1: 2203 2: C:\WINDOWS\system32\Setup\SqlRun.msi 3: -2147287038
Loaded DLL:
C:\Program Files\Microsoft SQL Server\90\Setup Bootstrap\xmlrw.dll
Version:
2.0.3609.0
Failed to find installation media path due to datastore exception
in FindSetupFolder()
Loaded DLL:
C:\Program Files\Microsoft SQL Server\90\Setup Bootstrap\sqlsval.dll
Version:
2005.90.3042.0
Failed to find installation media path due to datastore exception
in FindSetupFolder()
.
.
.
Doing Action: Do_sqlGroupMember
PerfTime Start: Do_sqlGroupMember : Sat Dec 15 12:51:43 2007
<Func Name='Do_sqlGroupMember'>
Local group CLOGIC\SQL Services doesn't exist
Failure adding user
_svcSQL@cl.prvopen.mycorporation.com to local group CLOGIC\SQL Services (2221)
        Error Code: 0x800708ad (2221)
Windows Error Text: The user name could not be found.
  Source File Name: sqlca\sqlsecurityca.cpp
Compiler Timestamp: Sat Oct  7 09:43:41 2006
     Function Name: Do_sqlGroupMember
Source Line Number: 1132

So I went to the source code of our Do_sqlGroupMember custom action, and found that this part of code does the following:

  1. If the computer from where setup is running is not a Domain Controller, it calls NetGetAnyDCName, to try to find the name of one DC on which the security group exists. If none is found, or if the node itself is a DC, one local variable which stores the name of the DC is set to NULL.
  2. Later, we call NetLocalGroupAddMembers API passing it the DC Name we obtained in previous step, the group name (having removed everything that was before the backslash, so it would be "SQL Services" in your case), and the user name you're trying to add to that hypothetically existing local group (_svcSQL@cl.prvopen.mycorporation.com in your case). If this call to NetLocalGroupAddMembers fails with ERROR_NO_SUCH_ALIAS, it means there's no Local group with such name, so we log the following in the setup log file "Local group %s doesn't exist" (which in your case looks like "Local group CLOGIC\SQL Services doesn't exist"). But this message is not really an error, rather it's an informational message.
  3. If the call to NetLocalGroupAddMembers failed with ERROR_NO_SUCH_ALIAS, then we try to add the user to the group as if the group was Global. To do so, we call the NetGroupAddUser API. And that's the one which is failing with NERR_UserNotFound (2221 == The user name could not be found).

Now, reading through the documentation of that API, it explicitly mentions this:

User account names are limited to 20 characters and group names are limited to 256 characters. In addition, account names cannot be terminated by a period and they cannot include commas or any of the following printable characters: ", /, \, [, ], :, |, <, >, +, =, ;, ?, *. Names also cannot include characters in the range 1-31, which are nonprintable.

In your case, _svcSQL@cl.prvopen.mycorporation.com is 36 characters in length, and that's the reason why it fails with that error, because the API is truncating the user name and not finding it.

The user name is taken from the attributes of the SQL Server Service, from the node from where Service Pack 2 setup is run.

We've reviewed the account under which the SQL Server Service was running for this instance, and it was actually set as _svcSQL@cl.prvopen.mycorporation.com. But what was more surprising was that on the other node, it was set using the expected format used by SQL Server Setup when it creates the services in the first place (i.e. CLOGIC\_svcSQL).

I have no way to explain who and when that change was made, but this is definitely something you should investigate, between the people who operates these servers, so that you avoid doing this again in the future.

So, suggested action plan was: change that service account to its correct/original format and retry the installation of Service Pack 2.

After following that action plan, the installation of Service Pack 2 went through with no errors. While we tried to change the service account, we kind of found what could have been the cause of that change. In customer environment, when they tried to set the service account from the Services console (services.msc), if they used the AD Object Browser window, and typed CLOGIC\_svcSQL and then clicked on "Check Names", it resolved it to its fully qualified name, as in _svcSQL@cl.prvopen.mycorporation.com. So, it looks somebody did that operation in the past in customer's environment, and that subtle difference in the format used to name the service account makes SQL Server's Service Pack code fail, because it doesn't expect it to be expressed that way.

The reason why Windows resolves the account name in one or another format I don't know and didn't have the time during that incident to continue investigating. So this, I leave it open for someone with more experience in Windows AD than me, explains in the comments section.

Thanks and enjoy your day!

Is there any way you can execute an SSIS package whose TransactionOption property is set to Required, without having the MSDTC service running?

That was the question one develepment consultant asked me. My initial answer, was what I typically answer when I'm asked any of these questions: "I dunno, but let me check it for you." :-)

After reviewing the source code of SSIS runtime in SQL Server 2005, the answer is: "No, it isn't possible." Even in the case where you're working with a single connection manager and are doing nothing else within the package but working with that connection manager only, your MSDTC must be started.

Once any container has its TransactionOption property set to Required, it either enlists it in an already existing transaction or begins a new distributed transaction, which requires a transaction dispenser object from MSDTC. That  explains why DTC must be started.

Many thanks for reading me!

More Posts Next page »
Page view tracker