The SQL Dude!

On-Disk & In-Memory Pages that teach you the SQL way of life!

Archive for August 3rd, 2011

SQL Server service does not start after enabling SSL encryption

Posted by Sudarshan Narasimhan on August 3, 2011


I recently had a customer who came up to me with a SQL Service start-up issue. This issue started after they had enabled SSL encryption using a personal certificate. Now, before I begin let me confirm a couple of things :-

  1. The correct SSL certificate has been chosen in SQL Configuration Manager.
  2. The ForceEncryption flag is set to Yes.

There are some forum posts on this issue and I don’t entirely agree with the solutions proposed there, because they did not actually solve the real problem but worked around it without understanding how/why the problem occurred, and how to get a complete solution.

http://social.msdn.microsoft.com/Forums/en-US/sqlexpress/thread/b308d9c8-6aba-4b3b-9b32-f919816d1be2/

http://social.msdn.microsoft.com/Forums/en-US/sqldatabaseengine/thread/63c15cb5-0d12-4ea8-bf84-e3ea8a42a866/

I am going to be bold and say this; please do not follow the above posts since they are workarounds. Most people in enterprise environments cannot run SQL Service under the Local System account, which is what the above posts are asking you do to, yikes!!!

As always, the first place to check when a SQL Service does not start is the SQL ERRORLOG (yes, ERRORLOG and NOT the EVENTLOGS – I said 1st place).

For a complete step-by-step guide to approach SQL Service start-up issues, you can read the blog post I wrote on MSDN SQL Server FAQ –> HERE

Here is what I found in the ERRORLOG,

2011-06-08 12:35:30.56 Server Unable to load user-specified certificate [Cert Hash(sha1) “XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX“]. The server will not accept a connection. You should verify that the certificate is correctly installed. See “Configuring Certificate for Use by SSL” in Books Online.

2011-06-08 12:35:30.59 Server Error: 17182, Severity: 16, State: 1.
2010-06-08 12:35:30.59 Server TDSSNIClient initialization failed with error 0x80092004, status code 0x80. Reason: Unable to initialize SSL support. Cannot find object or property.

2011-06-08 12:35:30.62 Server Error: 17182, Severity: 16, State: 1.
2011-06-08 12:35:30.62 Server TDSSNIClient initialization failed with error 0x80092004, status code 0x1. Reason: Initialization failed with an infrastructure error. Check for previous errors. Cannot find object or property.

So, it appears the certificate chosen for SSL encryption has some issues. Here are the things I checked next:-
1. The certificate itself is valid and has not expired (using certmgr.msc).
2. The certificate hash matched that of the certificate associated with the instance but it wasn’t loading.

The certificate appears to be fine. Well, what next?

The way SQL Server loads the certificate happens through the credentials of the SQL Server service account defined for this instance. So, I started to check what the SQLSvc account was and whether it had permissions to access the certificate. At this point I cam across this forum post for a similar issue

http://social.msdn.microsoft.com/Forums/en/sqlexpress/thread/db68b3bf-33a8-42d6-8dac-f7229a2f9cde

The solution listed there was to ensure that the SQL service account had a valid user profile on the server machine. This profile can sometimes be missing if the service account was changed to a new account, which doesn’t yet have a user profile created. You can verify the user profile on any machine by going to
My Computer –> Properties –> Advanced –> Settings (under User Profiles section).

image

Solution #1 (as applicable)

Identify the SQL service account and log on to the server machine that is running SQL Server, with the service account. During logon, Windows will create a new user profile for the service account.

Unfortunately, this wasn’t the scenario in my case. Another thing I have to caution people is regarding service account change. When changing the SQL Svc account ALWAYS ALWAYS use the SQL Server Configuration Manager, and NEVER do it through services.msc. Here are some reasons why:-

1. Permissions & ACL’s of SQL Server registry keys are done only by SSCM
2. SQL Server User Groups are updated with the new service account only by SSCM.
3. WMI namespace permissions are only set through SSCM.

So, if you changed the service account through services.msc, it is possible that the new service account does not have permissions to access the certificate. The certificate hash is stored in the following registry key. If the new service account cannot access it, then you “can” get the error above, since SQL cannot load the certificate due to insufficient privileges.

HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Microsoft SQL Server\MSSQL10.SQL2008\MSSQLServer\SuperSocketNetLib\Certificate

