SQL in Stockholm

SQL Server thoughts from the support team in Stockholm

SQL Server troubleshooting thoughts from Graham Kent, (ex) Senior Support Escalation Engineer at Microsoft Sweden.

  • SQL in Stockholm

    Using Xquery to query Extended Events asynchronous file target results

    • 1 Comments

    This is the follow up (part 2) to the following post:

    http://blogs.msdn.com/grahamk/archive/2009/09/23/realistic-troubleshooting-example-of-extended-events-xevent-usage-in-sql-server-2008-part-1.aspx

    In the original post we configured an extended event session and issued a very simple query to review the results as XML. Here are some more intelligent XQuery examples. I’m documenting these purely because I hate XQuery so much, and it takes so damn long to do (well it does for me anyway). Please feel free to post in the comments section if you think XQuery is the best damn query language ever invented :-)

    Hopefully the code comment explain everything, I have attempted to use very descriptive alias names as well

    -- get information from XET binary files representing extended event session date
     
    -- as per part 1 blog post:
    -- straight select, view the XML manually in an SSMS window by clicking on the XML results column
    select CAST(event_data as XML) , * 
    from sys.fn_xe_file_target_read_file
    (
    'C:\temp\ArithmeticErrors_0_128981071730370000.xet', 
    'C:\temp\ArithmeticErrors_0_128981071730390000.xem', 
    null, 
    null
    )
     
    -- Get only specific nodes
    -- 2 different methods shown of the xquery, you can specify the name of the node
    -- or you can specify its location in the structure
    -- this means that you return every row for every event captured in the file
    -- the results are then converted to SQL data types
     
    SELECT
    xdata.value('(/event/data[4]/value)[1]', 'varchar(100)') AS [error],
    xdata.value('(/event/data[@name="severity"]/value)[1]', 'int') AS [severity],
    xdata.value('(/event/action[@name="sql_text"]/value)[1]', 'varchar(max)') AS [sql_text]
     
    FROM
        (
            select CAST(event_data as XML)
            from sys.fn_xe_file_target_read_file
            (
            'C:\temp\ArithmeticErrors_0_128981071730370000.xet', 
            'C:\temp\ArithmeticErrors_0_128981071730390000.xem', 
            null, 
            null
            )
        ) as xmlr(xdata)
     
    -- using the above technique, you can now wrap the entire query and give it an alias
    -- and then perform more useful T-SQL language queries on the results
    -- here is an example of an aggregate
     
    SELECT
    convert(varchar(100), outer_results.[error]) as 'error',
    convert(int, outer_results.[severity]) as 'severity',
    convert(varchar(max), outer_results.[sql_text]) as 'sql_text',
    count(*) as [count_occurances]
    FROM
        (
        SELECT
        xdata.value('(/event/data[4]/value)[1]', 'varchar(100)') AS [error],
        xdata.value('(/event/data[@name="severity"]/value)[1]', 'int') AS [severity],
        xdata.value('(/event/action[@name="sql_text"]/value)[1]', 'varchar(max)') AS [sql_text]
     
        FROM
            (
                select CAST(event_data as XML)
                from sys.fn_xe_file_target_read_file
                (
                'C:\temp\ArithmeticErrors_0_128981071730370000.xet', 
                'C:\temp\ArithmeticErrors_0_128981071730390000.xem', 
                null, 
                null
                )
            ) as xmlr(xdata)
        ) as outer_results
    group by error, severity,sql_text
     
    -- finally using the same technique as above , here we have simple predicates as well
     
    -- add a predicate into the outer query
    SELECT
    convert(varchar(100), outer_results.[error]) as 'error',
    convert(int, outer_results.[severity]) as 'severity',
    convert(varchar(max), outer_results.[sql_text]) as 'sql_text',
    count(*) as [count_occurances]
    FROM
        (
        SELECT
        xdata.value('(/event/data[4]/value)[1]', 'varchar(100)') AS [error],
        xdata.value('(/event/data[@name="severity"]/value)[1]', 'int') AS [severity],
        xdata.value('(/event/action[@name="sql_text"]/value)[1]', 'varchar(max)') AS [sql_text]
     
        FROM
            (
                select CAST(event_data as XML)
                from sys.fn_xe_file_target_read_file
                (
                'C:\temp\ArithmeticErrors_0_128981071730370000.xet', 
                'C:\temp\ArithmeticErrors_0_128981071730390000.xem', 
                null, 
                null
                )
            ) as xmlr(xdata)
        ) as outer_results
     
    -- here is the extra predicate we have added
    where outer_results.severity < 17
    group by error, severity,sql_text
     

    I fully accept that this may not be the most reasonable way, or the most efficient way to do this, but it’s the way that I’ll be using for now.

  • SQL in Stockholm

    SQL Server 2008 SDK directory does not contain the opends60.lib file required for the creation of extended stored procedures

    • 0 Comments

    If you are trying to create extended stored procedures in SQL Server 2008, you will probably have read the BOL article here:

    Creating Extended Stored Procedures

    Hopefully you will have noticed that this feature is deprecated, and so firstly you’ll only be using this functionality for legacy requirements. That said you may have noticed that you will require the file opends60.lib to be able to create your extended stored procedure DLL. You may have noticed that you cannot find this after installing SQL Server 2008 (even if you have installed the SDK).

    The default location for the SDK directory in SQL Server 2008 is here:

    C:\Program Files\Microsoft SQL Server\100\SDK\

    However it does not contain the opends60.lib. If you need to acquire a copy of this file, currently you need to obtain it from an alternate source, namely a previous version of SQL Server SDK or from an install of a previous version of visual studio. For example the x64 version of the file can be found in the SQL Server 2005 SDK directory here:

    C:\Program Files\Microsoft SQL Server\90\SDK\Lib\x64

    You should be able to use one of these other versions instead.

  • SQL in Stockholm

    SQL Server DMV script for monitoring USERSTORE_TOKENPERM size by token type and number

    • 0 Comments

    Here’s a script I was using last week. I wrote this so that it could be used in a custom PSSDIAG / SQLDIAG task, but you can also run it in other automated methods as well.

    To include it in SQLDIAG / PSSDIAG I added a custom group section into the XML config file (see previous posts on this blog if you don’t know how to do this), and saved the file in the root of the SQLDIAG directory as exec_userstore1.sql.

    <CustomGroup name="userstore" enabled="true" />
    <CustomTask enabled="true" groupname="userstore" taskname="detailed_scripts" type="TSQL_Script" point="Startup" wait="No" cmd="exec_userstore1.sql"/>

    Here’s the script itself:

    /*
    detailed USERSTORE_TOKENPERM analysis for SQL 2005
    script designed to be packaged into PSSDIAG and run over long time frame to monitor
    but can be run individually at a fixed point to capture a snapshot
    can be used in association with script number 2 which is verbose and does a snapshot
    of all logins and token in cache, so can be HUGE.
    graham kent - microsoft css - 15th September 2009
    */
     
    SET NOCOUNT ON
    SET QUOTED_IDENTIFIER ON
    GO
     
    -- get the token type distribution
     
    WHILE 1=1
    BEGIN
     
    select 'start time:', GETDATE();
     
    SELECT 
    convert(varchar(50),[name]) as 'SOS StoreName', 
    convert(varchar(50),[TokenName]) as 'TokenName',
    convert(varchar(50),[Class]) as 'Class',
    convert(varchar(50),[SubClass]) as 'SubClass',
    count(*) as [Num Entries]
    FROM
    (SELECT name,
    x.value('(//@name)[1]', 'varchar (100)') AS [TokenName],
    x.value('(//@class)[1]', 'varchar (100)') AS [Class],
    x.value('(//@subclass)[1]', 'varchar (100)') AS [SubClass]
    FROM
    (SELECT CAST (entry_data as xml),name
    FROM sys.dm_os_memory_cache_entries
    WHERE type = 'USERSTORE_TOKENPERM') 
    AS R(x,name)
    ) a
    group by a.name,a.TokenName,a.Class,a.SubClass
     
    -- loop on 1 minute basis
    WAITFOR DELAY '00:01:00'
     
    END

    When run in this format you’ll get a text file created in the output directory used by SQLDIAG which will contain the results from the script. You can then monitor the individual items in the cache over long periods of time to see if you’re encountering any of the known issues around this security cache.

  • SQL in Stockholm

    SQL Server DMV script for searching the plan cache by query text, plan handle or execution time

    • 0 Comments

    I guess everyone has their own set of DMV scripts to hand when working with SQL Server nowadays. I thought I’d post a few of mine. Pretty much as the title says: comment in whichever clauses suit you and then run the query. Returns a result set with an XML column that can be clicked on if you want, to view the plan itself in SSMS. Works with 2005 and 2008.

    select 
    bucketid,
    a.plan_handle,
    refcounts, 
    usecounts,
    execution_count,
    size_in_bytes,
    cacheobjtype,
    objtype,
    text,
    query_plan,
    creation_time,
    last_execution_time,
    execution_count,
    total_elapsed_time,
    last_elapsed_time
     
    from sys.dm_exec_cached_plans a 
          inner join sys.dm_exec_query_stats b on a.plan_handle=b.plan_handle
        cross apply sys.dm_exec_sql_text(b.sql_handle) as sql_text
        cross apply sys.dm_exec_query_plan(a.plan_handle) as query_plan
    where 1=1
    and text like '%mybadproc%'
    -- and a.plan_handle = 0x06000B00C96DEC2AB8A16D06000000000000000000000000
    and b.last_execution_time between '2009-09-24 09:00' and '2009-09-25 17:00'
    order by last_execution_time desc
  • SQL in Stockholm

    Realistic troubleshooting example of extended events (XEvent) usage in SQL Server 2008 – Part 1

    • 0 Comments

    Here’s an example of how to collect and consume extended events in SQL Server 2008. It’s something that we in CSS are starting to use more and more frequently with the uptake of SQL 2008, and I believe it’s something that everyone who troubleshoots SQL can gain benefit from.

    Here’s a relatively simple example which is based upon real world experiences of looking at this bug in Connect, which I was looking at recently. The main thing I want to show here is how to review the results of collection yourself, as obviously the setup of the actual event collection is already described on the connect site.

    The scenario is relatively simple, and a typical one for extended event usage. You have a process which produces an arithmetic overflow at an unknown point. In the example of this bug, it’s within the SSIS package managing data upload for the performance data warehouse. It could be any large process application or tool though, which would prove more difficult to trace with something like profiler or any of the other troubleshooting tools.

    From the connect site, a colleague in the product group has asked the reporting customer to configure and run the following event session:

    -- XEvent Session Definition Arithmetic error, Log additional info
     
    -- Sample Query: select convert(bigint,21568194 * 100)
    if exists(select * from sys.server_event_sessions where name='ArithmeticError')
         DROP EVENT SESSION ArithmeticError ON SERVER
    go
     
    CREATE EVENT SESSION ArithmeticError ON SERVER
    ADD EVENT sqlos.exception_ring_buffer_recorded (
    ACTION (sqlserver.tsql_stack, sqlserver.sql_text)
                     WHERE (error = 8115 ))
    ADD TARGET package0.ring_buffer,
    ADD TARGET package0.asynchronous_file_target(
    SET filename='c:\temp\ArithmeticErrors.xet', metadatafile='c:\temp\ArithmeticErrors.xem')
    WITH (MAX_MEMORY = 4096KB, 
    EVENT_RETENTION_MODE = ALLOW_MULTIPLE_EVENT_LOSS, 
    MAX_DISPATCH_LATENCY = 1 SECONDS, 
    MAX_EVENT_SIZE = 0KB, 
    MEMORY_PARTITION_MODE = NONE, 
    TRACK_CAUSALITY = OFF, 
    STARTUP_STATE = OFF)
     
    go
     
    ALTER EVENT SESSION ArithmeticError ON SERVER
    state=start
    go
     
    -- Cleanup the session 
    -- drop EVENT SESSION ArithmeticError ON SERVER
     
     

    You can run this code as is on a test server to try out the demo. You’ll need to ensure that you have a c:\temp directory for the results to output to a file. There are several different ways that you can consume or record the output from an extended event, but here we are writing to a file as said files can then easily be uploaded to us here at Microsoft. You can read about some of the other alternatives in the Books Online link above if you want.

    Once you have the event set up, you can trigger the 8115 error, by un-commenting the “sample query” line at the top of the script. When you run it in SSMS, you should encounter the following error:

    Msg 8115, Level 16, State 2, Line 1
    Arithmetic overflow error converting expression to data type int.

    If you then look in the c:\temp directory, you ought to notice the files the session is writing to have been created, however at this stage, the .xet file (which actually holds the event data as opposed to the xem file which holds the event meta data required to decode the event itself) is actually empty. This is because the session is still active and the data has not been flushed to the file. If you run the following to stop (but not drop) the event

     
    ALTER EVENT SESSION ArithmeticError ON SERVER
    state=stop
    go
    Then the data will be written to the file. You’ve now capture enough data for the purposes of this test, so you can drop the event session, the syntax for which is
    drop EVENT SESSION ArithmeticError ON SERVER

    So the question then comes, what to do with the files. I have to admit it took me a while to work this out, as it wasn’t obviously documented. I also needed the help of my good friend and pool partner, Spike, to write some XQuery in a nice way, as I don’t really like XQuery. The function is documented in Books Online though to be fair (although not the XQuery!)

    There are 2 different ways you can go about reading this type of file in my opinion. Firstly you can just run the following query in SSMS and you’ll get an XML column in the results pain, if you output to grid. You can then just click on the column and you’ll get to look at the XML document in a new SSMS window. Quick and undeniably dirty yes, but it works quite effectively for a simple scenario like this:

    -- straight select, view the XML manually
    select CAST(event_data as XML) , * 
    from sys.fn_xe_file_target_read_file
    (
    'C:\temp\ArithmeticErrors_0_128981030796910000.xet', 
    'C:\temp\ArithmeticErrors_0_128981030796920000.xem', 
    null, 
    null
    )

    Note that the actual file names have been modified automatically by the event engine to guarantee uniqueness. When you run this, you should get an output grid which looks like this:

    image

    If you then click on the first XML column, you’ll open up a new tab with the XML document for viewing, which will look something like this:

    <event name="exception_ring_buffer_recorded" package="sqlos" id="21" version="1" timestamp="2009-09-22T14:33:06.537Z">
      <data name="id">
        <value>0</value>
        <text />
      </data>
      <data name="timestamp">
        <value>0</value>
        <text />
      </data>
      <data name="task_address">
        <value>0x00000000000ffdc8</value>
        <text />
      </data>
      <data name="error">
        <value>8115</value>
        <text />
      </data>
      <data name="severity">
        <value>16</value>
        <text />
      </data>
      <data name="state">
        <value>2</value>
        <text />
      </data>
      <data name="user_defined">
        <value>false</value>
        <text />
      </data>
      <data name="call_stack">
        <value />
        <text />
      </data>
      <action name="tsql_stack" package="sqlserver">
        <value>&lt;frame level='1' handle='0x01000100FC030E3850E97786000000000000000000000000' line='1' offsetStart='0' offsetEnd='0'/&gt;</value>
        <text />
      </action>
      <action name="sql_text" package="sqlserver">
        <value>select convert(bigint,21568194 * 100)</value>
        <text />
      </action>
    </event>

    Most of this XML ought to be self explanatory. The bit that is most interesting to us here is the “sql_text” section which shows the actual text being executed. In a real world scenario where we didn’t know what code was causing our error, we’ve now tracked it down.

    The tsql_stack section is also useful. You can pass the handle you get back from this section into a DMV to get further details about the object or statement being executed (if it’s part of a stored procedure for example). A typical syntax for this would be

    SELECT * FROM sys.dm_exec_sql_text(0x01000100FC030E3850E97786000000000000000000000000)

    However, you should note that in this very simple example, this will return nothing. This is because a plan has not been cached for our simple select statement that only does a mathematical  calculation. This is of course possible in other scenarios where the plan which was used at the time the event captured it, is no longer cached, due to it being aged out, or the server being re-started.

    If you want to follow this example and be able to look at the sql_text plan handle, then you need to write an actual query which fetches data and has an arithmetic overflow. For example, simple procedure like this

    create procedure mybadproc
     
    as
     
    select *
    from sys.servers
     
    select convert(bigint,999999999 * 100)

    will cache a plan when executed, and will be captured by the same event session we set up above. If you execute this, or other more complex statements / procedures, you can get back multiple items in the tsql_stack, each with separate handles which you can then pass into DMV based queries which accept plan handles. If you capture the execution of the above procedure in this event session, you’ll get back a slightly different XML document, where the tsql_stack has multiple values and the sql_text is now the name of the procedure that we executed. You can then pass any of the handles into DMV queries which accept such parameters.

    <action name="tsql_stack" package="sqlserver">
       <value>&lt;frame level='1' handle='0x03000D00E7A4787D959020018C9C00000100000000000000' line='8' offsetStart='132' offsetEnd='-1'/&gt;
              &lt;frame level='2' handle='0x01000D00D8E5380F60E77786000000000000000000000000' line='1' offsetStart='0' offsetEnd='-1'/&gt;</value>
       <text />
     </action>
     <action name="sql_text" package="sqlserver">
       <value>mybadproc</value>
       <text />
     </action>
    /event>

    So to summarise part 1 of this post, we’ve looked at how to setup an extended event session and capture the output to a file. We’ve then seen a very simple way of looking at the output to manually identify a condition captured by our session. In the next part I’ll show some XQuery to review the output in more detail.

  • SQL in Stockholm

    Troubleshooting SQL Server performance problems associated with low memory conditions – should I use sys.dm_os_ring_buffers

    • 0 Comments

    I recently received a question through this blog about the use of the sys.dm_os_ring_buffers DMV with regard to troubleshooting performance problems and low memory conditions. Here are some excerpts – edits from my reply which might provide some ideas for you.

    Here's an interesting article you might like to read about monitoring memory usage with ring buffers:

    http://blogs.msdn.com/slavao/archive/2005/02/19/376714.aspx

    In terms of my personal preferences regarding performance monitoring in SQL Server 2005, I find it rare that I have to use the ring buffers. They are of course undocumented externally (which is why you are having trouble finding information on them!), and so I tend to discuss with customers the usage of published documented tools as in 99% of cases these are enough to diagnose memory problems (and most others).

    I would potentially take a different approach. As I often write in my blog I like to use the SQLDIAG tool to collect a variety of data when I am experiencing / monitoring a problem. In this case it might be useful to follow my post about collecting the DBCC MEMORYSTATUS output, in addition to the standard data when you are experiencing this problem. If you have experiencing a memory issue somewhere, this will give you the breakdown to diagnose it pretty much in all cases, and all the results of this output are publically documented. Alternatively though you could change the script which collects DBCC MEMORYSTATUS to collect some other hybrid selection of DMV based output, or even the ring buffers output.

    The other benefit of this approach is that you collect a whole set of data which allows you to keep an open mind (which I like to do) about what the cause of the performance problem really is.

    So in summary, should a customer come to me with a rough issue description like this (I have performance problems and I believe I am experiencing low memory conditions, my initial action plan would be as follows:

    Run SQLDIAG for 30 minutes when the problem was occurring

    Collect the SQL 2005 perfstats scripts

    Collect DBCC MEMORYSTATUS add in

    Collect a lightweight profiler (do not include statement level events or showplans)

    Collect perfmon with all SQL Server counters like Buffer Manager added in .

    And then I would review all the data. You could of course consider using SQLNEXUS to do this, or alternatively review the output manually as its all from documented in sources.

    Here is a particularly good article which covers a lot of these documented issues, and has an excellent section of memory troubleshooting.

    http://technet.microsoft.com/en-us/library/cc966540.aspx

    Finally I just remembered that there is this public article as well which does document a good use for the sy.dm_os_ring_buffer output for a specific condition.

    How to reduce paging of buffer pool memory in the 64-bit version of SQL Server

    Update: another more detailed post about resource manager and the ring buffer records it writes is now available here:

    http://blogs.msdn.com/psssql/archive/2009/09/17/how-it-works-what-are-the-ring-buffer-resource-monitor-telling-me.aspx

    That said my comments still remain the same when you are going into a more generic performance problem.

    Graham

  • SQL in Stockholm

    Fixed - incorrect CPU time reported by sys.dm_exec_query_stats for parallel plans

    • 0 Comments

    I was discussing with Elisabeth back in this blog post about the above problem, and made comments that there were no plans currently to backport this to SQL 2005 or 2008. This changed following feedback both from customers and from us within CSS, and the fix was made part of SQL Server 2008 SP1. You'll note if you look at the KB article for SP1, that it doesn't have it's own KB, but it does get a mention in the fix list.

    Enjoy!

Page 1 of 1 (7 items)