Cherrypy - 随机请求挂起然后服务器变得无响应

Cherrypy - random requests hanging then server becomes unresponsive

我们有一个基于以下内容构建的服务器:

在以下平台运行ning:

在过去的几个月里,我们遇到了几个 cherypy 服务器变得无响应的情况。第一个症状是 ajax 请求超时,在浏览器中重新加载页面超时,然后最终 Apache 将 return 一个 502 因为 cherrypy 将不再接受任何连接。重新启动 python 服务可解决问题。有时它会在 10 分钟内从超时到 502,有时它会持续超时半个多小时,然后我们才意识到必须重新启动。

服务器可以 运行 数周没有问题,但有时该问题可能会在几个小时内出现 5 次。

我们对所有请求实施了一些额外的日志记录以识别模式。首先,它似乎不是由任何一种特定类型的请求、一天中的时间、负载、用户等触发的。但是我们偶尔会遇到 SQL 死锁错误,有时我们会遇到 cherrypy 请求超时错误。 SQL 死锁似乎与请求清理无关,并且与服务器冻结时间无关。请求超时确实发生在相似的时间,但我只见过几次,不会每次都发生。

在每个模块的每个入口点中,我们添加了以下日志记录:

    util.write_to_debuglog("ajax", "START", _path)

    # Call AJAX target providing the session object
    _args.update(session=session)
    result=target(**_args)

    util.write_to_debuglog("ajax", "FINISH", _path)

    return result

在调试日志中,我们还打印出会话 ID 和用户名,这样我就可以准确地看到请求的来源。

昨天当它宕机时,调试日志显示如下(逆向工作):

在 11:23:11 和 11:59:08 之间,如果您尝试访问服务器,浏览器最终会超时,而其他时候它最终会达到您从 Apache 立即获得 502 错误网关的程度.这告诉我在此期间 cherrypy 仍在接受套接字连接,但日志显示请求没有到来。甚至 cherrypy 访问日志也没有显示任何内容。

127.0.0.1 - - [05/Jan/2017:11:23:04] "GET /***/get_joblist HTTP/1.1" 200 18 "" "***/2.0"
127.0.0.1 - - [05/Jan/2017:11:59:09] "GET /***/upload_printer HTTP/1.1" 200 38 "" "***/2.0"

在这一天,错误日志文件中有两次请求超时,但这并不常见。

    [05/Jan/2017:11:22:04]  Traceback (most recent call last):
      File "c:\python27\lib\site-packages\cherrypy\_cpwsgi.py", line 169, in trap
        return func(*args, **kwargs)
      File "c:\python27\lib\site-packages\cherrypy\_cpwsgi.py", line 96, in __call__
        return self.nextapp(environ, start_response)
      File "c:\python27\lib\site-packages\cherrypy\_cpwsgi.py", line 379, in tail
        return self.response_class(environ, start_response, self.cpapp)
      File "c:\python27\lib\site-packages\cherrypy\_cpwsgi.py", line 222, in __init__
        self.run()
      File "c:\python27\lib\site-packages\cherrypy\_cpwsgi.py", line 320, in run
        request.run(meth, path, qs, rproto, headers, rfile)
      File "c:\python27\lib\site-packages\cherrypy\_cprequest.py", line 603, in run
        raise cherrypy.TimeoutError()
    TimeoutError

    [05/Jan/2017:11:22:05]  Traceback (most recent call last):
      File "c:\python27\lib\site-packages\cherrypy\_cpwsgi.py", line 169, in trap
        return func(*args, **kwargs)
      File "c:\python27\lib\site-packages\cherrypy\_cpwsgi.py", line 96, in __call__
        return self.nextapp(environ, start_response)
      File "c:\python27\lib\site-packages\cherrypy\_cpwsgi.py", line 379, in tail
        return self.response_class(environ, start_response, self.cpapp)
      File "c:\python27\lib\site-packages\cherrypy\_cpwsgi.py", line 222, in __init__
        self.run()
      File "c:\python27\lib\site-packages\cherrypy\_cpwsgi.py", line 320, in run
        request.run(meth, path, qs, rproto, headers, rfile)
      File "c:\python27\lib\site-packages\cherrypy\_cprequest.py", line 603, in run
        raise cherrypy.TimeoutError()
    TimeoutError

我们不会更改响应超时,因此这应该是默认的 5 分钟。基于这个假设,错误与任何挂起的请求都不相关。 11:22:04 的超时意味着 11:18:04 的请求,但当时的所有请求都成功了。而确实挂起的 8 个请求比 5 分钟早得多并且从未超时。

为什么一种类型的请求对一个用户会挂起,但对其他用户继续成功工作?

如果他们之前已经工作了几天或几周,为什么他们会挂机?

为什么请求超时没有清除所有这些?

为什么服务器达到了根本不接受任何请求的地步?确定 8 个并发请求不是服务器的最大值吗?

为什么服务器仍然接受套接字连接但不处理请求?

对于如何诊断或解决这些问题的任何建议,我们将不胜感激。

谢谢, 帕特里克

我相信我们终于找到了。

在一组非常具体的条件下,它正在对从事务内调用的单独数据库游标执行查询(即第二个查询不在事务中)。因此,一个连接在 SQL 中持有一个 table 锁,而第二个连接正在等待该锁,但两者都来自同一个 Python 线程。数据库连接也没有超时设置(默认是无限的),所以它会永远陷入自己的死锁状态。只要没有人查询交易中持有的相同 tables,系统就会继续工作。最终,当其他 users/threads 试图访问数据库的相同锁定区域时,他们也将永远等待。

我不认为 SQL 将此视为死锁,因为它期望一个连接完成事务并释放锁。我不认为 CherryPy 可以终止线程,因为 SQL 连接有控制权。