I started to check if this was happening in my case and found that the SQL Service account was not even present in the local group SQLServerMSSQLUser$[Computer_Name]$[Instance_Name]. This confirms that the service account change wasn’t done through SQL Configuration Manager.

This means the SQL Service account does not have permissions to open the private key for the certificate. i.e. SQL Server failed to load this specific certificate due to insufficient permissions. Once we give the service account permission to read the private key, the SQL Server should start up without a problem.

Here is what I did to resolve it,

Solution #2

1. Identify the SQL service account (could be a domain account or any of the built-in accounts like LocalSystem/LocalService/NetworkService).

2. If the service account was set properly using SQL Configuration Manager, then it should have been added to the SQL Security Groups. Look for this on the local machine groups. e.g. SQLServerMSSQLUser$[Computer_Name]$[Instance_Name]

3. Open the Microsoft Management Console (MMC) by click Start -> Run, entering mmc and pressing Enter.

4. Add the Certificates snap-in by clicking File -> Add/Remove Snap-in… and double clicking the Certificates item.

Note:
Select computer account and Local computer in the two pages on the wizard that appears.
Click OK.

5. Expand Certificates (Local Computer) -> Personal -> Certificates and find the SSL certificate you imported or created.

6. Right click on the imported certificate (the one you selected in the SQL Server Configuration Manager) and click All Tasks -> Manage Private Keys.

Note:
You will only see this option for SSL certificates imported from a certifying authority. E.g. you will not see this for EFS, RDP certificates

7. Click the Add button under the Group or user names list box.

8. Enter the SQL service security group that you identified in step #2 and click OK.

You can also directly add the service account itself here, but for any future changes you need to repeat these steps to add that individual account. Instead its better to add the security group, since the service account will always be present here if account change was done using SSCM.

Now, when I started the SQL service you can double-check that the certificate is being loaded and used by looking for this entry in the errorlog. In my case, it started fine and SSL encryption was working.

Open-mouthed smile

2011-06-08 12:48:47.88 Server The certificate [Cert Hash(sha1) “XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX“] was successfully loaded for encryption.


Problem Solved!

Now, to check if the connection is actually encrypted you can use Netmon or Wireshark to check the network packet. Refer to the screenshot posted in this blog on how to do that. An easier way for DBA’s to verify this is to use the DMV sys.dm_exec_connections, look at the encrypt_option column. This DMV also tells you if the connection is using Kerberos/NTLM/SQL Authentication -> auth_scheme column has this value.

Hope this saves you some time.

Advertisement

Posted in Startup | Tagged: , , , , , , , | 19 Comments »

Data Collector (Management Data Warehouse) – Issues, Tips and Solutions

Posted by Sudarshan Narasimhan on August 3, 2011


Somehow I ended up working on data collector issues quite a bit in the last 6 months or so. It’s certainly a useful feature but not an easy one to work with and definitely not an easy one to troubleshoot for you DBA’s. I’m listing down some issues that I faced and solutions for these issues. If you come up with or face any new issues in data collector, please drop a mail to sudarn.

1. Data Collector Upload Job Timeouts

The Data Collector jobs were getting timeout errors on for data upload job ONLY AT THE TIME WHEN PURGE JOB IS RUNNING. You notice that once the purge job completes, the data upload job also starts succeeding, but till that time it simply keeps failing. Here is what you would see in job history for these upload jobs.

02/08/2011 05:25:00,collection_set_3_upload,Error,0,SERVERXYZ\INSTANCEXYZ,collection_set_3_upload,(Job outcome),,The job failed. 
The Job was invoked by Schedule 2 (CollectorSchedule_Every_5min).  The last step to run was step 2 (collection_set_3_upload_upload).,01:00:01,0,0,,,,0

02/08/2011 05:25:00,collection_set_3_upload,Error,2,SERVERXYZ\INSTANCEXYZ,collection_set_3_upload,collection_set_3_upload_upload,,Executed as user: STARWARS\Yoda
The thread "ExecMasterPackage" has timed out 3600 seconds after being signaled to stop.  Process Exit Code 259.  The step failed.,01:00:01,0,0,,,,0

Since we know that the purge job running was the only time when these uploads were failing, we have a simple solution

Solution:
Schedule the purge and upload to run at different schedules. You can use the SSMS UI to define a new schedule for the collection set, just make sure it doesn’t fall under the schedule of the purge job.

 

