CSS SQL Server Engineers

High CPU Troubleshooting with DMV Queries

psssql — Mon, 17 Jun 2013 20:53:00 GMT

High CPU Troubleshooting with DMV Queries

Scenario:

Recently, a customer called Microsoft Support with a critical performance issue that I worked on. Their SQL Server instance had 100% CPU utilization for a period, but the problem stopped without any action taken
by the customer. By the time I was engaged, the issue was no longer occurring. Very often we use PSSDiag to gather data related to performance issues, but we cannot gather trace data with PSSDiag
after the fact. XEvents will also not reveal anything.

PSSDiag will gather other details like top CPU queries that will be useful after the problem has ceased. In this case, we reviewed the execution plans that consumed the most CPU by using DMVs like sys.dm_exec_query_stats.

Troubleshooting:

In my discussion with the customer, he was made aware of the problem and started to investigate it, but the problem seemed to resolve itself. When I was engaged on the call, the issue had been over for 2 hours. I asked if the server had been restarted and found that it had not. This raised the possibility that the execution plan of the queries and procedures that had driven CPU were still in the cache. In that case, we can run queries against sys.dm_exec_query_stats to review those queries and procedures as well as their execution plans.

Sys.dm_exec_query_stats Query:

Here’s an example (and the attached file has the script as well):

--Run the following query to get the TOP 50 cached plans that consumed the most cumulative CPU All times are in microseconds

SELECT TOP 50 qs.creation_time, qs.execution_count, qs.total_worker_time as total_cpu_time, qs.max_worker_time as max_cpu_time, qs.total_elapsed_time, qs.max_elapsed_time, qs.total_logical_reads, qs.max_logical_reads, qs.total_physical_reads, qs.max_physical_reads,t.[text], qp.query_plan, t.dbid, t.objectid, t.encrypted, qs.plan_handle, qs.plan_generation_num FROM sys.dm_exec_query_stats qs CROSS APPLY sys.dm_exec_sql_text(plan_handle) AS t CROSS APPLY sys.dm_exec_query_plan(plan_handle) AS qp ORDER BY qs.total_worker_time DESC

(Please visit the site to view this video)

Many variants of this query can be found which retrieve the stats (reads, CPU, executions) for execution plans from sys.dm_exec_query_stats() and the text of the query from sys.dm_exec_sql_text. To this template, I added sys.dm_exec_query_plan() to also provide the graphical execution plan. This query puts the results in order by total CPU usage.

This is not necessarily an exhaustive list. If a query is recompiled the details for that plan are removed; if there are further executions later, its cumulative stats in sys.dm_exec_query_stats start off at zero. If the procedure cache is flushed or SQL Server is restarted, all plans will be similarly affected.

After running this query with my customer, we saw that there were about five queries that were noticeably higher in total CPU than the rest.

Reviewing Execution Plans:

Once we identified the highest CPU consumers, we started reviewing their execution plan by clicking on the link in our results.** There are a number of items to look for in any execution plan that could indicate where performance can be improved:

High cost operations
Index scans
Multiple executions of scans/seeks
Bookmark Lookups
Operations with very high rowcount
Sort operations
Implicit conversions
Estimated rows/executions that do not match actual rows/executions (which could indicated out of date statistics)

In this case, we found the execution plans for each didn’t have obvious red flags, like expensive scans. So, we reviewed the index seeks with higher costs. We reviewed the queries to see what columns were used in the WHERE and JOIN clauses. Using sp_help against the tables, we looked at the existing indexes and found that the indexes seemed to support these queries relatively well.

Statistics:

Since the indexes appeared to support the queries, I decided to take another step and check statistics on these tables using DBCC SHOWSTATISTICS.

For the first several queries from our high CPU output, we checked the statistics on any indexes that seemed relevant. The most important
parts of the statistics output are the “All Density” value, the “Rows” and
“Rows Sampled” values, and the “Updated” value.

The “Updated” value shows when the statistics were sampled. “Rows” and “Rows Sampled” allows you to determine the sampling rate; a higher sampling rate tends to lead to the statistics being more accurate and providing better performance.

The “All Density” is less direct; inverting this number (dividing 1 by the “All Density”) gives the number of unique values in the column. This is useful in determining how unique an index is, and a more unique index is more likely to be used by the engine to complete a request faster.

What we found in the customer's case was a wide variety of dates for statistics; some were 4 hours old, some were 4 days old, and some were 4 months old. After seeing this repeated on indexes related to several queries, the statistics were updated which resolved the issue.

To Summarize:

Here were the steps we took to analyze and resolve this issue.

Used query against sys.dm_exec_query_stats and sys.dm_exec_sql_text to identify highest CPU consumers
Reviewed the execution plans, identified what drives the cost of the plan and operators that are typically problematic
Reviewed the columns used in JOIN or WHERE clauses in the query, ensured there are indexes built on these columns
Checked the statistics and updated them when we realized they were out of date.

Additional steps to consider in similar cases:

Check the SELECT list and consider if a covering index would further improve performance
Use the cost of plans to compare old and new plans

Tools to help identify performance issues causes and improve performance:

The DatabaseTuning Advisor can use a workload or a specific query to determine if adding or modifying an index can improve the SQL Server’s performance.
A variant of the high CPU query and a number of other queries I use to gather data quickly are available in the Performance Dashboard. This provides a graphical interface to access these queries as reports.

Jared Poché, Sr. Support Escalation Engineer. @jpocheMS

with thanks to Jack Li and Bob Ward

** If clicking on the link in the query opens a window with raw XML, save this data to an .XML file. Change the file extension to .SQLPLAN, then open the file in SQL Server Management Studio to view the graphical plan.

A performance issue involving CLR garbage collection and SQL CPU affinity setting

JackLi — Tue, 11 Jun 2013 21:20:20 GMT

We have been troubleshooting a customer’s case and uncovered a GC behavior with SQL Server CPU affinity that is worth sharing here in a blog.

Problem

Customer reported that they had two instances of SQL Server 2008 running on a two-node cluster. Let’s call them Instance1 and Instance2. When they run both instances on the same node, kicking off a job on Instance1 will cause query timeouts on Instance2. The queries timed out were CLR queries via spatial usage.

