CherryPy - случайные запросы висит, то сервер перестает отвечать на запросы

Question

Мы сервер построен на следующем:

• CherryPy 3.2.2 для Windows,
• Python 2.7.1
• Мако 0.3.6
• SQLAlchemy 0.7.2
• pyodbc 2.1.8
• различные другие минорные компоненты

Он работает на следующей платформе:

• Windows Server 2008
• Microsoft SQL Server 2008 Web
• Хостинг VM
• XAMPP Apache шлюз

За последние несколько месяцев у нас было несколько случаев, когда херповый сервер стал невосприимчивым. Первый симптом заключается в том, что ajax запрашивает время, перезагружая страницу в браузере, а затем Apache вернет 502, потому что cherrypy больше не будет принимать какие-либо соединения. Перезапуск службы python устраняет проблему. Иногда он перейдет от тайм-аутов до 502 в течение 10 минут, в других случаях он может просто отключить тайм-аут более полутора часов, прежде чем мы поймем и должны перезапустить.

Сервер может работать в течение нескольких недель без проблем, но через несколько дней проблема может произойти 5 раз в течение нескольких часов.

Мы внедрили несколько дополнительных протоколов всех запросов для идентификации шаблонов. Во-первых, он не запускается каким-либо конкретным типом запроса, временем суток, загрузкой, пользователем и т. Д. Однако мы иногда получаем ошибки SQL-тупика, и иногда мы получаем ошибки тайм-аута запроса вихревого доступа. Тупики 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 

В пределах журнала отладки мы также распечатать идентификатор сеанса и имя пользователя, так что я могу видеть, где именно запросы приходят из.

Вчера, когда он пошел вниз, это то, что журнал отладки показал (работает в обратном направлении):

• Я перезагрузил сервер в 11:59:08
• Предыдущая запись в журнале была 11:23:11 с СНВ АЯКС get_orders user1 (без corrsponding FINISH)
• между 11:23:04 и 11:22:33 было 9 пар успешного начать и закончить просьбы различных пользователей и различных функций
• В 11:22:31 был START ajax get_orders User2 (без FINISH)
• 11:22:27 до 11:22:23 4 пары начинаются и заканчиваются, разными пользователями и функции
• 11:22:22 СНВ-Ajax do_substitutions User3 (без FINISH)
• 11:22:19 до 11:15:52 299 пар START и FINISH, разные пользователи (включая User1, User2 и User3) и различные функции (включая те, которые были видены)
• 11:15:52 a START ajax get_filling_pack User4 (без FINISH)
• 11:15:51 до 11:15:45 13 пар начинать и заканчивать
• 11:15:45 СТАРТ Ajax эхо USER5 (без FINISH)
• 11:15:43 до 11:14:56 63 пары START и FINISH
• 11:14:56 a START ajax echo User6 (без FINISH)
• 11:14:56 до 11:13:40 104 пары начинаются и заканчиваются
• 11:13:40 СНВ-Ajax update_supplies User7 (без FINISH)
• 11:13:38 до 11:13:17 36 пар начать и закончить
• 11:13:17 START post set_status User8 (нет FINISH)
• Затем нормальная деятельность до полуночи при перезапуске сервера

Между 11:23:11 и 11:59:08, если вы попытаетесь получить доступ к серверу, браузер, в конечном счете, отключится, тогда как в других случаях он в конечном итоге достиг точки, в которой вы получаете немедленный 502 плохих шлюза от Apache. Это говорит мне, что 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 одновременных запросов не являются максимальными для сервера?

Почему сервер все еще принимает соединения сокетов, но не обрабатывает запросы?

Любые предложения по тому, как я могу диагностировать или разрешать эти проблемы, будут весьма признательны.

Thanks, Patrick.

Answer 1

Я считаю, что мы, наконец, отслеживали это.

В очень специфическом наборе условий он выполнял запрос на отдельный курсор базы данных, вызываемый из транзакции (т. Е. Второй запрос не был в транзакции). Таким образом, одно соединение содержало блокировку таблицы в SQL, а второе соединение ожидало эту блокировку, но оба они происходили из одного и того же потока Python. Также не было тайм-аутов, установленных в соединениях с базой данных (по умолчанию это бесконечно), поэтому навсегда останется в своем тупике. Система будет работать до тех пор, пока никто не будет запрашивать те же таблицы, что и в транзакции. В конце концов, когда другие пользователи/потоки попытались получить доступ к одной и той же заблокированной области базы данных, они также были бы горничными, чтобы ждать вечно.

Я не думаю, что SQL видел это как тупик, потому что ожидал, что одно соединение завершит транзакцию и отпустит блокировку. Я не думаю, что CherryPy может завершить поток, потому что SQL-соединение имеет контроль.