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的

KILL spid --相应的spid

 相当于在cmd下运行：TASKKILL  notepad.exe（进程ID）

不过这些kill命令是发给SQLSERVER去执行

---

 

在启动的时候，SQLSERVER会创建很多线程来进行初始化数据库或者其他工作，所以会看到下面的，但是spid会不同

2013-02-12 17:53:29.29 spid29s

2013-02-12 17:53:22.26 Server      Microsoft SQL Server 2005 - 9.00.5069.00 (Intel X86) 
    Aug 22 2012 16:01:52 
    Copyright (c) 1988-2005 Microsoft Corporation
    Developer Edition on Windows NT 6.1 (Build 7601: Service Pack 1)

--启动信息，记录了你当前机器的SQL版本 和操作系统版本 SP补丁版本

 

2013-02-12 17:53:22.26 Server      (c) 2005 Microsoft Corporation.
2013-02-12 17:53:22.26 Server      All rights reserved.
2013-02-12 17:53:22.26 Server      Server process ID is 5164.
2013-02-12 17:53:22.26 Server      Authentication mode is MIXED.
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'.
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.
--SQL进程ID是5164  登录SQLSERVER的验证模式是：混合模式
--errorlog存放的目录是：你懂的
--上次启动SQLSERVER使用的进程ID是3756

 启动信息：

2013-02-12 17:53:22.26 Server      Registry startup parameters:
2013-02-12 17:53:22.26 Server           -d C:\Program Files\Microsoft SQL Server\MSSQL.1\MSSQL\DATA\master.mdf
2013-02-12 17:53:22.26 Server           -e C:\Program Files\Microsoft SQL Server\MSSQL.1\MSSQL\LOG\ERRORLOG
2013-02-12 17:53:22.26 Server           -l C:\Program Files\Microsoft SQL Server\MSSQL.1\MSSQL\DATA\mastlog.ldf
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.
2013-02-12 17:53:22.26 服务器         Detected 4 CPUs. This is an informational message; no user action is required.

--读取注册表的启动参数，启动参数都存放在注册表里面的
--这些参数可以SQLSERVER配置管理器里改
--检测到4个逻辑cpu 我的机器cpu是酷睿i3 双核四线程
--四个线程就是4个逻辑cpu，多少线程就是多少逻辑cpu
--启动优先级是7，这个优先级不是很明白

 

2013-02-12 17:53:22.56 服务器         Set AWE Enabled to 1 in the configuration parameters to allow use of more memory.
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.
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.
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.

--AWE已经配置成功，AWE可以使SQLSERVER使用更多内存，突破32位操作系统限制
--使用动态锁分配，因为是多核处理器，所以使用了NUMA架构，将CPU分成多个节点，每个节点都有一些锁
--初始化和恢复MSDTC，如果你的应用需要用到分布式事务，例如分布式查询，查询access数据库就需要MSDTC的支持

 

2013-02-12 17:53:23.78 服务器         Database mirroring has been enabled on this instance of SQL Server.
2013-02-12 17:53:23.79 spid5s      Starting up database 'master'.
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.
2013-02-12 17:53:23.87 spid5s      SQL Trace ID 1 was started by login "sa".
2013-02-12 17:53:23.88 spid5s      Starting up database 'mssqlsystemresource'.
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.
2013-02-12 17:53:24.63 spid5s      Server name is 'JOE'. This is an informational message only. No user action is required.

--数据库镜像已经准备就绪，我的机器配置了数据库镜像
--启动master数据库，恢复master数据库，使用检查点技术把数据写入磁盘
--因为我启动了SQL Trace 所以会看到SQL Trace的信息
--启动sqlserver 系统资源数据库，这个数据库在SSMS里是不可见的
--但是他又很重要，存储数据库的元数据
--我的计算机名：joe

 

2013-02-12 17:53:24.63 spid9s      Starting up database 'model'.
2013-02-12 17:53:24.66 spid9s      Clearing tempdb database.
2013-02-12 17:53:25.48 spid9s      Starting up database 'tempdb'.
2013-02-12 17:53:25.62 spid12s     The Service Broker protocol transport is disabled or not configured.
2013-02-12 17:53:25.62 spid12s     The Database Mirroring protocol transport is disabled or not configured.
2013-02-12 17:53:25.62 spid12s     Service Broker manager has started.

--启动model数据库
--清空tempdb数据库，清空tempdb数据库的时机就是在
--SQLSERVER启动的时候
--我的ServiceBroker没有配置
--数据库镜像传输没有配置，因为我之前把镜像删除了，但是因为启用了镜像，所以还是会提示在启动的时候

 

2013-02-12 17:53:26.91 服务器         A self-generated certificate was successfully loaded for encryption.
2013-02-12 17:53:26.91 服务器         Server local connection provider is ready to accept connection on [ \\.\pipe\SQLLocal\MSSQLSERVER ].
2013-02-12 17:53:26.91 服务器         Server local connection provider is ready to accept connection on [ \\.\pipe\sql\query ].
2013-02-12 17:53:26.92 服务器         Server is listening on [ 'any' <ipv6> 1434].
2013-02-12 17:53:26.92 服务器         Server is listening on [ 'any' <ipv4> 1434].
2013-02-12 17:53:26.92 服务器         Dedicated admin connection support was established for listening remotely on port 1434.
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.