2. Data Collector Upload Job Deadlocks intermittently

The collection set upload job is running into deadlocks now and then (aka intermittent). This is again related to the purge jobs. Why?

There have been multiple reports of this issue on Connect & MSDN Forums and I’ve had the “pleasure” of talking to customers about this issue. Here are some,

Deadlock in MDW Upload Purge Logs Job Step
http://connect.microsoft.com/SQLServer/feedback/details/539547/deadlock-in-mdw-upload-purge-logs-job-step

Management Data Warehouse Data Collector upload job deadlocks
http://connect.microsoft.com/SQLServer/feedback/details/504557/management-data-warehouse-data-collector-upload-job-deadlocks

Here is a sample output of a failed Upload job that reported the deadlock.

Log Job History (collection_set_3_upload)
Step ID 1
Job Name collection_set_3_upload
Step Name collection_set_3_upload_purge_logs

Message
Executed as user: STARWARS\Yoda. Transaction (Process ID 457) was deadlocked on lock | communication buffer resources with another process and has been chosen as the deadlock victim. Rerun the transaction. [SQLSTATE 40001] (Error 1205). The step failed.

Solution:

Stagger the two collector jobs. E.g. collection_set_2_upload Server Activity and collection_set_3_upload Query Statistics to run a couple of minutes apart. Now, here is a catch! Don’t change the schedule for the SQL Server Agent job, you need to change the schedule using the collector “pick schedule” option in SSMS.

To do this, right click on the collector agent (not the SQL Agent job) select properties and then uploads in the left hand pane. Click on "New" to create a new schedule. If you do it this way you can create two new schedules that are independent of each other.

3. Unable to change/define Schedules for MDW Collection Sets

I did run into another quirky issue when attempting to define a new schedule for the collection sets. i.e I was not able to define a new schedule for this and kept getting this error.

clip_image002[4]

These are the collection sets that are present by default,

  1. Disk Usage
  2. Server Activity
  3. Query Statistics
  4. Utility Information

Of these, the Utility Information is disabled and does not have a schedule defined by default. The reason for the above error was the Collection set “Query Statistics” mentioned above, did not have a valid schedule UID stored. You can confirm this by doing these queries.

1. In the context of MSDB database, run the following query and note down the schedule_uid value for Query Statistics collection set

select * from dbo.syscollector_collection_sets where collection_set_id=3

e.g output. A575FFD0-98A0-4D0E-B43C-B63482FB5B00

2. Again in the MSDB context, run the following,

SELECT schedule_id from sysschedules_localserver_view WHERE ‘XYZ’ = schedule_uid

                — XYZ is the value obtained from step#1. You will see that there is NO value returned for step#2

 

3. As I mentioned, Utility Info has no schedule by default, so we need to use this to get out of this situation. So I used the Utility Information collection set and defined a new schedule for it for every 10 minutes.

4. Next, I queried the schedule_id for this in dbo.syscollector_collection_sets and used this schedule_id to map to the collection set that was failing.

declare @schedule_uid uniqueidentifier

select @schedule_uid = schedule_uid from dbo.syscollector_collection_sets where collection_set_id = 5 – whichever is the Utility Info collection set ID

exec dbo.sp_syscollector_update_collection_set @collection_set_id = 3, @schedule_uid = @schedule_uid — whichever is the Query Statistics collection set ID (change according to the one failing at your end)

 

5. This fixed the issue with Query Stats and I was able to change/define a schedule for that. But, since we created a schedule for Utility Info and you don’t want that to run, I tried to disable it by setting it to “On Demand”. But this failed. Oops!

6. So I enabled the Utility Info collection set and only then did it create a valid job_id for it, but I got another error when trying to remove the schedule.

7. I stopped the collection and then deleted the job manually. To get things back to old state, I updated the metadata using like this,

UPDATE [msdb].[dbo].[syscollector_collection_sets_internal]

SET [collection_job_id] = NULL, [upload_job_id] = NULL

WHERE collection_set_id = 7 – whichever is the Utility Info collection set ID

8. Now, you can stop the Utility Info collection set and also get the other collection sets schedule changed to fix issue #2 mentioned aboveSmile.

 

4. Data Collector Purge Job (Clean-up job) takes a long time to complete

