Sunday, February 19, 2012

Browse Cube Causes CPU Spike & Unresponsive SSAS

Hello,

I'm interested to see if anyone else has seen the behavior I have experienced. I could have missed a KB article, however, hoping that someone will help with some advice anyhow.

I have a cube (it is around 400 mb). Every morning I execute a SSIS package to process the cube (full process). This works every morning without any failures. When I came in this morning, I opened Management Studio, connected to SSAS, went to the cube, right clicked, and chose browse.

In Task Manager, the Mem Usage by msmdsrv.exe started around 411,000. Once I chose browse, the cpu jumped to 40-60 percent. It has been almost 30 minutes now, and the cpu is still in that range. The mem usage has risen to 530,000, but I expected this.

The problem is the CPU. I can't see any reason for such heavy cpu usage for 30 minutes +. If I restart the SSAS service, and browse the cube again, it seems to work fine. I have seen this happne 4-5 times now.

We are using SQL Server 2005 enterprise (no SP) on Windows Server 2003 SP 1. The machine has 1.5 gig of ram.

Any suggestions or direction is greatly appreciated.

Regards,


Dan

This is strange.

It is hard to say what is going on.
Try and run Profiler connect to Analysis Server and see what it is doing during these 30 min. See what kind of activity reported.

Try and run ActivityViewer sample application and see which sessions are active and what is getting executed.

Edward.
--
This posting is provided "AS IS" with no warranties, and confers no rights.

|||

Thanks for your response Edward. I followed your suggestions, but I'm not sure it yielded any useful results. Below is what I have typed up & pasted as I was looking through things.

I’ll start from the ActivityViewer.While I got a few errors from the JIT compiler getting it to run, I managed to hit continue each time and saw some interesting information.While I’m not 100% on how to interpret the findings, this is what I found:

Under Sessions, I found 25295. It is on the same cube/database that I tried to “Browse”.It appears that all the times show something around 12pm (although it is 8am… I’m going to ignore this for the time being) and under last command it has MDSCHEMA_CUBES.

If find this under “Transactions”

TRANSACTION_ID

TRANSACTION_SESSION_ID

TRANSACTION_START_TIME

TRANSACTION_ELAPSED_TIME_MS

TRANSACTION_CPU_TIME_MS

96EC1996-B252-4F80-A0FA-330EE37476BB

25A40F0E-A6FD-4FBA-A6FD-17DFFC0F2340

7/6/2006 12:36 PM

4176799

31

And this under “Locks”.The same Transaction ID above is causing the Lock.

SPID

LOCK_ID

LOCK_TRANSACTION_ID

LOCK_OBJECT_ID

LOCK_STATUS

LOCK_TYPE

LOCK_CREATION_TIME

LOCK_GRANT_TIME

25295

c6eceba6-19bc-480b-96fb-989273e4eade

96ec1996-b252-4f80-a0fa-330ee37476bb

<Object xmlns="urn:schemas-microsoft-com:xml-analysis:rowset"><DatabaseID>dw_prep_archive_PROD</DatabaseID></Object>

1

8

7/6/2006 12:36 PM

7/6/2006 12:36 PM

The time shown under the “lock creation time” is the time that I tried to browse the cube this morning.The profiler trace now shows 13:48 so this whole process has been occurring for over an hour (and my cpu is still above 45%).

This first set of data (below) from the profiler might show something useful, but I'm not sure what it means.

The second set below (seperated by a line) shows the set of commands that loop over and over again every 2 minutes or so. I know below is incredibly messy, but it basically shows “Flight recorder begin” followed by “discover locks”, “discover transactions”, “discover locks”, and then “Flight Recorder Snapshot End”.

Although I am relatively new to SSAS, I don’t think I see anything that could be causing this.Does anyone have any insight on what is happening here?

I really don't expect anyone to try to decipher below completely, but if anyone sees any unusual commands, I would appreciate it.

The only thing I can see is that my initial connection to browse the cube is trying to do something and in a transaction and is blocking everything else.

Regards,


Dan



Upon Connection

