• 玩转Windows服务系列——Windows服务启动超时时间


    最近有客户反映,机房出现断电情况,服务器的系统重新启动后,数据库服务自启动失败。第一次遇到这种情况,为了查看是不是断电情况导致数据库文件损坏,从客户的服务器拿到数据库的日志,进行分析。

    数据库工作机制

    要分析数据库启动失败的原因,首先说明一下数据库服务的工作机制。

    数据库分为六大服务:

    数据库六大服务

    数据库的六大服务之间存在依赖关系,及启动流程:

    数据库启动流程

    服务自动启动失败原因

    从客户那里,拿到了两份日志,一份是开机自启动的日志信息,此次数据库启动失败。另外一份是开机后,手动启动数据库服务的日志信息,此次数据库启动成功。

    首先看第一份日志:

    快照数据服务成功启动

    从日志中看到,快照数据服务已经成功启动,但是没有后续的日志信息,说明问题可能出在snapshot服务,或者下一个将要启动的equation服务。而另外一份日志中看到所有的服务都成功启动,并且正常运行,这就排除了服务器意外断电导致文件损坏的可能。

    数据库可以通过手动的方式成功启动,说明数据库的文件信息都正确,但是第一启动时却只logger、historian、snapshot服务成功启动,由于后续没有日志输出,很难分析问题的原因。

    既然数据库没有相应的日志,那么就要通过系统日志来分析,此处需要寻求系统的事件日志的帮助。

    在计算机管理中找到事件查看器,选择系统,如下图:

    系统事件查看器

    默认情况下,服务出现启动失败等异常时,操作系统会记录一些系统事件。

    从中可以看到如下信息:

    snapshot 服务启动时挂起
    事件ID 7022

    有事件ID与事件描述,谷歌之,但是没有找到相应的解决方案,没办法,还是只能从数据库日志来分析。

    再次分析日志,看到这样一种情况:

    快照服务启动耗时

    snapshot服务从开始启动,到启动结束,共耗时两分半,这个时间对于Windows服务的启动来说,时间是很长了。根据此情况,以及系统事件的描述,推测,有可能是服务启动超时。

    为了验证此推测,在数据库服务启动时加入一个Sleep(60000),这个时间足够超时了。从服务管理器中启动服务,过了一段时间后,服务启动失败,从事件查看器中,看到”服务启动时挂起的消息”,由此基本上可以断定数据库服务是由于超时而启动失败的。

    服务启动超时原因

    知道服务启动失败原因是超时导致的,还需要分析一下为什么开机自启动的时候服务会启动超时。

    还是从日志开始,幸好日志中有详细的输出日志,从这些日志中,看到两个耗时比较长的操作:

    快照服务耗时比较长的操作

    锁定历史数据缓存与锁定历史数据补写缓存两个操作,耗时分别在一分钟左右,两个操作一起占了启动耗时的大部分时间,那么启动超时就是由这两个操作导致的。

    既然这两个操作比较耗时,那么他们在悄悄的做什么呢。这两个操作实际是在锁定物理内存,使其尽量不要交换到磁盘上,那么开机启动后,所有的缓存数据还没有加载到内存中,此时锁定此内存,就会导致操作系统将此缓存数据从磁盘加载到内存中。看似复杂,实际就是操作系统在读磁盘,而机械磁盘的读取速度是有限并且非常慢的,当缓存文件很大时,纯粹读取磁盘的时间就要很长。而此案例中,两个缓存文件都在15G左右,所以耗时也就比较长了。

    由此分析下来,也就找到了服务启动超时的原因了。

    服务第二次启动时顺利启动的原因分析

    这还没完,服务启动超时的原因是知道了,但是为什么第二次启动时,就可以顺利启动呢。接着分析。

    再来看第二次启动时的日志:

    快照服务第二次启动耗时

    此日志中看到,第一次启动中,每个占用耗时达到60秒的锁定内存操作,此次只有3秒,可以说非常迅速了。

    上面说到,锁定内存实际是在读取磁盘,而磁盘速度特别慢,15G的缓存文件,在3秒内读取完,是根本不可能的。那么唯一的可能就是根本没有读取磁盘。

    其实这是Windows的一个内存管理机制,内存映射文件在卸载的时候,并不会立即去释放内存,释放内存的时机是由操作系统来决定的。当snapshot服务在很短的时间内又重新加载此内存映射文件时,操作系统发现此内存映射文件还存放在内存中,那么就不会再加载了,因为读取磁盘的速度实在是太慢了。而在开机启动的时候,由于是第一次加载内存映射文件,内存中还不存在,就会读取一次磁盘。所以这个锁定内存的时间也就由第一启动时的60秒变为3秒了。

    设置Windows服务启动超时时间

    Windows系统的服务超时时间默认是30s,当一个服务的启动时间超过这个时间后,服务管理器会认为服务存在异常,并视为启动失败,然后记录一些系统事件信息。但是有时候这个时间是比较短的,比如我们的snapshot服务,这就需要修改注册表来解决这个问题。注册表项为HKEY_LOCAL_MACHINE/SYSTEM/CurrentControlSet/Control/ServicesPipeTimeout,这个值有可能不存在,如果不存在需要添加。类型为DWORD,单位是毫秒。

    当然,这个超时时间是对所有服务都有效的,修改这个值并不是最好的解决办法。最好能在snapshot程序内部,对启动时加载缓存流程进行优化,以缩短启动时间,或者将耗时比较长的操作放到启动后进行。

    总结

    • 可以通过修改注册表来修改Windows的服务启动超时时间。
    • Windows的一个内存管理机制,内存映射文件在卸载的时候,并不会立即去释放内存,释放内存的时机是由操作系统来决定的。当程序在很短的时间内又重新加载此内存映射文件时,操作系统发现此内存映射文件还存放在内存中,那么就不会再加载了。

    当然,还有最重要的一点,日志系统很重要,骚年,乖乖的给程序加日志去吧!

    系列链接

    玩转Windows服务系列——创建Windows服务

    玩转Windows服务系列——Debug、Release版本的注册和卸载,及其原理

    玩转Windows服务系列——无COM接口Windows服务启动失败原因及解决方案

    玩转Windows服务系列——服务运行、停止流程浅析

    玩转Windows服务系列——Windows服务小技巧

    玩转Windows服务系列——命令行管理Windows服务

    玩转Windows服务系列——Windows服务启动超时时间

    玩转Windows服务系列——使用Boost.Application快速构建Windows服务

    玩转Windows服务系列——给Windows服务添加COM接口

  • 相关阅读:
    bzoj1257
    bzoj1833
    bzoj3505
    bzoj2226
    bzoj1263
    bzoj2429
    bzoj1854
    bzoj3555
    bzoj1877
    放两个模版
  • 原文地址:https://www.cnblogs.com/hbccdf/p/service_start_over_time.html
Copyright © 2020-2023  润新知