一次日志爆满引发的数据库无法访问

依然记得那天早晨，踏进办公室的瞬间，即被严肃的气氛给震慑住了。

最有活力的 90 后们，也不像往常一样活跃了。他们很紧张的盯着屏幕，在反复的 debug CRM 界面。明明代码一切都正常，为什么就是提示系统错误呢！

接着数据库开发也爆出问题了，” 我们的查询，哪怕最简单的查询都报错了，整个系统跪了！” 毫无疑问，数据库问题。

因为是在 UAT ，所以也没太在意，我依然啃着自己手里的苹果。心想，能登进去库，问题就不大。随手就简单敲了一下：

SELECT TOP 1 *

FROM sys.tables WITH(NOLOCK)

前面记不大清楚了，只记得后面是这么提示错误的： Transaction full， because of replication

嗯，问题就是日志满了嘛！

打开自己的开发工具库，里面藏了各种自己的看家本领脚本，运行了这么一条：

DBCC SQLPERF(LOGSPACE)

一看日志 99.98%

我们的数据库采取了读写分离的机制，用的是 CDC ( change data capture) 技术。因此日志会增长非常快。

虽然 UAT 上开启了 CDC 模式，但并没有实现读写分离，白白造成了日志文件的浪费。

所以果断丢弃这些日志:

EXEC sp_repldone @xactid = NULL

, @xact_segno = NULL

, @numtrans = 0

, @time = 0

, @reset = 1

再跑一次 DBCC SQLPERF(LOGSPACE)， 日志 0.5%.

整个系统恢复了。

其实在生产系统做好备份是不会出现类似的情况的。原理看我写的这个系列：

但是在这里想说的是，我们可以监控到类似情况的发生，从而积极主动的去避免它。

所以故事才刚刚开始！我们前面的文章《用好三张 DMV， 检测 80% 的性能故障》中最后一张 DMV 登场了，它就是 sys.dm_os_performance_counters

我们用它主要可以来监控这些指标：

1 Buffer Node - Page life expectancy

2 General Statistics - Logins/sec

3 General Statistics - Active Temp Tables/sec

4 General Statistics - User Connections

5 Database - Active Transactions

6 Access Methods - Full Scans/sec

7 Databases - Active Transactions - instance_name = tempdb

8 Databases - Percent Log Used - instance_name = crmdb

9 Databases - Active Transactions - instance_name = crmdb

10 Memory Manager - Connection memory(Kb)

, Free Memory(Kb)

, Reserved Server Memory(Kb)

, SQL Cache Memory(Kb)

,Target Server memory(KB)

, Total Server Memory(kb)

挑几个讲讲：

Page Life Expectancy:

存储的是数据页待在内存中的时长。待得越长，说明内存充足，极大满足了查询性能要求。

数据从磁盘读到内存需要花时间，如果我们能将整个数据库放在内存里，那么就可以解决一大部分性能缓慢的问题了

Target Server Memory:

系统在一个稳定的状态下，满足查询性能要求，需要的内存总量。

Total Server Memory:

服务器目前分配给 SQL Server 进程的内存大小。

如果 Total Server Memory 比 Target Server Memory 小很多，说明服务器分配给 SQL Server 的内存不多，这样数据库性能自然跟不上；

如果 Total Server Memory 与 Target Server Memory 差不多，比例接近 1， 说明 SQL Server 要什么有什么，内存充足。

通过采集这张 DMV， 我们可以统计出以下有用的图：

日志图显示 8 小时之内，日志文件会被占满，因此及时清理日志文件，就能避免前面提到的异常。断崖式的下降，就是清理了日志造成的

Total Server Memory vs Target Server Memory 偶尔也会有内存压力，但是普遍良好。

脚本如下：

CREATE TABLE T_PERFORMANCE_COUTNERS

( ID BIGINT IDENTITY(1,1) NOT NULL

, AUDIT_DATETIME DATETIME

, OBJECT_NAME NVARCHAR(128)

, COUNTER_NAME NVARCHAR(128)

, INSTANCE_NAME NVARCHAR(128)

, CNTR_VALUE BIGINT

, CNTR_TYPE INT

)

CREATE INDEX IDX_OBJ_CNTER ON T_PERFORMANCE_COUTNERS(AUDIT_DATETIME,OBJECT_NAME,COUNTER_NAME) ;

DECLARE @INC_TIME_PERIOD INT = 5 ;

DECLARE @WAIT_DELAY VARCHAR(20) = '' ;

SET @WAIT_DELAY = LEFT( '00:' + RIGHT('00'+CONVERT(VARCHAR,@INC_TIME_PERIOD),2),5 )

WHILE(EXISTS(SELECT * FROM T_GLOBAL_WAIT_COLLECT_PROGRESS_CONTROL WHERE ENABLED_FLAG=1))

BEGIN

INSERT INTO T_PERFORMANCE_COUTNERS (

AUDIT_DATETIME

,OBJECT_NAME

,COUNTER_NAME

,INSTANCE_NAME

,CNTR_VALUE

,CNTR_TYPE

)

SELECT

GETUTCDATE() AS AUDIT_DATETIME

,object_name

,counter_name

,instance_name

,cntr_value

,cntr_type

FROM sys.dm_os_performance_counters WITH(NOLOCK)

WAITFOR DELAY @WAIT_DELAY ;

END

最后一图用到了 pivot 来画双指标，脚本如下：

; WITH BASE_QUERY AS (

SELECT AUDIT_DATETIME, ROW_NUMBER() OVER ( ORDER BY AUDIT_DATETIME) AS RNK

FROM (SELECT DISTINCT AUDIT_DATETIME FROM T_PERFORMANCE_COUTNERS WITH(NOLOCK) ) TMP

)

, CAL_QUERY_CURRENT AS ( SELECT HIS.AUDIT_DATETIME,LTRIM(RTRIM(OBJECT_NAME))AS OBJECT_NAME

,LTRIM(RTRIM(COUNTER_NAME)) AS COUNTER_NAME,CNTR_VALUE

FROM T_PERFORMANCE_COUTNERS HIS

INNER JOIN BASE_QUERY BQ ON HIS.AUDIT_DATETIME = BQ.AUDIT_DATETIME

WHERE LTRIM(RTRIM(COUNTER_NAME)) Collate Latin1_General_CI_AI IN (N'Total Server Memory (KB)',N'Target Server Memory (KB)')

)

SELECT AUDIT_DATETIME,OBJECT_NAME, ps.[Target Server Memory (KB)], ps.[Total Server Memory (KB)]

FROM CAL_QUERY_CURRENT t

PIVOT( MAX(CNTR_VALUE)

FOR COUNTER_NAME IN ([Target Server Memory (KB)],[Total Server Memory (KB)])

) ps

谢谢阅读与分享。

欢迎关注【有关SQL】