--之前配置过数据库镜像，使用证书的方式，所以这里也会提示成功加载
--证书，因为我的证书还没有删除
--下面的几个都说明了SQLSERVER已经准备就绪接受连接
--包括命名管道，共享内存，TCP/IP
--因为开启了SQL BROSWER服务，所以会侦听1434端口
--SQL BROSWER的作用可以看MSDN
--专用管理员连接支持已经建立，也是侦听1434端口
--专用管理员连接DAC是当遇到数据库连接不上或者某些原因
--登录不了数据库而使用的，侦听1434的原因估计是因为
--1433端口都用不了

 

2013-02-12 17:53:26.95 spid18s     Starting up database 'msdb'.
2013-02-12 17:53:26.95 spid19s     Starting up database 'ReportServer'.
2013-02-12 17:53:26.95 spid21s     Starting up database 'AdventureWorks'.
2013-02-12 17:53:26.95 spid22s     Starting up database 'AdventureWorksDW'.
2013-02-12 17:53:26.95 spid20s     Starting up database 'ReportServerTempDB'.
2013-02-12 17:53:26.96 spid23s     Starting up database 'dbdreamlink'.
2013-02-12 17:53:26.96 spid24s     Starting up database 'DLGPOS'.
2013-02-12 17:53:26.98 spid25s     Starting up database 'hengshan'.
2013-02-12 17:53:27.02 spid19s     Starting up database 'Monitoring'.
2013-02-12 17:53:27.02 spid26s     Starting up database 'Northwind'.
2013-02-12 17:53:27.03 spid27s     Starting up database 'partionTest'.
2013-02-12 17:53:27.03 spid20s     Starting up database 'pratice'.
2013-02-12 17:53:27.04 spid28s     Starting up database 'pubs'.
2013-02-12 17:53:27.05 spid29s     Starting up database 'TransactionTestDb'.
2013-02-12 17:53:27.05 spid25s     Starting up database 'GPOSDB'.

--前面的一些检查成功之后，开始各个数据库的启动

 

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.
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.
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.
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.
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.
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.
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.
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.

--开始恢复各个数据库并进行前滚或者回滚数据库，使各个数据库进入
--在线状态，关于各种状态可以看我这篇文章
--SQLSERVER数据库主要状态和切换路径
--http://www.cnblogs.com/lyhabc/archive/2012/09/15/2687076.html
--数据库后面的数字是DBID

 

 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.
 
 --使用checkdb命令检查各个数据库的状态
 --由于数据库太多我就不贴出来了

 

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.
2013-02-12 17:53:33.10 spid5s      Recovery is complete. This is an informational message only. No user action is required.
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.
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.
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.
--检查所有的分布式事务都没有问题
--加载xpsqlbot.dll来执行扩展存储过程xp_qv
--加载xpstar90.dll来执行扩展存储过程xp_instance_regread
--加载xplog70.dll来执行扩展存储过程xp_msver

--这些扩展存储过程都需要加载第三方dll来执行的，之前遇到过
--有人因为缺少xplog70.dll 而不能执行xp_cmdshell
--无法装载 DLL xpsql70.dll 或该DLL所引用的某一 DLL。
--原因126（找不到指定模块）
--无法在库 xpweb70.dll 中找到函数 xp_cmdshell

  启动完毕

运行过程的SQL ErrorLog

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%.
 
 --因为我的机器内存不足，所以需要把SQLSERVER内存页面换出
 --这个信息在Windows事件查看器里应用程序日志也能看到
 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.
 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.

 --3604跟踪标志已经打开
复制代码
 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.
 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.
 
 --跟踪标志1222和1204已经打开，刚才因为我要跟踪死锁信息
 --所以手动打开了1222和1204跟踪标志

 就这麽多了，SQL ErrorLog不会很多，所以有时候遇到SQL问题先查找SQL ErrorLog里的记录会比较好

当然了，在SSMS里也能看到SQL ErrorLog，SSMS里还包括筛选和搜索功能，但是有时候如果连SQLSERVER服务都启动不了

那只能到SQL ErrorLog的目录里面，用记事本或者其他编辑器打开找问题原因了

 

------------------------------------------------------------------------------------------------------------

2013-10-21

附上SQLSERVER2012 启动时候的ERRORLOG

2013-10-21 18:06:18.51 Server      Microsoft SQL Server 2012 (SP1) - 11.0.3000.0 (X64) 
    Oct 19 2012 13:38:57 
    Copyright (c) Microsoft Corporation
    Developer Edition (64-bit) on Windows NT 6.1 <X64> (Build 7601: Service Pack 1) (Hypervisor)