The node had plenty of memory for both instances. Each instance had max server memory set. Additionally, Instance1 and Instance2 had CPU affinity set so that they don’t overlap CPU usage.

Analysis

The puzzle here was that Instance2 was negatively impacted by a job run by Instance1 though on the surface it shouldn’t have been. The system had plenty of memory and CPU’s were divided by CPU affinity settings. When Instance1’s job was not running or running on a different node, Instance2 would work perfectly fine.

We captured data such as DMV data, perfmon, userdump etc via pssdiag during problem period (when both instances ran on the same node and Instance1 kicked off the offending job).

In sys.dm_exec_requests, we saw high waits on CLR_MANUAL_EVENT and CLR_CRST for spatial queries which used CLR on Instance1.

From perfmon and userdump, we were able to see the threads were waiting for garbage collection to finish. When the issue occured, time spent by GC was greatly increased.

For a while, we were puzzled why Instance1 would impact Instance2 by increasing it’s GC time spent. The system had plenty of free memory and CPU affinity was set so that two instances didn’t overlap CPU usage.

We did notice that a few CPUs affinitized to Instance1 were pegged to 100% for a long time. Note that these CPUs should not have been used by Instance2 because CPU affinity was set.

One break-through came in when I noticed that number of GC threads seemed to be odd. SQL CLR uses server GC. For each CPU, there will be a CLR heap and GC thread created. What I noticed was that, even Instance1 had 16 CPUs affinitized to it, there were 64 GC threads (customer had 64 CPU on each node). The same was true for Instance2 ( 64 GC threads with affinity set to 30 CPUs).

Here was a little discovery:

When you set CPU affinity on SQL Server, it doesn’t actually set process affinity. Instead the affinity is set at thread creation time to a specific CPU/scheduler. Doing this way will help enable dynamic CPU affinity.

But CLR initializes heaps and GC threads based on process affinity. It will create number of heaps and GC threads depending on the number of CPUs set by process affinity. If no process affinity is set, it will create number of heaps and GC threads based machine CPU.

In other words, even though Instance2 was affinitized (at SQL level) to use CPUs 16-45, some GC threads still run on CPUs 0-15 (where instance1 ran).

This is where ‘interaction’ comes in. Basically the CLR heaps and GC threads are not isolated at all. For example, even CPU 1 was configured for Instance1, there will be one CLR heap and GC thread for Instance2 running on that CPU as well.

Since there were quite a few of CPUs run by Instance1 were pegged, this caused GC threads from Instance2 to fight CPU quantum, leading to increased GC time.

Conclusion & Solution

To summarize, if you have multiple instances of SQL Server on the same machine, garbage collection from one instance may be impacted by another instance even you have CPU affinity set to isolate the instances.

There are a couple of things you can do:

When you examine your system health, look for individual CPU utilization. Any individual CPU pegged to 100% for a sustained period of time, you need to work to bring CPU down. If you have a balanced resource usage, this behavior (GC thread starvation) shouldn’t happen. SQL CLR has been in use since 2005, this is the first time I have seen this behavior.

If you want true isolation, consider use VM (one instance per VM).

A couple of additional notes:

By the way, the same customer also helped uncover a situation Bob Dorr documented it in the blog titled “AppDomain unloading messages flooding the SQL Server error log”

Note that CLR itself has a bug that can cause GC to misbehave. This is fixed in http://support.microsoft.com/default.aspx?scid=kb;EN-US;2504603. This customer was on that build. If you have GC misbehavior, apply this hotfix first before doing additional troubleshooting. That’s maybe all you need.

Jack Li | Senior Escalation Engineer | Microsoft SQL Server Support

Getting a SharePoint List Data Source to work with Reporting Services Native Mode

Adam W. Saxton — Tue, 11 Jun 2013 20:21:45 GMT

A case came up where the user was trying to use Report Builder in a Reporting Services instance that was not integrated with SharePoint. It was in Native Mode configuration. They indicated that they were getting a 401 error. My initial thought was that we were hitting a Kerberos issue. Of note, they were trying to hit a List that was in SharePoint 2013.

SharePoint 2013 is defaulted to use Claims Authentication Sites. So, most would probably ignore the Kerberos aspects of the SharePoint site. I was able to reproduce the issue locally because I had done the same thing.

I created the Data Source within Report Builder to hit my SharePoint 2013 site: http://capthelo/, and when I click on “Test Connection” within the Data Source Dialog Window, I get the following error.

dataextension!ReportServer_0-1!9cc!06/11/2013-14:25:58:: e ERROR: Throwing Microsoft.ReportingServices.DataExtensions.SharePointList.SPDPException: , Microsoft.ReportingServices.DataExtensions.SharePointList.SPDPException: An error occurred when accessing the specified SharePoint list. The connection string might not be valid. Verify that the connection string is correct. ---> System.Net.WebException: The request failed with HTTP status 401: Unauthorized.

This happens because when you click “Test Connection” the connection test is actually performed on the Report Server itself not directly from Report Builder. I had blogged a while back regarding Report Builder and Firewalls where I talk about how some of the items in Report Builder will try to connect direction, but “Test Connection” is not one of them.

At this point, we could ignore the error and hit OK on the Data Source Dialog and try and create a DataSet. When I go to the Query Designer, it appears to have worked. This because the DataSets and Query Designer are coming from Report Builder itself. It is a direct Web Request from the Report Builder Process and not the Report Server, so I don’t get an error.

However, this is misleading. This may make you believe that it is working properly, but when you deploy and try to run the report, you will be back to the 401 error because we are now coming from the Report Server which will be down the same path that the original error with the “Test Connection” had. From the DataSet/Query Designer perspective, this is a straight shot from Report Builder to SharePoint, so we can get away with an NTLM connection for the Web Request and the Windows Credential is valid.