Discover Begin 26 - DISCOVER_PROPERTIES <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<PropertyName>ProviderVersion</PropertyName>
</RestrictionList> 101 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:20.000 2006-07-06 12:35:20.000 3572 25267 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Timeout>0</Timeout> <SspropInitAppName>Micros
Discover End 26 - DISCOVER_PROPERTIES <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<PropertyName>ProviderVersion</PropertyName>
</RestrictionList> 101 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:20.000 2006-07-06 12:35:20.000 0 0 3572 25267 0 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Timeout>0</Timeout> <SspropInitAppName>Micros
Discover Begin 31 - DISCOVER_XML_METADATA <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis"><ObjectExpansion>ExpandFull</ObjectExpansion></RestrictionList> 99 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:22.000 2006-07-06 12:35:22.000 25271 QG
Discover End 31 - DISCOVER_XML_METADATA <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis"><ObjectExpansion>ExpandFull</ObjectExpansion></RestrictionList> 99 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:22.000 2006-07-06 12:35:37.000 15107 0 25271 2625 QG
Discover Begin 26 - DISCOVER_PROPERTIES <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<PropertyName>DBMSVersion</PropertyName>
</RestrictionList> 101 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:39.000 2006-07-06 12:35:39.000 3572 25267 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Timeout>0</Timeout> <SspropInitAppName>Micros
Discover End 26 - DISCOVER_PROPERTIES <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<PropertyName>DBMSVersion</PropertyName>
</RestrictionList> 101 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:39.000 2006-07-06 12:35:39.000 0 0 3572 25267 0 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Timeout>0</Timeout> <SspropInitAppName>Micros
Discover Begin 31 - DISCOVER_XML_METADATA <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis"><ObjectExpansion>ExpandObject</ObjectExpansion></RestrictionList> 103 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:44.000 2006-07-06 12:35:44.000 25280 QG
Discover End 31 - DISCOVER_XML_METADATA <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis"><ObjectExpansion>ExpandObject</ObjectExpansion></RestrictionList> 103 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:44.000 2006-07-06 12:35:44.000 47 0 25280 47 QG
Discover Begin 31 - DISCOVER_XML_METADATA <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis"><DatabaseID>dw_prep_archive_PROD</DatabaseID><ObjectExpansion>ExpandObject</ObjectExpansion></RestrictionList> 102 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:48.000 2006-07-06 12:35:48.000 25284 QG
Discover End 31 - DISCOVER_XML_METADATA <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis"><DatabaseID>dw_prep_archive_PROD</DatabaseID><ObjectExpansion>ExpandObject</ObjectExpansion></RestrictionList> 102 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:48.000 2006-07-06 12:35:48.000 31 0 25284 31 QG
Discover Begin 31 - DISCOVER_XML_METADATA <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<ObjectExpansion>ExpandObject</ObjectExpansion>
</RestrictionList> 105 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:50.000 2006-07-06 12:35:50.000 3572 25289 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Timeout>0</Timeout> <SspropInitAppName>Micros
Discover End 31 - DISCOVER_XML_METADATA <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<ObjectExpansion>ExpandObject</ObjectExpansion>
</RestrictionList> 105 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:50.000 2006-07-06 12:35:50.000 47 0 3572 25289 47 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Timeout>0</Timeout> <SspropInitAppName>Micros
Discover Begin 31 - DISCOVER_XML_METADATA <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<DatabaseID>dw_prep_archive_PROD</DatabaseID>
<ObjectExpansion>ExpandObject</ObjectExpansion>
</RestrictionList> 105 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:52.000 2006-07-06 12:35:52.000 3572 25289 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Timeout>0</Timeout> <SspropInitAppName>Micros
Discover End 31 - DISCOVER_XML_METADATA <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<DatabaseID>dw_prep_archive_PROD</DatabaseID>
<ObjectExpansion>ExpandObject</ObjectExpansion>
</RestrictionList> 105 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:35:52.000 2006-07-06 12:35:52.000 31 0 3572 25289 31 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Timeout>0</Timeout> <SspropInitAppName>Micros
Discover Begin 26 - DISCOVER_PROPERTIES <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<PropertyName>DBMSVersion</PropertyName>
</RestrictionList> 106 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:36:04.000 2006-07-06 12:36:04.000 3572 25295 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Catalog>dw_prep_archive_PROD</Catalog> <ShowH
Discover End 26 - DISCOVER_PROPERTIES <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<PropertyName>DBMSVersion</PropertyName>
</RestrictionList> 106 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:36:04.000 2006-07-06 12:36:04.000 0 0 3572 25295 0 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Catalog>dw_prep_archive_PROD</Catalog> <ShowH
Discover Begin 4 - MDSCHEMA_CUBES <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<CATALOG_NAME>dw_prep_archive_PROD</CATALOG_NAME>
<CUBE_NAME>DW PREP ARCHIVE</CUBE_NAME>
<CUBE_SOURCE>3</CUBE_SOURCE>
</RestrictionList> 106 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:36:04.000 2006-07-06 12:36:04.000 3572 25295 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Catalog>dw_prep_archive_PROD</Catalog> <ShowH
Discover End 4 - MDSCHEMA_CUBES <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<CATALOG_NAME>dw_prep_archive_PROD</CATALOG_NAME>
<CUBE_NAME>DW PREP ARCHIVE</CUBE_NAME>
<CUBE_SOURCE>3</CUBE_SOURCE>
</RestrictionList> 106 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:36:04.000 2006-07-06 12:36:04.000 78 0 3572 25295 16 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Catalog>dw_prep_archive_PROD</Catalog> <ShowH
Discover Begin 4 - MDSCHEMA_CUBES 106 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:36:09.000 2006-07-06 12:36:09.000 3572 25295 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Catalog>dw_prep_archive_PROD</Catalog> <ShowH
Discover End 4 - MDSCHEMA_CUBES 106 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:36:09.000 2006-07-06 12:36:09.000 0 0 3572 25295 0 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Catalog>dw_prep_archive_PROD</Catalog> <ShowH
Discover Begin 4 - MDSCHEMA_CUBES <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<CUBE_SOURCE>3</CUBE_SOURCE>
</RestrictionList> 106 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:36:09.000 2006-07-06 12:36:09.000 3572 25295 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Catalog>dw_prep_archive_PROD</Catalog> <ShowH
Discover End 4 - MDSCHEMA_CUBES <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<CUBE_SOURCE>3</CUBE_SOURCE>
</RestrictionList> 106 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:36:09.000 2006-07-06 12:36:09.000 16 0 3572 25295 16 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Catalog>dw_prep_archive_PROD</Catalog> <ShowH
Discover Begin 5 - MDSCHEMA_DIMENSIONS <RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">
<CUBE_NAME>DW PREP ARCHIVE</CUBE_NAME>
<CUBE_SOURCE>3</CUBE_SOURCE>
</RestrictionList> 106 DMLENZ Microsoft SQL Server Management Studio 2006-07-06 12:36:10.000 2006-07-06 12:36:10.000 3572 25295 QG <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"> <Catalog>dw_prep_archive_PROD</Catalog> <ShowH
Query Subcube 2 - Non-cache data 00000000,000000000000000000000000,0000000,00,00000000,00000000,00000000 0 2006-07-06 12:36:10.000 2006-07-06 12:36:10.000 797 dw_prep_archive_PROD 25307 531
Query Subcube 2 - Non-cache data 00000000,000000000100100000011000,0000000,00,00000000,00000000,00000000 0 2006-07-06 12:36:10.000 2006-07-06 12:36:11.000 219 dw_prep_archive_PROD 25307 1156
Query Subcube 2 - Non-cache data 00000000,000000000100100000011000,0000000,00,00000000,00000000,00000000 0 2006-07-06 12:36:19.000 2006-07-06 12:36:19.000 406 dw_prep_archive_PROD 25307 9656