2013-10-21 18:06:18.53 Server      (c) Microsoft Corporation.
2013-10-21 18:06:18.53 Server      All rights reserved.
2013-10-21 18:06:18.53 Server      Server process ID is 2364.
2013-10-21 18:06:18.53 Server      System Manufacturer: 'VMware, Inc.', System Model: 'VMware Virtual Platform'.
2013-10-21 18:06:18.53 Server      Authentication mode is MIXED.
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'.
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.
2013-10-21 18:06:18.54 Server      Registry startup parameters: 
     -d D:\Program Files\Microsoft SQL Server\MSSQL11.MSSQLSERVER\MSSQL\DATA\master.mdf
     -e D:\Program Files\Microsoft SQL Server\MSSQL11.MSSQLSERVER\MSSQL\Log\ERRORLOG
     -l D:\Program Files\Microsoft SQL Server\MSSQL11.MSSQLSERVER\MSSQL\DATA\mastlog.ldf
2013-10-21 18:06:18.54 Server      Command Line Startup Parameters:
     -s "MSSQLSERVER"
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.
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.
2013-10-21 18:06:19.24 服务器         Detected 2999 MB of RAM. This is an informational message; no user action is required.
2013-10-21 18:06:19.26 服务器         Using conventional memory in the memory manager.
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.
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.
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.
2013-10-21 18:06:24.53 服务器         Software Usage Metrics is disabled.
2013-10-21 18:06:24.61 Server      CLR version v4.0.30319 loaded.
2013-10-21 18:06:24.65 spid2s      Starting up database 'master'.
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\.
2013-10-21 18:06:30.12 spid2s      Resource governor reconfiguration succeeded.
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.
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.
<{39B75A24-0837-4CEC-AFDF-B960027AE07E}>RsFxNso initialized. InstanceId = 00000001
<{50080099-5EC4-4EAF-A2A2-63C3DA97F8EB}>FsAgent is initialized
<{09C4480B-DBA4-49B7-956F-68A8B8B2445D}>FsAgent is up and running
2013-10-21 18:06:30.45 spid2s      FILESTREAM: effective level = 2 (remote access enabled), configured level = 2, file system access share name = 'MSSQLSERVER'.
2013-10-21 18:06:33.25 spid2s      SQL Trace ID 1 was started by login "sa".
2013-10-21 18:06:33.99 spid2s      Server name is 'WIN7U-20130702M'. This is an informational message only. No user action is required.
2013-10-21 18:06:34.92 spid18s     A self-generated certificate was successfully loaded for encryption.
2013-10-21 18:06:35.04 spid18s     Server is listening on [ 'any' <ipv6> 1433].
2013-10-21 18:06:35.05 spid18s     Server is listening on [ 'any' <ipv4> 1433].
2013-10-21 18:06:35.05 spid18s     Server local connection provider is ready to accept connection on [ \\.\pipe\SQLLocal\MSSQLSERVER ].
2013-10-21 18:06:35.06 spid18s     Server named pipe provider is ready to accept connection on [ \\.\pipe\sql\query ].
2013-10-21 18:06:35.06 服务器         Server is listening on [ ::1 <ipv6> 1434].
2013-10-21 18:06:35.06 服务器         Server is listening on [ 127.0.0.1 <ipv4> 1434].
2013-10-21 18:06:35.06 服务器         Dedicated admin connection support was established for listening locally on port 1434.
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.
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.
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.
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.
2013-10-21 18:07:13.64 spid26s     Starting up database 'ReportServer'.
2013-10-21 18:07:13.65 spid23s     Starting up database 'ReportServerTempDB'.
2013-10-21 18:07:13.65 spid28s     Starting up database 'GPOSDB'.
2013-10-21 18:07:13.65 spid24s     Starting up database 'msdb'.
2013-10-21 18:07:13.66 spid27s     Starting up database 'hengshan'.
2013-10-21 18:07:13.66 spid25s     Starting up database 'pratice'.
2013-10-21 18:07:13.66 spid9s      Starting up database 'mssqlsystemresource'.
2013-10-21 18:07:13.71 spid29s     Starting up database 'FileStreamTestDb'.
2013-10-21 18:07:13.72 spid30s     Starting up database '长铁物业公司资产数据库'.
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.
2013-10-21 18:07:16.04 spid9s      Starting up database 'model'.
2013-10-21 18:07:18.92 spid9s      Clearing tempdb database.
2013-10-21 18:07:25.96 spid9s      Starting up database 'tempdb'.
2013-10-21 18:07:27.18 spid11s     The Service Broker endpoint is in disabled or stopped state.
2013-10-21 18:07:27.37 spid11s     The Database Mirroring endpoint is in disabled or stopped state.
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.
2013-10-21 18:07:29.57 spid11s     Service Broker manager has started.
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.
2013-10-21 18:07:35.53 spid2s      Recovery is complete. This is an informational message only. No user action is required.
2013-10-21 18:07:52.84 spid20s     A new instance of the full-text filter daemon host process has been successfully started.
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.
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.
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.
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.
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.
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.
2013-10-21 19:16:46.09 spid3s      Warning: Failure to calculate super-latch promotion threshold.