SQLSERVER errorlog講解
很多時候診斷SQLSERVER問題都需要看SQLSERVER的錯誤日志
日志里面很多內容沒有書本專門講解，今天我就講一下，可能里面的日志信息是從我個人的機器
里抓出來的，跟大家的機器環境會有所不同，但是SQLSERVER啟動部分的日志大家都是一樣的
特別的說一下：2013-02-12 17:53:29.29 spid29s
這些spid指的是SQLSERVER內部的進程，因為SQLSERVER內部有SQL OS，所以稱呼他自己內部的線程為“進程”
所以在Windows的任務管理器里是看不到這些“進程ID的”的，這些進程ID也會跟會話關聯的，例如你在
SSMS里新建一個查詢，SQLSERVER就會新建一個會話ID（SPID），這些“進程”可以kill的
1 KILL spid --相應的spid
相當於在cmd下運行：TASKKILL notepad.exe（進程ID）
不過這些kill命令是發給SQLSERVER去執行
在啟動的時候，SQLSERVER會創建很多線程來進行初始化數據庫或者其他工作，所以會看到下面的，但是spid會不同
2013-02-12 17:53:29.29 spid29s
開頭：
1 2013-02-12 17:53:22.26 Server Microsoft SQL Server 2005 - 9.00.5069.00 (Intel X86) 2 Aug 22 2012 16:01:52 3 Copyright (c) 1988-2005 Microsoft Corporation 4 Developer Edition on Windows NT 6.1 (Build 7601: Service Pack 1) 5 6 --啟動信息，記錄了你當前機器的SQL版本 和操作系統版本 SP補丁版本
1 2013-02-12 17:53:22.26 Server (c) 2005 Microsoft Corporation. 2 2013-02-12 17:53:22.26 Server All rights reserved. 3 2013-02-12 17:53:22.26 Server Server process ID is 5164. 4 2013-02-12 17:53:22.26 Server Authentication mode is MIXED. 5 2013-02-12 17:53:22.26 Server Logging SQL Server messages in file 'C:\Program Files\Microsoft SQL Server\MSSQL.1\MSSQL\LOG\ERRORLOG'. 6 2013-02-12 17:53:22.26 Server This instance of SQL Server last reported using a process ID of 3756 at 2013/2/12 15:38:30 (local) 2013/2/12 7:38:30 (UTC). This is an informational message only; no user action is required. 7 --SQL進程ID是5164 登錄SQLSERVER的驗證模式是：混合模式 8 --errorlog存放的目錄是：你懂的 9 --上次啟動SQLSERVER使用的進程ID是3756
啟動信息：
1 2013-02-12 17:53:22.26 Server Registry startup parameters: 2 2013-02-12 17:53:22.26 Server -d C:\Program Files\Microsoft SQL Server\MSSQL.1\MSSQL\DATA\master.mdf 3 2013-02-12 17:53:22.26 Server -e C:\Program Files\Microsoft SQL Server\MSSQL.1\MSSQL\LOG\ERRORLOG 4 2013-02-12 17:53:22.26 Server -l C:\Program Files\Microsoft SQL Server\MSSQL.1\MSSQL\DATA\mastlog.ldf 5 2013-02-12 17:53:22.26 服務器 SQL Server is starting at normal priority base (=7). This is an informational message only. No user action is required. 6 2013-02-12 17:53:22.26 服務器 Detected 4 CPUs. This is an informational message; no user action is required. 7 8 --讀取注冊表的啟動參數，啟動參數都存放在注冊表里面的 9 --這些參數可以SQLSERVER配置管理器里改 10 --檢測到4個邏輯cpu 我的機器cpu是酷睿i3 雙核四線程 11 --四個線程就是4個邏輯cpu，多少線程就是多少邏輯cpu 12 --啟動優先級是7，這個優先級不是很明白
1 2013-02-12 17:53:22.56 服務器 Set AWE Enabled to 1 in the configuration parameters to allow use of more memory. 2 2013-02-12 17:53:22.69 服務器 Using dynamic lock allocation. Initial allocation of 2500 Lock blocks and 5000 Lock Owner blocks per node. This is an informational message only. No user action is required. 3 2013-02-12 17:53:22.71 服務器 Attempting to initialize Microsoft Distributed Transaction Coordinator (MS DTC). This is an informational message only. No user action is required. 4 2013-02-12 17:53:23.78 服務器 Attempting to recover in-doubt distributed transactions involving Microsoft Distributed Transaction Coordinator (MS DTC). This is an informational message only. No user action is required. 5 6 --AWE已經配置成功，AWE可以使SQLSERVER使用更多內存，突破32位操作系統限制 7 --使用動態鎖分配，因為是多核處理器，所以使用了NUMA架構，將CPU分成多個節點，每個節點都有一些鎖 8 --初始化和恢復MSDTC，如果你的應用需要用到分布式事務，例如分布式查詢，查詢access數據庫就需要MSDTC的支持
1 2013-02-12 17:53:23.78 服務器 Database mirroring has been enabled on this instance of SQL Server. 2 2013-02-12 17:53:23.79 spid5s Starting up database 'master'. 3 2013-02-12 17:53:23.83 spid5s Recovery is writing a checkpoint in database 'master' (1). This is an informational message only. No user action is required. 4 2013-02-12 17:53:23.87 spid5s SQL Trace ID 1 was started by login "sa". 5 2013-02-12 17:53:23.88 spid5s Starting up database 'mssqlsystemresource'. 6 2013-02-12 17:53:23.89 spid5s The resource database build version is 9.00.5069. This is an informational message only. No user action is required. 7 2013-02-12 17:53:24.63 spid5s Server name is 'JOE'. This is an informational message only. No user action is required. 8 9 --數據庫鏡像已經准備就緒，我的機器配置了數據庫鏡像 10 --啟動master數據庫，恢復master數據庫，使用檢查點技術把數據寫入磁盤 11 --因為我啟動了SQL Trace 所以會看到SQL Trace的信息 12 --啟動sqlserver 系統資源數據庫，這個數據庫在SSMS里是不可見的 13 --但是他又很重要，存儲數據庫的元數據 14 --我的計算機名：joe
1 2013-02-12 17:53:24.63 spid9s Starting up database 'model'. 2 2013-02-12 17:53:24.66 spid9s Clearing tempdb database. 3 2013-02-12 17:53:25.48 spid9s Starting up database 'tempdb'. 4 2013-02-12 17:53:25.62 spid12s The Service Broker protocol transport is disabled or not configured. 5 2013-02-12 17:53:25.62 spid12s The Database Mirroring protocol transport is disabled or not configured. 6 2013-02-12 17:53:25.62 spid12s Service Broker manager has started. 7 8 --啟動model數據庫 9 --清空tempdb數據庫，清空tempdb數據庫的時機就是在 10 --SQLSERVER啟動的時候 11 --我的ServiceBroker沒有配置 12 --數據庫鏡像傳輸沒有配置，因為我之前把鏡像刪除了，但是因為啟用了鏡像，所以還是會提示在啟動的時候
1 2013-02-12 17:53:26.91 服務器 A self-generated certificate was successfully loaded for encryption. 2 2013-02-12 17:53:26.91 服務器 Server local connection provider is ready to accept connection on [ \\.\pipe\SQLLocal\MSSQLSERVER ]. 3 2013-02-12 17:53:26.91 服務器 Server local connection provider is ready to accept connection on [ \\.\pipe\sql\query ]. 4 2013-02-12 17:53:26.92 服務器 Server is listening on [ 'any' <ipv6> 1434]. 5 2013-02-12 17:53:26.92 服務器 Server is listening on [ 'any' <ipv4> 1434]. 6 2013-02-12 17:53:26.92 服務器 Dedicated admin connection support was established for listening remotely on port 1434. 7 2013-02-12 17:53:26.92 服務器 SQL Server is now ready for client connections. This is an informational message; no user action is required. 8 9 --之前配置過數據庫鏡像，使用證書的方式，所以這里也會提示成功加載 10 --證書，因為我的證書還沒有刪除 11 --下面的幾個都說明了SQLSERVER已經准備就緒接受連接 12 --包括命名管道，共享內存，TCP/IP 13 --因為開啟了SQL BROSWER服務，所以會偵聽1434端口 14 --SQL BROSWER的作用可以看MSDN 15 --專用管理員連接支持已經建立，也是偵聽1434端口 16 --專用管理員連接DAC是當遇到數據庫連接不上或者某些原因 17 --登錄不了數據庫而使用的，偵聽1434的原因估計是因為 18 --1433端口都用不了
1 2013-02-12 17:53:26.95 spid18s Starting up database 'msdb'. 2 2013-02-12 17:53:26.95 spid19s Starting up database 'ReportServer'. 3 2013-02-12 17:53:26.95 spid21s Starting up database 'AdventureWorks'. 4 2013-02-12 17:53:26.95 spid22s Starting up database 'AdventureWorksDW'. 5 2013-02-12 17:53:26.95 spid20s Starting up database 'ReportServerTempDB'. 6 2013-02-12 17:53:26.96 spid23s Starting up database 'dbdreamlink'. 7 2013-02-12 17:53:26.96 spid24s Starting up database 'DLGPOS'. 8 2013-02-12 17:53:26.98 spid25s Starting up database 'hengshan'. 9 2013-02-12 17:53:27.02 spid19s Starting up database 'Monitoring'. 10 2013-02-12 17:53:27.02 spid26s Starting up database 'Northwind'. 11 2013-02-12 17:53:27.03 spid27s Starting up database 'partionTest'. 12 2013-02-12 17:53:27.03 spid20s Starting up database 'pratice'. 13 2013-02-12 17:53:27.04 spid28s Starting up database 'pubs'. 14 2013-02-12 17:53:27.05 spid29s Starting up database 'TransactionTestDb'. 15 2013-02-12 17:53:27.05 spid25s Starting up database 'GPOSDB'. 16 17 --前面的一些檢查成功之后，開始各個數據庫的啟動
1 2013-02-12 17:53:28.36 spid5s Recovery is writing a checkpoint in database 'msdb' (4). This is an informational message only. No user action is required. 2 2013-02-12 17:53:29.24 spid27s 1 transactions rolled forward in database 'partionTest' (14). This is an informational message only. No user action is required. 3 2013-02-12 17:53:29.24 spid27s 0 transactions rolled back in database 'partionTest' (14). This is an informational message only. No user action is required. 4 2013-02-12 17:53:29.24 spid27s Recovery is writing a checkpoint in database 'partionTest' (14). This is an informational message only. No user action is required. 5 2013-02-12 17:53:29.24 spid28s 1 transactions rolled forward in database 'pubs' (16). This is an informational message only. No user action is required. 6 2013-02-12 17:53:29.26 spid27s 0 transactions rolled back in database 'pubs' (16). This is an informational message only. No user action is required. 7 2013-02-12 17:53:29.26 spid27s Recovery is writing a checkpoint in database 'pubs' (16). This is an informational message only. No user action is required. 8 2013-02-12 17:53:29.28 spid29s 1 transactions rolled forward in database 'TransactionTestDb' (17). This is an informational message only. No user action is required. 9 10 --開始恢復各個數據庫並進行前滾或者回滾數據庫，使各個數據庫進入 11 --在線狀態，關於各種狀態可以看我這篇文章 12 --SQLSERVER數據庫主要狀態和切換路徑 13 --http://www.cnblogs.com/lyhabc/archive/2012/09/15/2687076.html
14 --數據庫后面的數字是DBID
1 2013-02-12 17:53:29.29 spid29s CHECKDB for database 'TransactionTestDb' finished without errors on 2012-11-29 20:22:02.540 (local time). This is an informational message only; no user action is required. 2 3 --使用checkdb命令檢查各個數據庫的狀態 4 --由於數據庫太多我就不貼出來了
1 2013-02-12 17:53:33.10 spid5s Recovery of any in-doubt distributed transactions involving Microsoft Distributed Transaction Coordinator (MS DTC) has completed. This is an informational message only. No user action is required. 2 2013-02-12 17:53:33.10 spid5s Recovery is complete. This is an informational message only. No user action is required. 3 2013-02-12 17:53:34.29 spid51 Using 'xpsqlbot.dll' version '2005.90.5000' to execute extended stored procedure 'xp_qv'. This is an informational message only; no user action is required. 4 2013-02-12 17:53:34.60 spid51 Using 'xpstar90.dll' version '2005.90.5000' to execute extended stored procedure 'xp_instance_regread'. This is an informational message only; no user action is required. 5 2013-02-12 17:53:34.66 spid51 Using 'xplog70.dll' version '2005.90.5000' to execute extended stored procedure 'xp_msver'. This is an informational message only; no user action is required. 6 --檢查所有的分布式事務都沒有問題 7 --加載xpsqlbot.dll來執行擴展存儲過程xp_qv 8 --加載xpstar90.dll來執行擴展存儲過程xp_instance_regread 9 --加載xplog70.dll來執行擴展存儲過程xp_msver 10 11 --這些擴展存儲過程都需要加載第三方dll來執行的，之前遇到過 12 --有人因為缺少xplog70.dll 而不能執行xp_cmdshell 13 --無法裝載 DLL xpsql70.dll 或該DLL所引用的某一 DLL。 14 --原因126（找不到指定模塊） 15 --無法在庫 xpweb70.dll 中找到函數 xp_cmdshell
啟動完畢
運行過程的SQL ErrorLog
1 2013-02-12 18:02:57.41 spid1s A significant part of sql server process memory has been paged out. This may result in a performance degradation. Duration: 0 seconds. Working set (KB): 7484, committed (KB): 63256, memory utilization: 11%. 2 3 --因為我的機器內存不足，所以需要把SQLSERVER內存頁面換出 4 --這個信息在Windows事件查看器里應用程序日志也能看到
1 2013-02-12 19:48:24.67 spid55 DBCC TRACEON 3604, server process ID (SPID) 55. This is an informational message only; no user action is required. 2 2013-02-12 19:48:24.76 spid55 DBCC TRACEOFF 3604, server process ID (SPID) 55. This is an informational message only; no user action is required. 3 4 --3604跟蹤標志已經打開
1 2013-02-12 22:37:21.56 spid55 DBCC TRACEON 1222, server process ID (SPID) 55. This is an informational message only; no user action is required. 2 2013-02-12 22:37:21.60 spid55 DBCC TRACEON 1204, server process ID (SPID) 55. This is an informational message only; no user action is required. 3 4 --跟蹤標志1222和1204已經打開，剛才因為我要跟蹤死鎖信息 5 --所以手動打開了1222和1204跟蹤標志
就這麽多了，SQL ErrorLog不會很多，所以有時候遇到SQL問題先查找SQL ErrorLog里的記錄會比較好
當然了，在SSMS里也能看到SQL ErrorLog，SSMS里還包括篩選和搜索功能，但是有時候如果連SQLSERVER服務都啟動不了
那只能到SQL ErrorLog的目錄里面，用記事本或者其他編輯器打開找問題原因了
------------------------------------------------------------------------------------------------------------
2013-10-21
附上SQLSERVER2012 啟動時候的ERRORLOG
1 2013-10-21 18:06:18.51 Server Microsoft SQL Server 2012 (SP1) - 11.0.3000.0 (X64) 2 Oct 19 2012 13:38:57 3 Copyright (c) Microsoft Corporation 4 Developer Edition (64-bit) on Windows NT 6.1 <X64> (Build 7601: Service Pack 1) (Hypervisor) 5 6 2013-10-21 18:06:18.53 Server (c) Microsoft Corporation. 7 2013-10-21 18:06:18.53 Server All rights reserved. 8 2013-10-21 18:06:18.53 Server Server process ID is 2364. 9 2013-10-21 18:06:18.53 Server System Manufacturer: 'VMware, Inc.', System Model: 'VMware Virtual Platform'. 10 2013-10-21 18:06:18.53 Server Authentication mode is MIXED. 11 2013-10-21 18:06:18.54 Server Logging SQL Server messages in file 'D:\Program Files\Microsoft SQL Server\MSSQL11.MSSQLSERVER\MSSQL\Log\ERRORLOG'. 12 2013-10-21 18:06:18.54 Server The service account is 'NT Service\MSSQLSERVER'. This is an informational message; no user action is required. 13 2013-10-21 18:06:18.54 Server Registry startup parameters: 14 -d D:\Program Files\Microsoft SQL Server\MSSQL11.MSSQLSERVER\MSSQL\DATA\master.mdf 15 -e D:\Program Files\Microsoft SQL Server\MSSQL11.MSSQLSERVER\MSSQL\Log\ERRORLOG 16 -l D:\Program Files\Microsoft SQL Server\MSSQL11.MSSQLSERVER\MSSQL\DATA\mastlog.ldf 17 2013-10-21 18:06:18.54 Server Command Line Startup Parameters: 18 -s "MSSQLSERVER" 19 2013-10-21 18:06:19.24 服務器 SQL Server detected 2 sockets with 2 cores per socket and 2 logical processors per socket, 4 total logical processors; using 4 logical processors based on SQL Server licensing. This is an informational message; no user action is required. 20 2013-10-21 18:06:19.24 服務器 SQL Server is starting at normal priority base (=7). This is an informational message only. No user action is required. 21 2013-10-21 18:06:19.24 服務器 Detected 2999 MB of RAM. This is an informational message; no user action is required. 22 2013-10-21 18:06:19.26 服務器 Using conventional memory in the memory manager. 23 2013-10-21 18:06:24.37 服務器 This instance of SQL Server last reported using a process ID of 2328 at 2013/10/19 11:13:57 (local) 2013/10/19 3:13:57 (UTC). This is an informational message only; no user action is required. 24 2013-10-21 18:06:24.42 服務器 Node configuration: node 0: CPU mask: 0x000000000000000f:0 Active CPU mask: 0x000000000000000f:0. This message provides a description of the NUMA configuration for this computer. This is an informational message only. No user action is required. 25 2013-10-21 18:06:24.47 服務器 Using dynamic lock allocation. Initial allocation of 2500 Lock blocks and 5000 Lock Owner blocks per node. This is an informational message only. No user action is required. 26 2013-10-21 18:06:24.53 服務器 Software Usage Metrics is disabled. 27 2013-10-21 18:06:24.61 Server CLR version v4.0.30319 loaded. 28 2013-10-21 18:06:24.65 spid2s Starting up database 'master'. 29 2013-10-21 18:06:25.38 服務器 Common language runtime (CLR) functionality initialized using CLR version v4.0.30319 from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\. 30 2013-10-21 18:06:30.12 spid2s Resource governor reconfiguration succeeded. 31 2013-10-21 18:06:30.14 spid2s SQL Server Audit is starting the audits. This is an informational message. No user action is required. 32 2013-10-21 18:06:30.16 spid2s SQL Server Audit has started the audits. This is an informational message. No user action is required. 33 <{39B75A24-0837-4CEC-AFDF-B960027AE07E}>RsFxNso initialized. InstanceId = 00000001 34 <{50080099-5EC4-4EAF-A2A2-63C3DA97F8EB}>FsAgent is initialized 35 <{09C4480B-DBA4-49B7-956F-68A8B8B2445D}>FsAgent is up and running 36 2013-10-21 18:06:30.45 spid2s FILESTREAM: effective level = 2 (remote access enabled), configured level = 2, file system access share name = 'MSSQLSERVER'. 37 2013-10-21 18:06:33.25 spid2s SQL Trace ID 1 was started by login "sa". 38 2013-10-21 18:06:33.99 spid2s Server name is 'WIN7U-20130702M'. This is an informational message only. No user action is required. 39 2013-10-21 18:06:34.92 spid18s A self-generated certificate was successfully loaded for encryption. 40 2013-10-21 18:06:35.04 spid18s Server is listening on [ 'any' <ipv6> 1433]. 41 2013-10-21 18:06:35.05 spid18s Server is listening on [ 'any' <ipv4> 1433]. 42 2013-10-21 18:06:35.05 spid18s Server local connection provider is ready to accept connection on [ \\.\pipe\SQLLocal\MSSQLSERVER ]. 43 2013-10-21 18:06:35.06 spid18s Server named pipe provider is ready to accept connection on [ \\.\pipe\sql\query ]. 44 2013-10-21 18:06:35.06 服務器 Server is listening on [ ::1 <ipv6> 1434]. 45 2013-10-21 18:06:35.06 服務器 Server is listening on [ 127.0.0.1 <ipv4> 1434]. 46 2013-10-21 18:06:35.06 服務器 Dedicated admin connection support was established for listening locally on port 1434. 47 2013-10-21 18:06:35.39 服務器 SQL Server is attempting to register a Service Principal Name (SPN) for the SQL Server service. Kerberos authentication will not be possible until a SPN is registered for the SQL Server service. This is an informational message. No user action is required. 48 2013-10-21 18:06:35.39 服務器 The SQL Server Network Interface library could not register the Service Principal Name (SPN) [ MSSQLSvc/WIN7U-20130702M ] for the SQL Server service. Windows return code: 0xffffffff, state: 63. Failure to register a SPN might cause integrated authentication to use NTLM instead of Kerberos. This is an informational message. Further action is only required if Kerberos authentication is required by authentication policies and if the SPN has not been manually registered. 49 2013-10-21 18:06:35.39 服務器 The SQL Server Network Interface library could not register the Service Principal Name (SPN) [ MSSQLSvc/WIN7U-20130702M:1433 ] for the SQL Server service. Windows return code: 0xffffffff, state: 63. Failure to register a SPN might cause integrated authentication to use NTLM instead of Kerberos. This is an informational message. Further action is only required if Kerberos authentication is required by authentication policies and if the SPN has not been manually registered. 50 2013-10-21 18:06:35.39 spid18s SQL Server is now ready for client connections. This is an informational message; no user action is required. 51 2013-10-21 18:07:13.64 spid26s Starting up database 'ReportServer'. 52 2013-10-21 18:07:13.65 spid23s Starting up database 'ReportServerTempDB'. 53 2013-10-21 18:07:13.65 spid28s Starting up database 'GPOSDB'. 54 2013-10-21 18:07:13.65 spid24s Starting up database 'msdb'. 55 2013-10-21 18:07:13.66 spid27s Starting up database 'hengshan'. 56 2013-10-21 18:07:13.66 spid25s Starting up database 'pratice'. 57 2013-10-21 18:07:13.66 spid9s Starting up database 'mssqlsystemresource'. 58 2013-10-21 18:07:13.71 spid29s Starting up database 'FileStreamTestDb'. 59 2013-10-21 18:07:13.72 spid30s Starting up database '長鐵物業公司資產數據庫'. 60 2013-10-21 18:07:13.82 spid9s The resource database build version is 11.00.3000. This is an informational message only. No user action is required. 61 2013-10-21 18:07:16.04 spid9s Starting up database 'model'. 62 2013-10-21 18:07:18.92 spid9s Clearing tempdb database. 63 2013-10-21 18:07:25.96 spid9s Starting up database 'tempdb'. 64 2013-10-21 18:07:27.18 spid11s The Service Broker endpoint is in disabled or stopped state. 65 2013-10-21 18:07:27.37 spid11s The Database Mirroring endpoint is in disabled or stopped state. 66 2013-10-21 18:07:28.82 spid28s CHECKDB for database 'GPOSDB' finished without errors on 2013-06-10 00:00:41.420 (local time). This is an informational message only; no user action is required. 67 2013-10-21 18:07:29.57 spid11s Service Broker manager has started. 68 2013-10-21 18:07:35.01 spid25s CHECKDB for database 'pratice' finished without errors on 2013-06-10 00:00:56.963 (local time). This is an informational message only; no user action is required. 69 2013-10-21 18:07:35.53 spid2s Recovery is complete. This is an informational message only. No user action is required. 70 2013-10-21 18:07:52.84 spid20s A new instance of the full-text filter daemon host process has been successfully started. 71 2013-10-21 18:08:10.24 spid51 Attempting to load library 'xpsqlbot.dll' into memory. This is an informational message only. No user action is required. 72 2013-10-21 18:08:10.64 spid51 Using 'xpsqlbot.dll' version '2011.110.2100' to execute extended stored procedure 'xp_qv'. This is an informational message only; no user action is required. 73 2013-10-21 18:08:14.48 spid51 Attempting to load library 'xpstar.dll' into memory. This is an informational message only. No user action is required. 74 2013-10-21 18:08:15.66 spid51 Using 'xpstar.dll' version '2011.110.3000' to execute extended stored procedure 'xp_instance_regread'. This is an informational message only; no user action is required. 75 2013-10-21 18:08:17.53 spid51 Attempting to load library 'xplog70.dll' into memory. This is an informational message only. No user action is required. 76 2013-10-21 18:08:18.21 spid51 Using 'xplog70.dll' version '2011.110.2100' to execute extended stored procedure 'xp_msver'. This is an informational message only; no user action is required. 77 2013-10-21 19:16:46.09 spid3s Warning: Failure to calculate super-latch promotion threshold.