zoukankan      html  css  js  c++  java
  • 查看语句运行时间异常的原因(SQLServer)

    转载:http://www.cnblogs.com/fygh/archive/2012/01/17/2324926.html

    查看语句运行时间异常的原因(SQLServer)

     

        经常有开发同事反映如下情况:我有一条语句或者一个JOB昨天跑半个小时就完成了,今天怎么跑了两个小时还没有完成?

    是不是数据库出现问题了?

        数据库语句运行时间异常,其实是一个比较复杂的情况,因为数据是不断变动的,今天好好的一条语句,有可能明天运行就

    不在预计的时间内了,这个场景是没办法完全重溯的,即便有当时的备份数据,但是当时的服务器压力是没有办法知道和营造

    的;但是好在现在不是要调查昨天语句跑时间异常的原因,而是要找到现在语句运行异常的原因,现在的情况还正在进行着呢,

    所以我们可以根据语句目前的情况,初步来排查一下;

        其实要考虑的问题比较多:

        1. 索引是否正常(索引是否损坏、有没有人删除索引等);

        2. 统计信息是否过时;

        3. 语句执行计划是否发生偏移(和索引、统计信息以及数据量都有关系);

        4. 语句是否有bug;

        5. 是否发生的阻塞;

        6. 系统资源是否遇到瓶颈;

        .........

        这么多的情况都考虑的话我们很难下手,一般解决这个问题我们都需要采用比较快的方式来做排查,以下方法主要针对5和6两

    个方面进行,因为这两个方面是最常见的情况。

    我们来简单模拟一下排查过程:

    1. 创建测试表和数据

    复制代码
    USE [master]
    
    GO

    /****** Object: Table [dbo].[a] Script Date: 01/17/2012 16:46:34 ******/
    SET ANSI_NULLS ON
    GO

    SET QUOTED_IDENTIFIER ON
    GO

    SET ANSI_PADDING ON
    GO

    CREATE TABLE [dbo].[a](
    [id] [int] IDENTITY(1,1) NOT NULL,
    [name] [varchar](100) NULL
    ) ON [PRIMARY]

    GO

    SET ANSI_PADDING OFF
    GO


    insert into a values('aa'),('bb'),('cc')
    复制代码

    2. 制造阻塞:开两个session,分别运行下面的语句

    复制代码
    --Session 1
    use master

    go
    begin tran
    update A set name='abc' where id=2

    --rollback


    --Session 2
    select * from a
    复制代码

    因为Session1 的Update语句没有能够提交,所以此时Session2 过程会被阻塞


    3. 分析排查:

      我们首先需要查询下此时数据库中是否存在阻塞:

    --Blocked
    select * from sys.sysprocesses with(nolock) where blocked<>0


     我们看到了阻塞的记录,53阻塞了56,被阻塞的资源是:dbid 1 file 1 page 307;

     接下来我们需要知道阻塞和被阻塞的是什么语句,有两种方式:

     a. dbcc inputbuffer

     b. sys.dm_exec_sql_text

     方法一与方法二相比:

       优点:方法一能显示非活动session的语句,方法二只能查活动的session(通过sp_who2 active 能显示是否活动);

       缺点:方法一只能一个一个查询,方法二可以多个一起查询;

    方法一:

    --No1:
    dbcc inputbuffer(53)

    go
    dbcc inputbuffer(56)

    方法二:

    复制代码
    --No2:
    SELECT

    S.session_id, R.blocking_session_id,
    S.host_name, S.login_name,
    databaseName=DB_NAME(R.database_id),R.command, R.status,
    current_execute_sql = SUBSTRING(T.text,
    R.statement_start_offset / 2 + 1,
    CASE
    WHEN statement_end_offset = -1 THEN LEN(T.text)
    ELSE (R.statement_end_offset - statement_start_offset) / 2+1
    END),
    S.program_name,
    S.status,
    S.cpu_time, memory_usage_kb = S.memory_usage * 8, S.reads, S.writes,
    S.transaction_isolation_level,
    C.connect_time, C.last_read, C.last_write,
    C.net_transport, C.client_net_address, C.client_tcp_port, C.local_tcp_port,
    R.start_time,
    R.wait_time, R.wait_type, R.last_wait_type, R.wait_resource,
    R.open_transaction_count, R.transaction_id

    FROM sys.dm_exec_sessions S
    LEFT JOIN sys.dm_exec_connections C
    ON S.session_id = C.session_id
    LEFT JOIN sys.dm_exec_requests R
    ON S.session_id = R.session_id
    AND C.connection_id = R.connection_id
    OUTER APPLY sys.dm_exec_sql_text(R.sql_handle) T
    WHERE S.is_user_process = 1 -- 如果不限制此条件,则查询所有进程(系统和用户进程)
    and s.session_id in(53,56)
    复制代码

    我们看到方法一两条语句都能查出来,而方法二只能查出一个语句;

    到这里,我们已经能判断语句运行慢的原因是被阻塞了,我们再来查查阻塞的原因是什么,可以通过以下语句查看:

    select request_session_id,resource_type,db_name(resource_database_id) as DBName,resource_description,
    
    request_mode,request_type,request_status from sys.dm_tran_locks where request_session_id in(56,53)
    order by request_session_id

    可以看到,56处于WAIT状态,它在等待获取1:307:1 上的一个共享锁,但是1:307:1上被53的一个排他锁占据了(GRANT代表

    已获得资源,正在运行),因此56必须等待53上的排他锁释放后才能继续运行;于是我们转而调查53排他锁没有释放的原因;可能是

    53需要的其他资源被其他进程占有了,在等待其他进程释放锁;也可能是因为Update语句更新的数据量过多,需要的时间比较长,不

    能够及时的释放锁;还有就是我们现在的情况,没有提交事物了(语句中可以直接看到);阻塞的排查方法都是类似的。

     

    如果语句并没有被其他语句blocked呢? 那我们需要再进一步查找的原因就是Wait了,前面已经有wait的相关查询,下面我们来查下

    更具体的信息:

    复制代码
    -- wait & lock
    select lo.request_session_id as [Session],

    DB_NAME(lo.resource_database_id) as Dbname,
    lo.resource_type as [Type],
    lo.resource_description,
    lo.request_mode,
    lo.request_owner_type,
    lo.request_status,
    case when lo.resource_type='OBJECT' then OBJECT_NAME(lo.resource_associated_entity_id)
    when lo.resource_associated_entity_id IS NULL OR lo.resource_associated_entity_id=0
    then NULL
    else OBJECT_NAME(p.object_id)
    end as Associated_Entity,
    wt.blocking_session_id,wt.resource_description
    from
    sys.dm_tran_locks lo with(nolock)
    left join sys.partitions p with(nolock)
    on lo.resource_associated_entity_id=p.partition_id
    left join sys.dm_os_waiting_tasks wt with(nolock)
    on lo.lock_owner_address=wt.resource_address
    where lo.request_session_id>50
    and lo.request_session_id=56
    order by [Session] ,[TYPE]
    复制代码

    上面可以看到,56在获取共享资源1:307:1时,遇到了等待,当然这里的等待还是被53阻塞了,但是等待会有多种原因的等待,我们查

    一下当前的等待信息:

    复制代码
    --current wait info
    select wait_type,COUNT(0) as num_waiting_tasks,

    SUM(wait_duration_ms) as total_wait_time_ms
    from sys.dm_os_waiting_tasks with(nolock)
    where session_id>50
    group by wait_type
    order by wait_type
    复制代码

    这里可以看到是锁等待(Wait_Type),还有很多资源类型的等待,值的重点关注的有:
      Memory:CMEMTHREAD ,RESOURCE_SEMAPHORE
         CMEMTHREAD:
           说明和原因:计划缓存出现问题的标志(大量计划加入或者移出);
           解决:     使用参数化的查询或者设置数据库强制参数化(forced parameterization)

         RESOURCE_SEMAPHORE:
           说明和原因:内存密集型查询无法获得请求的内存;其他进程消耗了太多的内存;
           解决:     为数据库添加合适的索引或者增加内存

      IO:IO_COMPLETION,ASYNC_IO_COMPLETION,WRITELOG,PAGEIOLATCH_*

      CPU: CXPACKET,SOS_SCHEDULER_YIELD
           CXPACKET:
              说明和原因:并行处理等待类型,并行同步等待;
              解决:     可以通过修改并行度的值(或者禁用)解决;
           SOS_SCHEDULER_YIELD:
              说明和原因:任务执行到时间片尾,让出调度器给其他任务运行;
              解决:     需要处理能力更好的CPU
     
      Network:ASYNC_NETWORK_IO,DBMIRROR_SEND
           ASYNC_NETWORK_IO: 网卡带宽饱和或者客户端不能及时把结果取走;
           DBMIRROR_SEND:  网络带宽不足以支持镜像事务量或者镜像数据库超出限额;

      锁阻塞:LCK_*    


    我们可以统计下,我们数据库最多的20种等待类型:

    复制代码
    --total wait info
    select top 20 wait_type,SUM(waiting_tasks_count) waiting_tasks_count,

    SUM(wait_time_ms)as total_wait_time_ms,
    SUM(signal_wait_time_ms) as total_signal_wait_time_ms
    from sys.dm_os_wait_stats with(nolock)
    where wait_type not in
    --system wait type
    ('LAZYWRITER_SLEEP','REQUEST_FOR_DEADLOCK_SEARCH','SQLTRACE_BUFFER_FLUSH',

    'XE_TIMER_EVENT','FT_IFTS_SCHEDULER_IDLE_WAIT','LOGMGR_QUEUE','CHECKPOINT_QUEUE',
    'SLEEP_TASK','BROKER_IO_FLUSH','BROKER_TASK_STOP','BROKER_TO_FLUSH','BROKER_EVENTHANDLER')
    group by wait_type
    order by total_wait_time_ms desc
    复制代码

    通过这个我们可以从中看出DB等待主要集中在哪些方面,如果是在CPU、IO、Memory、Lock等上面等待时间很长,说明我们

    的数据库需要做某些方面的优化了。

        以上就是从阻塞和等待方面,对运行时间异常的语句做初步排查的过程,欢迎大家拍砖。

  • 相关阅读:
    FrameBuffer系列 之 一点资源
    FrameBuffer系列 之 显示图片
    FrameBuffer系列 之 相关结构与结构体
    FrameBuffer系列 之 介绍
    FrameBuffer系列 之 简单编程
    程序员五大层次,你属于哪一层?
    提高编程效率的14件事
    GTK简单了解记录
    __read_mostly变量含义
    [系统启动]Printk与sched_clock_init的一点分析
  • 原文地址:https://www.cnblogs.com/PatrickLee/p/3160881.html
Copyright © 2011-2022 走看看