From the Report Server, however, this is called a Double Hop and to forward Windows Credentials you need Kerberos to do that. Even when your SharePoint 2013 site is configured for Claims. This actually has nothing to do with SharePoint, it has everything to do with Reporting Services. The Report Server is the one trying to delegate the Windows Credential to whoever the receiving party is for the Web Request (or SQL Connection if that is your Data Source). In this case, it is SharePoint 2013. Because Kerberos isn’t configured properly, IIS (which is hosting SharePoint), received an anonymous credential for the Web Request and rejects it accordingly with a 401 error.

In my case, I was using a Domain User Account for the RS Service Account (BATTLESTAR\RSService – http://chieftyrol). It had the proper HTTP SPN on it. Also my SharePoint site was using a Domain User account for the AppPool identity within IIS (BATTLESTAR\spservice – http://capthelo) and this had the proper HTTP SPN on it.

So, now I just need to verify the Delegation properties for the RSService Account. Because I’m using the RSService account for other things that includes Claims within SharePoint 2013, I’m forced to Constrained Delegation on this account and need to continue using that. If you are not bound to Constrained Delegation, you could choose the option “Trust this user for delegation to any service (Kerberos Only)” which is considered Full Trust and should correct the issue. If you are using Constrained Delegation, you have to add the proper service that you want to delegate to. In my case that is for my SharePoint site and is http/capthelo.battlestar.local. After I added it, it looked like the following.

Then I restarted the Reporting Services Service and created the Data Source again. At that point, the “Test Connection” returned Success!

Adam W. Saxton | Microsoft Escalation Services
http://twitter.com/awsaxton

How It Works: The I/O Path: SQL Server Running in Windows Azure Virtual Machine (IaaS)

psssql — Mon, 03 Jun 2013 22:11:45 GMT

Note: This blog is based on behavior as of June 2013. At Microsoft we continue to evolve and enhance our products so the behavior may change over time.

The I/O path for SQL Server, running on Windows Azure Virtual Machines, uses Windows Azure storage (often referred to as XStore.) The following is a link to a whitepaper, written by the SQL Server development team, explaining various I/O aspects and tuning needs for this environment:

http://go.microsoft.com/fwlink/?LinkId=306266

I have been testing and driving workloads using SQL Server in our IaaS environment(s). Exercising test patterns from SQLIOSim, T-SQL, Tempdb stress, BCP, and the RML utility test suites. This work has afforded me the opportunity to work closely with both the SQL Server and Windows Azure development teams to better understand how to tune SQL Server for a Windows IaaS deployment.

The previously mentioned white paper points out many of the interactions but I would like to dive into some specific areas to help you understand your Windows Azure IaaS, SQL Server deployment capabilities and options.

Caching

Caching happens at multiple levels (SQL Server, VHD/VHDx, XStore, …). SQL Server requires stable media (data retained across power outages) in order to uphold the ACID properties of the database. It should not surprise you that I spent a fair amount of time understanding the various caches and how SQL Server I/O patterns interact with them from both data safety/stability and performance angles.

SQL Server Data and Log Files: FILE_FLAG_WRITETHROUGH/Forced Unit Access (FUA) Writes

SQL Server does all database and log file writes (including TEMPDB) forcing write though. This means the system is not allowed to return the success of a WriteFile* operation until the system guarantees the data has been stored in stable media. This is regardless of the cache settings at any level of the system. The data must be stored in a cache that is battery backed or written to physical media that will survive a power outage.

SQL Server Backups

When performing a backup SQL Server does NOT set the FILE_FLAG_WRITETHOUGH, instead the backup allows caching of the data to take place. When backup has written all of the data it issues the FlushFileBuffers command on the backup file(s). This acts like FUA in that the FlushFileBuffers must guarantee all data stored in cache has been written to stable media before returning success from the API.

Other Files

There are other files such as the SQL Server error log, BCP output, … that a SQL Server deployment will use. These usually do NOT use FILE_FLAG_WRITETHROUGH nor FlushFileBuffers. This behavior is not unique to Windows IaaS it has been the design and implementation for many releases of the SQL Server product. I am only mentioning this because it can make a difference to you as to where you store the data or leverage various caching mechanisms.

Drive: VHD/VHDx Cache (Drive Caching)

The first level of caching appears at the drive level. Accessing the drive’s properties exposes the drive level caching policy. When enabled the drive is allowed to cache data within the physical drive cache (for physical disks) and virtual implementations.

Drive: XStore Caching

The virtual disks attached to your Windows IaaS VM are stored in Windows Azure storage (the XStore.) The XStore provides host level caching and performance optimizations for your VM. XStore caching is controlled outside of the individual drive cache settings, previously shown. (Drive level cache settings do not impact the XStore cache settings.)

There are three cache settings (None, ReadOnly, ReadWrite) for the XStore. By default a data disk is set to NONE and an OS Disk is set to Read Write. The data disk can be configured to any of the 3 settings while an OS disk is limited to the Read Only or Read Write options.

To alter the XStore cache settings you must use a command such as the following: (The cmdlet’s are part of the Windows Azure Management cmdlets package.)

get-azurevm 'TestSub' 'TestMach' | set-azureosdisk -HostCaching "ReadOnly" | update-azurevm

Note: The configuration change does not take place until the VM is restarted.

You will find that most documentation points to the use of one or more data drives for SQL Server database and log files and I agree with this assessment but I would like to explain a bit more as to why I agree.

OS Drive Default: Read Write

To understand the recommendation it helps to understand a bit of how the XStore cache is implemented. The XStore cache can use a combination of the host’s RAM as well as disk space, on the local host to support the cache. When a read or write takes place the local cache is consulted. As you can imagine, the local cache can be faster than making a request to the Windows Azure storage cluster. To see this in action it helps if I show you some high level scenarios.

Note: These scenarios are designed to provide you a 10,000 foot view of the architecture.

Action	FUA	XStore Read Cache	XStore Write Cache	Outcome
WriteFile*	Yes	Yes	Yes	Is covering block in XStore write cache (No) Obtain cache block (could require write of an older block to XStore before reuse is allowed) Issue XStore read for block ~512K and store in local cache (write) Do original write to local cache Do original write to XStore Data is written all the way to the XStore (stable media.)
	No	Yes	Yes	Is covering block in XStore write cache (No) Obtain cache block (could require write of an older block to XStore before reuse is allowed) Issue XStore read for block ~512K and store in local cache (write) Do original write to local cache Data is NOT in stable media, will be written by XStore caching, LRU algorithms. This is not used by the SQL Server database or log files because FUA=YES but BCP out is a usage example. This may be helpful because the BCP can leverage the cache and allow the cache to optimally send data to the XStore. Note: For temporary files, such as BCP not TEMPDB, you may consider the (D:) scratch drive, provided. It is local and no XStore caching is involved.
	Yes	Yes	No	The write is propagated directly to the XStore.
	Yes	No	No	The write is propagated directly to the XStore.
ReadFile*	N/A	Yes	Yes	Is covering block in XStore read cache (No) Obtain cache block (could require reclaim of an older block before reuse is allowed) Issue XStore read for block ~512K and store in local cache (write) Provide portion of block requested to reader If the block is present in the read cache the portion of the block requested to the reader is directly serviced.

The SQL Server use cases become more clear once you understand the XStore caching behavior and combine it with SQL Server caching behavior.

SQL Server Log File

The log file is typically a serially moving, write only entity. SQL Server maintains a cache of log block to avoid physical I/O for actions such as a transaction rollback or provide data to Always On, Database Mirroring, Replication, … If you place the log on a drive that allows XStore write caching you are seldom taking advantage of the write cache. First the log is written with FUA enabled so a write has to go though the cache, all the way to the XStore. Secondly, since the log has a much higher ratio of writes to reads you are likely not using the XStore cache effectively but forcing local XStore cache writes for every backend, FUA XStore write.

SQL Server Data File

The data file is opened with FUA enabled and the SQL Server uses a large buffer pool to maintain database pages in cache. The larger your VM size the more buffer pool cache SQL Server can take advantage of, avoiding physical I/O activities.

The same write behavior is true for database pages as described in the log section above. When you then apply the XStore read cache capabilities, they may not be performance improving over what SQL Server is already caching in buffer pool. As shown in the scenario table a read, via XStore read cache enablement, can result in a fetch of a larger block into the local XStore read cache. This could be helpful for subsequent SQL Server read requests but you also incur a possible write to the local XStore cache to maintain the data in the XStore cache. Your application read pattern may also be sporadic and defeat the intent of the XStore read cache.

BCP Out

You may get an advantage of writing to a XStore, write enabled drive by allowing the XStore to cache and optimially flush information to the backend store.

BCP In

This is one of the tests that the XStore read cache improved performance for. The read ahead action of the larger blocks used by the XStore allowed the streaming of the read bytes to be faster than from a XStore drive with read caching disabled.

TEMPDB Scratch Drive – No Thanks

It can be a bit confusing that you have a (D: scratch) drive so why not use it for TEMPDB. The reason is that scratch drive is a shared resource between all VMs on the host. You are given a sandbox drive in the VM so others can’t see your data and you can’t see theirs but the physical media is shared. While the system attempts to avoid it, it does mean a noisy neighbor could impact consistent I/O throughput on the scratch drive and change your performance predictability.

Replicas of Data

The Windows Storage for the VHDs atomically replicates your data to 3 separate, physical media destinations. This is done during the write request in a way that the write is assured quorum to the devices before the write is considered complete, proving your VHDs with a high degree of data storage safety.

Remote Replicas (Geo-Replication)

The default for the VHD storage is to provide 3 local replicas of the data. A remote replica can also be established. The remote replica is currently NOT safe for SQL Server use. The remote replica is maintained asynchronously and the system, currently, does not provide the ability to group VHDs into a consistency group. Without consistency groups it is unsafe to assume SQL Server, with files on multiple VHDs maintain the write ordering across all the VHDs and as such the database won’t be recoverable.

At the current time you should not leverage the remote, Windows Azure storage replication capabilities for SQL Server as it is not supported. You should leverage SQL Server technologies that provide the capability (Always On, Database Mirroring, Log Shipping, Backup to Blob Storage, …)

Recap / Recommendation

What am I trying to say? – Test! As pointed out in the SQL Server whitepaper, the XStore is perfectly safe for SQL Server ACID requirements. However, the types of I/O pattern(s) your application(s) drive dictate how you can leverage the XStore caching capabilities.

Most implementations start with the SQL Server database and log files on a data drive, XStore caching disabled and only after testing enable various levels of XStore, caching behavior.

Bob Dorr - Principal SQL Server Escalation Engineer

Why won't my PowerPivot for Excel 2010 workbook upgrade to Excel 2013?

psssql — Thu, 23 May 2013 17:35:00 GMT

Recently we've seen an issue where some Excel 2010 workbooks containing PowerPivot models encounter errors when attempting to upgrade to Excel 2013.

When opening a PowerPivot model that was created in Excel 2010 in Excel 2013 you will be prompted to upgrade with the following message:

This workbook has a PowerPivot data model created using a previous version of
the PowerPivot add-in. You will need to upgrade this data model with PowerPivot
for Excel 2013.

After clicking OK to upgrade to model the following error message is displayed:

============================
Error Message:
============================

The handle is invalid
----------------------------
The '' local cube file cannot be opened.
----------------------------
A connection cannot be made. Ensure that the server is running.
----------------------------
Sorry, PowerPivot couldn't connect to server A connection cannot be made. Ensure that the server is running..

============================
Call Stack:
============================

   at Microsoft.AnalysisServices.LocalCubeStream..ctor(String cubeFile, OpenFlags settings, Int32 timeout, String password, String serverName)
----------------------------
   at Microsoft.AnalysisServices.LocalCubeStream..ctor(String cubeFile, OpenFlags settings, Int32 timeout, String password, String serverName)
   at Microsoft.AnalysisServices.XmlaClient.OpenLocalCubeConnection(ConnectionInfo connectionInfo)
   at Microsoft.AnalysisServices.XmlaClient.OpenConnection(ConnectionInfo connectionInfo, Boolean& isSessionTokenNeeded)
   at Microsoft.AnalysisServices.XmlaClient.Connect(ConnectionInfo connectionInfo, Boolean beginSession)
----------------------------
   at Microsoft.AnalysisServices.XmlaClient.Connect(ConnectionInfo connectionInfo, Boolean beginSession)
   at Microsoft.AnalysisServices.Server.Connect(String connectionString, String sessionId, ObjectExpansion expansionType)
   at Microsoft.AnalysisServices.BackEnd.DataModelingSandboxConnection.OpenAMOConnection()
----------------------------
   at Microsoft.AnalysisServices.BackEnd.DataModelingSandboxConnection.OpenAMOConnection()
   at Microsoft.AnalysisServices.BackEnd.DataModelingSandboxConnection.Open()
   at Microsoft.Office.PowerPivot.ExcelAddIn.InProcServer.LoadSandboxAfterConnection(String errorCache)
   at Microsoft.Office.PowerPivot.ExcelAddIn.InProcServer.LoadSafeSandboxAfterConnection(String errorCache)
   at Microsoft.Office.PowerPivot.ExcelAddIn.InProcServer.LoadOLEDBConnection(Boolean raiseCompleteEvent, String errorCache)

============================

This issue occurs when a Pivot Table in the workbook has an invalid set or calculated field definition.

When the attempt to upgrade begins, Excel opens the PowerPivot model and executes the commands in the pivotcache for the pivot tables in the workbook, including creating session sets or calculated items. If a definition contains an error then the embedded PowerPivot engine returns an error and Excel disconnects from the PowerPivot embedded engine, returning the message saying the server connection could not be opened.

We are working with the Excel team to address this issue, but for now one option to work around this problem is to use the following steps:

Open the workbook in Excel 2010
Click on a PivotTable
In the PivotTable Tools, Options, menu click on the "Fields, Items, and Sets" button and choose Manage Sets.
Delete any invalid set definitions.
Save the file then open it in Excel 2013. It should upgrade successfully.

-Wayne Robertson

SharePoint Adventures : Claims, Named Pipes and Kerberos

Adam W. Saxton — Fri, 17 May 2013 21:17:15 GMT

I ran into a new Kerberos Scenario that I hadn’t hit before when I was working on the cases related to this blog post. It’s rare that I actually see a case related to the Named Pipes protocol. When I do, it is usually a customer trying to get it setup with a Cluster deployment. I have never had a Named Pipes case related to Kerberos. On top of that, I’ve never had a SQL related Kerberos issue that looked like an actual network related issue. I usually see a traditional “Login failed for user” type error from the SQL Server itself.

As part of my troubleshooting for the other blog post with the Claims configuration, I stumbled upon some information and theories about how Named Pipes responds when Kerberos is in the picture that I hadn’t ever seen or dealt with before. I love when I see new things! It is very humbling and always reminds me there are a lot of things that I don’t know. And, if you have read my other blog posts, or have seen me present at conferences like PASS, you know I have a passion for Kerberos!

Here is what I saw from an error perspective using SharePoint 2013 and Reporting Services 2012 SP1.

System.Data.SqlClient.SqlException: A network-related or instance-specific error occurred while establishing a connection to SQL Server. The server was not found or was not accessible. Verify that the instance name is correct and that SQL Server is configured to allow remote connections. (provider: Named Pipes Provider, error: 40 - Could not open a connection to SQL Server) ---> System.ComponentModel.Win32Exception: Access is denied

This is a typical error if we can’t connect to SQL. Think of this like a “Server doesn’t exist” type error. We didn’t get the normal “Login failed for user” error that would possibly point towards Kerberos. In this error, we didn’t even make it to SQL. The interesting piece here though is the “Access is denied” inner exception. That does possibly point to a permission issue.

I had talked in the last Blog Post about protocol order with connecting to SQL and that the default was TCP. In this case, I was forcing Named Pipes, so the fact that the error is a Named Pipes error is expected.

I dropped down to a network trace to see how far we actually got and to see if that revealed any other information. One thing to keep in mind here is that we are in a Claims to Windows Token Service (C2WTS) scenario with the SharePoint/RS 2012 integration. So, Kerberos/Constrained Delegation will be in the picture here. A lot of people aren’t necessarily familiar with how Named Pipes actually works. Named Pipes actually uses the SMB (simple message block) protocol from a network perspective. This is the same protocol used for file shares and you’ll see the traffic on port 445. It can be a little confusing because SMB sits on top of TCP, but we aren’t actually using the TCP 1433 port. It is just a different way to connect to SQL Server. The IP 10.0.0.20 was the SharePoint Server hosting the Reporting Services Service.

300    9:04:40 AM 5/17/2013    10.0.0.20    captthrace.battlestar.local    SMB    SMB:C; Negotiate, Dialect = PC NETWORK PROGRAM 1.0, LANMAN1.0, Windows for Workgroups 3.1a, LM1.2X002, LANMAN2.1, NT LM 0.12, SMB 2.002, SMB 2.???    {SMBOverTCP:42, TCP:41, IPv4:1}

302    9:04:40 AM 5/17/2013    captthrace.battlestar.local    10.0.0.20    SMB2    SMB2:R   NEGOTIATE (0x0), Revision: (0x2ff) - SMB2 wildcard revision number., ServerGUID={97B805C2-296C-477B-82B4-DEB6170A2A01} Authentication Method: GSSAPI,     {SMBOverTCP:42, TCP:41, IPv4:1}

303    9:04:40 AM 5/17/2013    10.0.0.20    captthrace.battlestar.local    SMB2    SMB2:C   NEGOTIATE (0x0), ClientGUID= {9CB563F9-BEF4-11E2-9403-00155D4CB97B},     {SMBOverTCP:42, TCP:41, IPv4:1}

304    9:04:40 AM 5/17/2013    captthrace.battlestar.local    10.0.0.20    SMB2    SMB2:R   NEGOTIATE (0x0), Revision: (0x300) - SMB 3.0 dialect revision number., ServerGUID={97B805C2-296C-477B-82B4-DEB6170A2A01} Authentication Method: GSSAPI,     {SMBOverTCP:42, TCP:41, IPv4:1}

323    9:04:40 AM 5/17/2013    10.0.0.20    captthrace.battlestar.local    SMB2    SMB2:C   SESSION SETUP (0x1) Authentication Method: GSSAPI,     {SMBOverTCP:42, TCP:41, IPv4:1}

326    9:04:40 AM 5/17/2013    captthrace.battlestar.local    10.0.0.20    SMB2    SMB2:R - NT Status: System - Error, Code = (22) STATUS_MORE_PROCESSING_REQUIRED SESSION SETUP (0x1), SessionFlags=0x0 Authentication Method: GSSAPI,     {SMBOverTCP:42, TCP:41, IPv4:1}

327    9:04:40 AM 5/17/2013    10.0.0.20    captthrace.battlestar.local    SMB2    SMB2:C   SESSION SETUP (0x1) Authentication Method: GSSAPI,     {SMBOverTCP:42, TCP:41, IPv4:1}
     - ResponseToken: NTLM AUTHENTICATE MESSAGE Version:NTLM v2, Workstation: CAPTHELO
          Signature: NTLMSSP

328    9:04:40 AM 5/17/2013    captthrace.battlestar.local    10.0.0.20    SMB2    SMB2:R - NT Status: System - Error, Code = (34) STATUS_ACCESS_DENIED SESSION SETUP (0x1) ,     {SMBOverTCP:42, TCP:41, IPv4:1}

329    9:04:40 AM 5/17/2013    10.0.0.20    captthrace.battlestar.local    TCP    TCP:Flags=...A.R.., SrcPort=49665, DstPort=Microsoft-DS(445), PayloadLen=0, Seq=2945236632, Ack=2852397926, Win=0 (scale factor 0x8) = 0    {TCP:41, IPv4:1}

In the Network Trace we can see that we were trying to connect via NTLM. I already know that that will be a problem as we have to go Kerberos. We started supporting Kerberos with Named Pipes starting in SQL 2008, so it should work. At this point, I’m thinking we actually have a Kerberos issue even though it looked like a network issue from the original error message. So, lets go see if we can validate that. I already had Kerberos Event Logging enabled. These entries will be located in the System Event Log. You can ignore errors that show “KDC_ERR_PREAUTH_REQUIRED”. That is just noise and expected. Also realize that errors may be cached and if they are, you will not see them in the Event Log or a Network Trace. It may require an IISRESET, a reset of the C2WTS Windows Service, or even a reboot of the box to get the items to show in the Event log or Network Trace. See this Blog Post.

Log Name:      System
Source:        Microsoft-Windows-Security-Kerberos
Date:          5/17/2013 9:04:40 AM
Event ID:      3
Task Category: None
Level:         Error
Keywords:      Classic
User:          N/A
Computer:      CaptHelo.battlestar.local
Description:
A Kerberos error message was received:
on logon session
Client Time:
Server Time: 14:4:40.0000 5/17/2013 Z
Error Code: 0xd KDC_ERR_BADOPTION
Extended Error: 0xc0000225 KLIN(0)
Client Realm:
Client Name:
Server Realm: BATTLESTAR.LOCAL
Server Name: cifs/captthrace.battlestar.local
Target Name: cifs/captthrace.battlestar.local@BATTLESTAR.LOCAL
Error Text:
File: 9
Line: 12be
Error Data is in record data.

This entry was the only non-PREAUTH_REQUIRED error. Two things that were interesting about this. First was KDC_ERR_BADOPTION. When I see this, especially in a Claims type configuration, it tells me we have a Constrained Delegation issue. The other item that was interesting was the CIFS SPN. CIFS is used for File Sharing. It stands for “Common Internet File System”. This was our SMB traffic. We can also see this in the Network Trace.

319 9:04:40 AM 5/17/2013 10.0.0.20 10.0.0.1 KerberosV5 KerberosV5:TGS Request Realm: BATTLESTAR.LOCAL Sname: cifs/captthrace.battlestar.local {TCP:44, IPv4:14}

321 9:04:40 AM 5/17/2013 10.0.0.1 10.0.0.20 KerberosV5 KerberosV5:KRB_ERROR - KDC_ERR_BADOPTION (13) {TCP:44, IPv4:14}

This was interesting, because I never gave Constrained Delegation rights to CIFS for the C2WTS or the Computer Account. When we talk about SPN’s and Delegation and placement, we talk about that the SPN should be on the account that is running the servers. For CIFS, it will be the system itself and therefore on the machine account of the SQL Server that we are trying to connect to.

CIFS is one of those special Service Classes, similar to HTTP. It is covered by the HOST SPN on the Machine Account and we won’t see an actual CIFS SPN defined, but when we go to the delegation side of things you will see it.

I added this to both the Claims Service account and the Computer Account. I say computer account, because the actual SMB request will come from the machine and not directly from the RS Process. Under the hoods, it is affectively making a call to the CreateFile Windows API.

After resetting IIS and cycling the C2WTS Service, I still saw the same exact error. This was one of those reboot moments. After rebooting the server, I then got the following:

I didn’t necessarily expect this as I expected to fail on the Kerb side to SQL. So, I ran a report and stuck a WAITFOR DELAY in there so I could see the connection. had a look at dm_exec_connections on the SQL Server and saw that we had connected with NTLM:

For our purposes this will work as I’m not going further than SQL. This is technically a single hop between the SharePoint Server System context and the SQL Server. You can configure it for Kerberos if you really want that auth_scheme by creating the appropriate Named Pipes SPN and configuring the appropriate Delegation for the C2WTS Service Account and the Machine Account for where the SMB request is originating from. Also realize that if you have a misplaced Named Pipes SQL SPN, you will encounter a “Cannot Generate SSPI Context” similar to the following:

Adam W. Saxton | Microsoft Escalation Services
http://twitter.com/awsaxton

SharePoint Adventures : When connectivity is not connectivity

Adam W. Saxton — Fri, 17 May 2013 13:07:29 GMT

I’m always amazed that issues usually come in batches. I was looped into a few cases that had the following symptoms. They were running SharePoint 2010 and Reporting Services 2012 SP1. When they went to use a data source with Windows Authentication, they were seeing the following error:

System.Data.SqlClient.SqlException: A network-related or instance-specific error occurred while establishing a connection to SQL Server. The server was not found or was not accessible. Verify that the instance name is correct and that SQL Server is configured to allow remote connections. (provider: Named Pipes Provider, error: 40 - Could not open a connection to SQL Server)

This caused me to raise an eyebrow (visions of Spock as the new Star Trek movie is opening today <g>). A lot of thoughts were floating in my head that all told me that this error didn’t make sense, for a bunch of reasons.

The default protocol order for connecting to SQL from a client is TCP and then Named Pipes. So, because we failed with a Named Pipes error, that meant something was either wrong with TCP or someone changed the Protocol order (which I have never seen in a customer case – so very unlikely)
This is RS 2012, which means we are a Shared Service and rely on the Claims to Windows Token Service (C2WTS). This forces Constrained Delegation. Pretty sure most people would not have created the delegation requirements for the Named Pipes SQL SPN as most people go down the TCP route. You can read more about SQL’s SPNs being Protocol based here. Also more on this related aspect in a later post as I found some interesting things about this as well.
This error tells me that we couldn’t establish a connection to SQL via Named Pipes. Think of this as a “Server Not Found” type error. I immediately tossed out any Kerberos/Claims related issue due to that thinking – again more on the kerb piece of this in a later post.
This is really the first time I’ve had someone hit me up with a Named Pipes connection failure from an RS/SharePoint Integration perspective ever. And I just got hit with 3 of them within the same week. Something is up.

Being this told me we had an actual connection issue via Named Pipes, I started down the normal connectivity troubleshooting path. With any connectivity issue, I started with a UDL (Universal Data Link) file. Basically just a text file renamed with an extension of UDL. It’s important to run this from the same machine that is hitting the SqlException. In my case it was my SharePoint App server, not the WFE server.

You’ll notice the “np:” in front of the server name. This forces the Named Pipes Protocol and ignores the default protocol order. And this worked. I also tried “tcp:” to force TCP in the UDL and this worked to. I went back to my data source and tried forcing TCP there.

System.Data.SqlClient.SqlException: A network-related or instance-specific error occurred while establishing a connection to SQL Server. The server was not found or was not accessible. Verify that the instance name is correct and that SQL Server is configured to allow remote connections. (provider: TCP Provider, error: 0 - The requested name is valid, but no data of the requested type was found.)

This made no sense. I even made sure I was logged in as the RS Service Account as that is the context in which we would have been connecting to SQL. Same result. Also, within a network trace, I saw nothing on either the TCP or Named Pipes side of the house in the trace that related to this connection attempt. Which meant we never hit the wire.

As I was going to collect some additional diagnostic logging (Kerberos ETW tracing and LSASS Logging) I ended up doing an IISRESET and a recycle of the C2WTS service. We went to reproduce the issue, but got a different error this time.

System.IO.FileLoadException: Could not load file or assembly 'System.EnterpriseServices, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a' or one of its dependencies. Either a required impersonation level was not provided, or the provided impersonation level is invalid. (Exception from HRESULT: 0x80070542) File name: 'System.EnterpriseServices, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a' ---> System.Runtime.InteropServices.COMException (0x80070542): Either a required impersonation level was not provided, or the provided impersonation level is invalid. (Exception from HRESULT: 0x80070542)

This error I did know and can work with. I had blogged about this error last July here. Checking the “Act as part of the operating system” showed that the C2WTS service account in fact was not given that right. Adding that account to that policy right and restarting the C2WTS Windows Service and performing an IISRESET then yielded the following:

The connectivity errors were clearly related to the lack of the Policy Setting. It was unexpected and didn’t line up with normal connectivity related issues and also wasn’t very helpful with regards of where to go look for more information as all of the normal paths didn’t show anything useful.

Of note, I tried reproducing this on SharePoint 2013, but only got the FileLoadException. I think this is partly a timing issue with how IIS AppPools are started and the C2WTS service is started. Doesn’t mean you won’t see this on SharePoint 2013 necessarily. Even on SharePoint 2010, the first time I hit the FileLoadException.

Adam W. Saxton | Microsoft Escalation Services
http://twitter.com/awsaxton

SQL Server–Storage Spaces/VHDx and 4K Sector Size

psssql — Wed, 15 May 2013 14:40:25 GMT

This blog outlines a new twist to my previous blog outlining issues with 4K sector sizes.

SQL Server - New Drives Use 4K Sector Size: http://blogs.msdn.com/b/psssql/archive/2011/01/13/sql-server-new-drives-use-4k-sector-size.aspx

In the previous post I discussed that it was unsafe for the I/O subsystem to present a sector size that was smaller than the actual, physical sector size. This leads to unsupported, Read-Modify-Write (RMW) behavior.

I was doing testing on a Windows 2012 Server - Storage Space setup and found that both Storage Spaces and the VHDx format can report a 4K sector size to the SQL Server. This allows the various drives setup in the pool for Storage Spaces to be of disparate sector sizes (Drive 1 = 512 bytes, 1K, 2K, and Drive 4 = 4K.)

Is this safe for SQL Server?

The answer is yes. An I/O subsystem can return a larger sector size than actual, physical sector size as long as all reported values can be evenly divided by 512 bytes.

As the diagram below shows, SQL Server maintains parity on 512 byte boundaries, for the log, regardless of the reported sector size. This allows SQL Server to detect a partial write (torn behavior.) For example, if the system reported a sector size of 4K but the physical sector size was 512 bytes, the I/O subsystem is only guaranteed to flush to a 512 byte mark. If the first 4, physical sectors are flushed (2K of the 4K aligned block) and a power outage occurs, SQL Server will be able to detect the entire 4K was not properly flushed.

Without the logical parity every 512 bytes SQL Server would be unable to detect the torn situation, leading to unexpected recovery and logging behavior(s).

WARNING: While SQL Server protects your data against such a failure the reporting of sector size, larger than physical sector size, can lead to unwanted/unexpected space usage. SQL Server will align the log writes to the reported sector size (4K in this example.)

SQL Server packs records within the log blocks and then aligns/pads the writes on the reported sector boundary. Lots of small transactions, leading to many log flushes, can result in wasted log space for a system reporting larger sector sizes. Moving the scenario to an I/O subsystem reporting smaller sector sizes can reduce space usage.

The easiest way to see this in action is a single worker doing tiny transactions.

while(1=1)

begin

insert into tblTest values (1) // Each insert is a transaction and a log flush

end

Each insert is a separate commit transaction, causing the log to be flushed for each iteration. In this example each insert will require at least 4K of log space to properly align during the flush. Wrapping a transaction around the while loop or only committing at reasonable boundaries (say 10,000 inserts) reduces the log flushing behavior and uses the log space more effectively.

Bob Dorr - Principal SQL Server Escalation Engineer

Using PowerShell to discover Reporting Services 2012 in SharePoint

Adam W. Saxton — Tue, 30 Apr 2013 18:58:46 GMT

I was recently going through an exercise of documenting how to discover certain aspects of Reporting Services for some Kerberos work. RS 2012 in SharePoint is a totally different game though. The easiest way I could discover certain items about Reporting Services within SharePoint was with PowerShell. For previous versions, and RS 2012 in Native Mode, we can use other avenues such as WMI to discover configuration of Reporting Services.

Service Enumeration

One of the big things we want to do when we are discovering what is out there is to be able to tell if we even have the service installed. This may also lead to multiple services within SharePoint. Within SQL 2012, Reporting Services is a Shared Service within SharePoint and is deployed as such. We could run the following to see the Service Applications that are configured.

Get-SPServiceApplication |where {$_.TypeName -like "SQL Server Reporting*"}

This aligns with what we see in Central Admin as well.

From the Kerberos/Claims configuration perspective, we are also interested in the Service Account for the Reporting Services Application. Also keeping in mind that there may be more than one.

$apps = Get-SPServiceApplication |where {$_.TypeName -like "SQL Server Reporting*"}
foreach ($app in $apps){"{0,-20} {1,-20}" -f $app.name, $app.ApplicationPool.ProcessAccountName}

We can see that the name is “Reporting Services” and the AppPool Process Account is “BATTLESTAR\rsservice”. The next piece of information we want to know is which SharePoint boxes is this service running on? We could have any number of App Servers that we need to go check.

$services = Get-SPServiceInstance |where {$_.TypeName –like "*Reporting*"}
foreach ($service in $services){"{0,-20} {1,-20}" -f $service.parent.address, $service.status}

In this example, I only have one server that has the Reporting Services Service started within SharePoint and that is on the CAPTHELO server. We can then compare with the Claims to Windows Token Service (C2WTS).

Claims to Windows Token Service (C2WTS)

As part of SQL 2012 with SharePoint Integration, the Claims to Windows Token Service plays a big part in our functionality when it comes to Kerberos. As such, if we are going to validate RS 2012 in SharePoint configuration, we need to look at C2WTS as well. We can use the following PowerShell command to get the C2WTS instances:

Get-SPServiceInstance |where {$_.TypeName -like "*Claims*"}

One thing to remember is that C2WTS is not a service app. You may see multiple items here if they have more than one SharePoint Server. For example, in my environment I have two SharePoint Servers:

The service only needs to be started on the SharePoint Box where the Reporting Services Shared Service is started as well. In the Reporting Services example above, we know that Reporting Services is only active on CAPTHELO, so that is where C2WTS needs to be started.

$services = Get-SPServiceInstance |where {$_.TypeName –like "*Claims*"}
foreach ($service in $services){"{0,-20} {1,-20} {2}" -f $service.parent.address, $service.status, $service.Service.ProcessIdentity.username}

We can see that we have two SharePoint servers here. C2WTS is started on LTBOOMER but it is not running on CAPTHELO. This will result in an error such as the following:

Throwing Microsoft.ReportingServices.Diagnostics.Utilities.ClaimsToWindowsTokenLoginTypeException: , Microsoft.ReportingServices.Diagnostics.Utilities.ClaimsToWindowsTokenLoginTypeException: Can not convert claims identity to windows token. This may be due to user not logging in using windows credentials.;

From the last command above, we can also see the Process Identity for the C2WTS. So, this will provide the service accounts for both Reporting Services and C2WTS as well as let us know which servers Reporting Services is enabled on and which servers C2WTS needs to be enabled on. This could be very helpful when it comes to automation.

Adam W. Saxton | Microsoft Escalation Services
http://twitter.com/awsaxton

AlwaysON - HADRON Learning Series: lock_redo_blocked/redo worker Blocked on Secondary Replica

psssql — Fri, 26 Apr 2013 18:34:06 GMT

The topic I received most in my inbox this week was redo blocked on a secondary while attempting to acquire SCH-M (schema modify) lock.

First of all, this is expected behavior and you can monitor for this with your standard blocking activities (sys.dm_exec_requests, blocked process TRC event, blocked process threshold configuration setting(s) and the log_redo_blocked XEvent.)

The SQL Server 2012 implementation of Always On extended the database mirroring (DBM) capabilities by allowing read only queries and backups against a secondary replica. With this new activity comes additional overhead.

1. When a replica is marked for read only capabilities the updated/inserted rows on primary add additional overhead for the row versioning to help support snapshot isolation activities of the read only connections.

2. When queries are run against the secondary the SCH-S (schema stability) lock is held during the query to make sure the schema of the object can’t be changed during the processing of results.

In the case of the blocked, redo the read only clients typically have long running queries and the object is changed (ALTER, create index, …) on the primary. When the DDL activity arrives on the secondary the SCH-M is required to complete the requested, redo change. This causes the redo worker to become blocked on the long running, read only query(s).

You can monitor the redo queue size and other performance counters to determine the relative impact of redo being blocked and make any necessary business decisions to KILL the head blocker(s). It will look no different than a production server with a head blocker that you resolve today.

Microsoft is evaluating, for future builds, the ability to configure a replica to automatically kill a redo blocker, allowing redo to progress.

Bob Dorr - Principal SQL Server Escalation Engineer