2012年10月17日星期三

一次由重复索引导致的问题

一次由重复索引导致的问题

    最近一个朋友公司的OA系统总是出故障,具体表现在某个特定用户在登录后,无法查看自己的任务。等过了一会后,就报503错误。让我帮忙看看。

    首先服务器是JBOSS,数据库是SQL Server 2005 64位企业版。

    根据以上提供的信息,首先找到JBOSS日志,当某个用户登录后点查看待办任务,JBOSS日志就会显示:

   

ERROR [org.jboss.ejb.plugins.LogInterceptor] TransactionRolledbackLocalException in method: public abstract xxxx xxx(), causedBy:
org.jboss.util.NestedSQLException: No ManagedConnections available within configured blocking timeout ( 30000 [ms] ); - nested throwable: (javax.resource.ResourceException: No ManagedConnections available within configured blocking timeout ( 30000 [ms] ))
    at org.jboss.resource.adapter.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:106)
    at com.adobe.pof.ConnectionWrapper.getConnection(ConnectionWrapper.java:25)
    at com.adobe.pof.ConnectionWrapper.getMetaData(ConnectionWrapper.java:101)
    at com.adobe.pof.POFBean.getAdapter(POFBean.java:120)
    at com.adobe.pof.omapi.POFObjectManagerRemoteBean.getObjectManagerImpl(POFObjectManagerRemoteBean.java:108)
    at com.adobe.pof.omapi.POFObjectManagerRemoteBean.getEnvironment(POFObjectManagerRemoteBean.java:489)
    at sun.reflect.GeneratedMethodAccessor144.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:592)
    at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:683)

 

    根据报错日志,很明显问题是出在连接超时。当超时超过30秒后,数据库Session断开。然后服务器报503错误。而只有这个特定用户存在这个问题,测试了几个其它用户均不存在这个问题,因此可以知道错误应该没出在应用程序那一端。

    由于只有这个特定用户存在这个问题,因此也基本排除数据库无法连接,T-SQL代码存在一些问题等原因。

    因此,超时我首先想到是阻塞,阻塞我首先想到可能是锁引起的。我先运行了这个代码来看哪个session下锁跑得最多。

SET TRANSACTION ISOLATION LEVEL READ UNCOMMITTED
SELECT COUNT(*),request_session_id FROM
(
SELECT DB_NAME(resource_database_id) AS DatabaseName
, request_session_id
, resource_type
, CASE
WHEN resource_type = 'OBJECT'
THEN OBJECT_NAME(resource_associated_entity_id)
WHEN resource_type IN ('KEY', 'PAGE', 'RID')
THEN (SELECT OBJECT_NAME(OBJECT_ID)
FROM sys.partitions p
WHERE p.hobt_id = l.resource_associated_entity_id)
END AS resource_type_name
, request_status
, request_mode
FROM sys.dm_tran_locks l

) AS a
GROUP BY a.request_session_id

 

    发现session id为150的连接上跑了4000+个锁。再通过sys.dm_tran_locks 来具体的看,发现这些锁都是key级的S锁,以及对应Page和表上的IS锁。当30秒过后超时,所有这些锁都会被自动释放。

    我产生两个疑问:

    1.为什么仅仅是这个用户一查看数据库就会产生这么多的锁,而其它用户不会产生这么多锁呢?

    2.为什么4000+个锁没有升级呢?

 

    带着这个疑问,我使用Profiler对这个Session ID查看待办工作时的操作进行了抓取。发现对应的T-SQL语句仅仅是一个普通的Select语句。为了看清返回的行数,我使用未提交读看到这个用户尚待办的工作有1900条(用户是一个地区的经理,所有地区产生的任务无论他是否参与都要转给他一个),而其它不产生阻塞的用户待办工作不超过50条。

    4000+个锁没有升级我想是因为表上存在了意向锁。

    因此我怀疑表上的多个索引之间在选择多条语句时可能产生互相阻塞。因此对相关的表上索引进行查看,发现在用于关联用户和任务的assignment表中存在两个索引的最左列完全一样,估计这里就是产生问题的根源。

    因此kill掉Session 150之后,Drop了那个键少的索引。问题解决!


TAG: