Медленный отчет об исключениях в Кемале - PullRequest
Новая
       38

Медленный отчет об исключениях в Кемале

1 голос
/ 07 февраля 2020

Я использую кристалл 32.1 и Kemal. В случае, если у меня возникла исключительная ситуация во время выполнения, для печати трассировки потребуется 21 секунда. Есть идеи, почему это так долго?

500 GET /chats/by_sale/1 21280.52ms

Backtrace: 

web_1     | I, [2020-02-07 17:57:33 +00:00 #1]  INFO -- : [1]
web_1     | Exception: Expected string for object name (JSON::Error)
web_1     |   from /usr/share/crystal/src/json/builder.cr:308:16 in 'start_scalar'
web_1     |   from /usr/share/crystal/src/json/builder.cr:295:11 in 'start_scalar'
web_1     |   from /usr/share/crystal/src/json/builder.cr:194:5 in 'start_object'
web_1     |   from src/service/json.cr:220:5 in 'object'
web_1     |   from src/controller/chat.cr:37:5 in '->'
web_1     |   from lib/kemal/src/kemal/route.cr:255:3 in '->'
web_1     |   from lib/kemal/src/kemal/route_handler.cr:255:3 in 'process_request'
web_1     |   from lib/kemal/src/kemal/route_handler.cr:17:7 in 'call'
web_1     |   from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call_next'
web_1     |   from lib/kemal/src/kemal/websocket_handler.cr:13:14 in 'call'
web_1     |   from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call_next'
web_1     |   from lib/kemal/src/kemal/filter_handler.cr:21:7 in 'call'
web_1     |   from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call_next'
web_1     |   from src/middleware/authenticate.cr:17:7 in 'call'
web_1     |   from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call_next'
web_1     |   from lib/kemal/src/kemal/static_file_handler.cr:68:9 in 'call'
web_1     |   from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call_next'
web_1     |   from lib/kemal/src/kemal/exception_handler.cr:8:7 in 'call'
web_1     |   from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call_next'
web_1     |   from lib/kemal/src/kemal/log_handler.cr:8:37 in 'call'
web_1     |   from /usr/share/crystal/src/http/server/handler.cr:26:7 in 'call_next'
web_1     |   from lib/kemal/src/kemal/init_handler.cr:12:7 in 'call'
web_1     |   from /usr/share/crystal/src/http/server/request_processor.cr:48:11 in 'process'
web_1     |   from /usr/share/crystal/src/http/server/request_processor.cr:22:3 in 'process'
web_1     |   from /usr/share/crystal/src/http/server.cr:497:5 in 'handle_client'
web_1     |   from /usr/share/crystal/src/http/server.cr:463:13 in '->'
web_1     |   from /usr/share/crystal/src/fiber.cr:255:3 in 'run'
web_1     |   from /usr/share/crystal/src/fiber.cr:47:34 in '->'
web_1     |   from ???
web_1     |
web_1     | 2020-02-07 17:57:54 UTC 500 GET /chats/by_sale/1 21280.52ms

1 Ответ

0 голосов
/ 21 февраля 2020

Большой размер для комментария, чтобы сделать его ответом.

Как бы я справился с этим, запустив ваш сервер в gdb, а затем в «середине 21-секундной паузы» вы нажали Ctrl + c на вашем сервере. Это приведет вас в GDB. Затем запустите команду gdb backtrace и посмотрите, что она вам скажет. Другой вариант может заключаться в том, чтобы запустить профилировщик на нем, есть несколько упомянутых здесь : или даже gdb " profileman бедняков", который также работает для кристалла (в OS X * Команда 1008 * делает нечто подобное FWIW) и запускает ее во время рассматриваемого замедления.

...