## 背景 SQLServer Agent作為Windows服務提供給用戶定期執行管理任務，這些任務被稱為Job；考慮應用鏡像的場景如何解決Job同步問題，AWS RDS的做法是不予理會，由用戶維護Job，假如發生切換用戶需要在新的Principal端創建Job；另一種做法是鏡像端保持同步Job，切換后盡量讓用戶無感知不需要多余維護動作，但這種做法在某些情況會遇到非常嚴重的問題——內存耗盡。 ## 問題排查分析 ### 第一次分析 問題發生時實例的ERRORLOG出現： ~~~ Error: 701, Severity: 17, State: 123. ~~~ 并且記錄了 MEMORYSTATUS，根據 MEMORYSTATUS 的信息本身已經可以做推斷，但既然有現場 我們不妨用DAC（Dedicated Administrator Connection）看一下： ~~~ SELECT TOP 10 [type], sum ( single_pages_kb) as [SPA MEM/KB], SUM(multi_pages_kb) AS [MPA MEM/KB] FROM sys.dm_os_memory_clerks GROUP BY type ORDER BY SUM ( single_pages_kb+multi_pages_kb) DESC ; ~~~  內存占用 占用最多的 OBJECTSTORE_SNI_PACKET、MEMORYCLERK_SQLCONNECTIONPOOL 一般跟連接數、network packet size有關； ~~~ select c.session_id, c.net_packet_size, s.host_name as client_host_name, s.program_name, s.client_interface_name from sys.dm_exec_connections c join sys.dm_exec_sessions s on c.session_id = s.session_id join sys.endpoints e on c.endpoint_id = e.endpoint_id order by c.net_packet_size desc ~~~  net_packet_size ~~~ select value_in_use from sys.configurations where configuration_id=1544 select program_name,count(*) as conn_num from sys.sysprocesses where spid>50 group by program_name order by conn_num desc ~~~  內存規格 1W+的鏈接保持，根據`sys.dm_exec_sessions.program_name`可以確認都來自SQLServer Agent，每個session的packet size是4K，實例的max server memory是1G，所以出現內存耗盡； 那么這1W個鏈接在干嘛？根據`sys.dm_exec_sessions.program_name`中暴露的job_id我們找到對應的Job，先看下這個Job要做什么； ~~~ select * from msdb.dbo.sysjobs where job_id=0x825F84340AFD5B4BA1D5AD82A8E76C1A ~~~  Job信息 ### 第一次推論 這部分內容涉及業務邏輯我不再貼出，重點是Job_Step使用的DATABASE是鏡像中的（RESTORING），因為鏡像的DB不可用，Schedule又設置的過于頻繁，所以SQLServer Agent沒能及時釋放這部分鏈接導致內存耗盡。 ### 第一次驗證 重新搭建了一個測試環境，制造類似的場景但問題并沒能復現。感興趣的小伙伴可以測試下：鏡像 + Mirror端Job + Job鏈接鏡像庫且頻度調成10s + Job內容不限（為什么不限后續通過Profiler可以看出）。 借助Profiler和Session相關視圖我們可以看出，當Job-Step的鏈接DB設置為鏡像DB時，會出現： ~~~ Error: 18456, Severity: 14, State: 38. ~~~ 表示賬號校驗成功但數據庫不可訪問或登錄權限不夠，SQLServer Agent會重試多次，但最后都會釋放鏈接，這跟之前的推論不符。  Profiler信息 ~~~ select program_name,count(*) as conn_num from sys.sysprocesses where spid>50 group by program_name order by conn_num desc ~~~  connection ### 第二次分析 回到原現場，我們再做分析；嘗試復現時我們發現完整的鏈接都無法建立，但這1W個鏈接是如何做到的： ~~~ select spid,program_name,loginame,login_time as time,db_name(dbid) as dbname from sys.sysprocesses where spid>50 ~~~  dbname 根據spid我們看一下未釋放的鏈接最后執行的SQL是什么：  inputbuffer ~~~ (@P1 nvarchar(max),@P2 uniqueidentifier,@P3 int,@P4 int)DECLARE @logTextWithPreAndPost nvarchar(max) set @logTextWithPreAndPost = N'' + @P1 + N''; EXECUTE msdb.dbo.sp_write_sysjobstep_log @job_id = @P2, @step_id = @P3, @log_text=@logTextWithPreAndPost, @append_to_last=@P4 ~~~ 看下?`msdb.dbo.sp_write_sysjobstep_log`這個存儲過程： ~~~ exec sp_helptext 'sp_write_sysjobstep_log' Text ------------------------------------------------------------------------------- CREATE PROCEDURE sp_write_sysjobstep_log @job_id UNIQUEIDENTIFIER, @step_id INT, @log_text NVARCHAR(MAX), @append_to_last INT = 0 AS BEGIN DECLARE @step_uid UNIQUEIDENTIFIER DECLARE @log_already_exists int SET @log_already_exists = 0 SET @step_uid = ( SELECT step_uid FROM msdb.dbo.sysjobsteps WHERE (job_id = @job_id) AND (step_id = @step_id) ) IF(EXISTS(SELECT * FROM msdb.dbo.sysjobstepslogs WHERE step_uid = @step_uid )) BEGIN SET @log_already_exists = 1 END --Need create log if "overwrite is selected or log does not exists. IF (@append_to_last = 0) OR (@log_already_exists = 0) BEGIN -- flag is overwrite --if overwrite and log exists, delete it IF (@append_to_last = 0 AND @log_already_exists = 1) BEGIN -- remove previous logs entries EXEC sp_delete_jobsteplog @job_id, NULL, @step_id, NULL END INSERT INTO msdb.dbo.sysjobstepslogs ( log, log_size, step_uid ) VALUES ( @log_text, DATALENGTH(@log_text), @step_uid ) END ELSE BEGIN DECLARE @log_id INT --Selecting TOP is just a safety net - there is only one log entry row per step. SET @log_id = ( SELECT TOP 1 log_id FROM msdb.dbo.sysjobstepslogs WHERE (step_uid = @step_uid) ORDER BY log_id DESC ) -- Append @log_text to the existing log record. Note that if this -- action would make the value of the log column longer than -- nvarchar(max), then the engine will raise error 599. UPDATE msdb.dbo.sysjobstepslogs SET log .WRITE(@log_text,NULL,0), log_size = DATALENGTH(log) + DATALENGTH(@log_text) , date_modified = getdate() WHERE log_id = @log_id END RETURN(@@error) -- 0 means success END ~~~ MSDN 沒有找到詳盡 Document，但看完定義也可以確認它是Job-Step做Advanced配置時會用到的一個存儲過程，作用是把Job-Step日志寫到表 msdb.dbo.sysjobstepslogs 中，根據參數的不同可能會overwrite或append；  log_to_table ### 第二次推論 根據之前的信息我們可以推測出，這1W+空閑鏈接是由于執行完Job-Step后，內部更新msdb的日志表，更新完成后鏈接未釋放。 ### 第二次驗證 構造的場景跟第一次基本相同，只需要增加一點的是Job-Step開啟了log to table。  驗證成功 結果穩定復現，40s左右新增一個鏈接（Schedule 10s 不開啟Step Retry attempts 和 Retry interval），根據msdb.dbo.sysjobstepslogs.log_size和msdb.dbo.sysjobstepslogs.log可以確認日志的更新頻度在40s。 開啟Profiler、不斷調整Schedule時間、監控msdb.dbo.sysjobstepslogs.log_size大小，可以發現，當調度頻度大于40s時，新增鏈接按照頻度增加，當頻度小于40s時，新增鏈接按照40s一個增加。 ## 結論 如果Job-Step中定義的鏈接 DATABASE 是鏡像庫（RESTORING）且配置了Log To Table，那么每次做日志記錄的Session（msdb.dbo.sysjobstepslogs）都不會自動關閉，即Agent在這種場景下存在鏈接泄露。  version