Profiler that "loops"

Notification11 - Flight Recorder Snapshot Begin0 2006-07-06 12:52:29.0002006-07-06 12:52:29.000 25544

Server State Discover Begin8 - DISCOVER_LOCKS<RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">

<LOCK_MIN_TOTAL_MS>0</LOCK_MIN_TOTAL_MS>

</RestrictionList>0 2006-07-06 12:52:29.0002006-07-06 12:52:29.000 25545 <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"></PropertyList>

Server State Discover End8 - DISCOVER_LOCKS<RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">

<LOCK_MIN_TOTAL_MS>0</LOCK_MIN_TOTAL_MS>

</RestrictionList>0 2006-07-06 12:52:29.0002006-07-06 12:52:29.0000255450

Server State Discover Begin7 - DISCOVER_JOBS<RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">

<JOB_MIN_TOTAL_TIME_MS>0</JOB_MIN_TOTAL_TIME_MS>

</RestrictionList>0 2006-07-06 12:52:29.0002006-07-06 12:52:29.000 25546 <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"></PropertyList>

Server State Discover End7 - DISCOVER_JOBS<RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">

<JOB_MIN_TOTAL_TIME_MS>0</JOB_MIN_TOTAL_TIME_MS>

</RestrictionList>0 2006-07-06 12:52:29.0002006-07-06 12:52:29.0000255460

Server State Discover Begin2 - DISCOVER_SESSIONS<RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">

</RestrictionList>0 2006-07-06 12:52:29.0002006-07-06 12:52:29.000 25547 <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"></PropertyList>

Server State Discover End2 - DISCOVER_SESSIONS<RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">

</RestrictionList>0 2006-07-06 12:52:29.0002006-07-06 12:52:29.0000255470

Server State Discover Begin1 - DISCOVER_CONNECTIONS<RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">

</RestrictionList>0 2006-07-06 12:52:29.0002006-07-06 12:52:29.000 25548 <PropertyList xmlns="urn:schemas-microsoft-com:xml-analysis"></PropertyList>

Server State Discover End1 - DISCOVER_CONNECTIONS<RestrictionList xmlns="urn:schemas-microsoft-com:xml-analysis">

</RestrictionList>0 2006-07-06 12:52:29.0002006-07-06 12:52:29.0000255480

Notification12 - Flight Recorder Snapshot End0 2006-07-06 12:52:29.0002006-07-06 12:52:29.000025544

|||

This is great investigation you've done!

Unfortunately, I think the situation probably indicates problem with Analysis Services.
Dont see anything you should be doing differently.

Before you go and log your case with Customer Support Services can you please try and find a machine you can install Analysis Services SP1 into.
And see if your situaion is solved in SP1.

Feel free to contact me if you get stuck with your efforts.

Edward.
--
This posting is provided "AS IS" with no warranties, and confers no rights.

|||

Thanks for your suggestions Edward.

I'm pretty sure I found the culprit. Whether it is a bug in SSAS (or bad mdx), the person who created the cube has calculations and named sets using the calculations. I'm not entirely sure what the purpose of them were, however when I removed the named sets. the problem was solved. The cube allows me to click "Browse" without any hangups.

I am in the process of utilizing a support contract we have to determine if this is a problem.

Thanks again.

Regards,


Dan

No comments:

Post a Comment