This is actually the root cause of issue #1 and #2 listed above. The purge procedure is complicated and is responsible for cleaning up the metadata tables of old entries. This work is done by the core.sp_purge_data stored procedure. As a troubleshooting step, I captured the execution plan of the procedure and noticed a missing index recommendation in the XML Showplan.

<MissingIndexes>
  <MissingIndexGroup Impact="92.2913">
    <MissingIndex Database="[MDW]" Schema="[snapshots]" Table="[query_stats]">
      <ColumnGroup Usage="EQUALITY">
        <Column Name="[sql_handle]" ColumnId="1" />
      </ColumnGroup>
    </MissingIndex>

If you were to translate this into a CREATE INDEX statement this is how it would look,

CREATE NONCLUSTERED INDEX [Ix_query_stats_sql_handle]

ON [snapshots].[query_stats] ([sql_handle] ASC)

WITH (PAD_INDEX  = OFF, STATISTICS_NORECOMPUTE  = OFF, SORT_IN_TEMPDB = OFF, IGNORE_DUP_KEY = OFF,

DROP_EXISTING = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS  = ON, ALLOW_PAGE_LOCKS  = ON)

ON [PRIMARY]

 

Now, creating this requires modifying the MDW system table and of course this isn’t supported! This same thing is mentioned in this blog as well and is this blog post by the SQL Server Development Team. Don’t do it!  Patience, I will explain.

 

Here are some facts:-

1. Purge job can get slow on large MDW databases (40+ GB).

2. The DELETE TOP statement on snapshots.notable_query_plan is the one where most execution time is spent.

 

 

Solution:

Like I mentioned earlier, don’t modify system Stored Procedure code unless guided by Microsoft Support. Luckily, for the slow purge procedure a fix has been released in SQL Server 2008 R2 Service Pack 1, which can be downloaded here.

 

This fix updates the Purge procedure TSQL code and the purge has been broken down and re-written in an optimized way. The runtime will come down drastically once you update to SP1. The new procedures doing the purge is called “[core].[sp_purge_orphaned_notable_query_plan]” and “[core].[sp_purge_orphaned_notable_query_text]”

 

Hang on, it’s not over yet!

 

 

AFTER you apply SP1, you will need to modify the Stored Procedure sp_purge_orphaned_notable_query_text as shown below. These changes are required to correct the text of the sp_purge_orphaned_notable_query_text stored procedure because the delete statement incorrectly references the snapshots.notable_query_plan table after you apply Service Pack 1.

 

 

SP1 Code

        — Deleting TOP N orphaned rows in query plan table by joining info from temp table variable

        — This is done to speed up delete query.

        DELETE TOP (@delete_batch_size) snapshots.notable_query_plan

        FROM snapshots.notable_query_plan AS qp , #tmp_notable_query_plan AS tmp

        WHERE tmp.[sql_handle] = qp.[sql_handle]

 

Change this to following once you apply SP1

— Deleting TOP N orphaned rows in query text table by joining info from temp table
        — This is done to speed up delete query.
        DELETE TOP (@delete_batch_size) snapshots.notable_query_text 
         FROM snapshots.notable_query_text AS qt, #tmp_notable_query_text AS tmp
        WHERE tmp.[sql_handle] = qt.[sql_handle]

 

Hopefully, this code change will be included in a future cumulative update post-SP1, so that you don’t have to manually change the code. The same applies for SQL Server 2008 as well, where I am hopeful these changes will be included in a future Service Pack. This fix mentioned above is at present once valid for SQL Server 2008 R2 (as of Aug 2, 2011 when I wrote this). With these, the slow purge issues should be put to bed, once and for all!


UPDATE (August 3rd, 2011)
After working with our KB team, we have published an official KB article that talks about this issue. For all those running into slow purge issues, please follow the resolution given in this KB article,

FIX: Data Collector job takes a long time to clear data from a MDW database in SQL Server 2008 R2
http://support.microsoft.com/kb/2584903

 

Other Useful Links

FIX: The Management Data Warehouse database grows very large after you enable the Data Collector feature in SQL Server 2008
http://support.microsoft.com/kb/970014

Data Collector’s sp_purge_data may run for hours if there are many orphaned plans to purge
http://blogs.msdn.com/b/sqlagent/archive/2011/04/12/data-collector-s-sp-purge-data-may-run-for-hours-if-there-are-many-orphaned-plans-to-purge.aspx

Posted in Data Collector | Tagged: , , , , , , | 8 Comments »