Статьи

Чтение Clojure Stacktraces

Трассировки Clojure не очень удобны для пользователя. Как только я привык к статус-кво, я забыл, сколько шума живет в трассировке стека; однако, каждый раз начинающий Clojure будет напоминать сообществу, что трассировки стека немного запутаны. Вы можете обвинить JWM, отсутствие приоритетов со стороны сообщества Clojure или кого-то еще, если хотите, но реальность такова — я не ожидаю, что стековые трассы изменятся в ближайшее время. Эта запись в блоге посвящена отделению сигнала от шума внутри трассировки стека.

примечание: весь код для этой записи блога можно найти по адресу: http://github.com/blog-jayfields-com/Reading-Clojure-Stacktraces

. Начнем с очень простого примера.

(ns reading-clojure-stacktraces.core)

(defn foo [] (throw (RuntimeException. "thrown")))

(defn -main []
  (foo))

Запустив (я использую ‘lein run’) приведенный выше код, вы должны получить трассировку стека, которая выглядит как вывод ниже.

lmp-jfields03:reading-clojure-stacktraces jfields$ lein run
Exception in thread "main" java.lang.RuntimeException: thrown
 at reading_clojure_stacktraces.core$foo.invoke(core.clj:3)
 at reading_clojure_stacktraces.core$_main.invoke(core.clj:6)
 at clojure.lang.Var.invoke(Var.java:397)
 at user$eval37.invoke(NO_SOURCE_FILE:1)
 at clojure.lang.Compiler.eval(Compiler.java:6465)
 at clojure.lang.Compiler.eval(Compiler.java:6455)
[blah blah blah]

Я отсканировал немало фрагментов стека и заменил их [бла-бла-бла]. Я сделал это, потому что это то, что я делаю и мысленно, я ищу последнюю строку, которая содержит созданный мной файл, и игнорирую все после нескольких строк ниже моей строки. Это моя первая рекомендация — если вы видите трассировку стека, скорее всего, проблема в вашем коде, а не в Clojure. Ищите последнюю строку вашего кода (N) и игнорируйте каждую строку ниже N + 3.

В этом примере пользователь $ eval … вероятно имеет отношение к lein, и я могу с уверенностью предположить, что проблема, вероятно, не в там. Двигаясь оттуда, я вижу строку из моего кода:

reading_clojure_stacktraces.core$_main.invoke(core.clj:6)

Когда я читаю приведенную выше строку, я вижу, что проблема заключается в пространстве имен ‘read-clojure-stacktraces / core’, в функции ‘-main’, в файле core.clj, в строке 6. Я не являюсь экспертом по внутренним компонентам Clojure, но я считаю, что Clojure на самом деле создает класс с именем reading_clojure_stacktraces.core $ _main с помощью метода invoke; однако, честно говоря, я не знаю (и вам это тоже не нужно). Независимо от того, создан ли класс или нет, имеет смысл отформатировать строку так, чтобы она соответствовала допустимому имени класса Java, что объясняет, почему наши дефисы были преобразованы в подчеркивания.

Двигаясь вверх по другой строке, я вижу, что проблема, скорее всего, связана с функцией ‘foo’ пространства имен read-clojure-stacktraces. Быстрый просмотр исходного кода показывает, что строка 3 файла core.clj содержит вызов throw,и все имеет смысл.

Если бы все стеки трассировки Clojure были такими простыми, я бы не стал беспокоиться об этой записи в блоге; однако, когда вы вводите анонимные функции, все может стать немного сложнее.

Следующий фрагмент кода удаляет функцию ‘foo’ и выдает исключение из анонимной функции.

(ns reading-clojure-stacktraces.core)

(defn -main []
  (#(throw (RuntimeException. "thrown"))))

Другая поездка в «lein run» дает следующий результат

Exception in thread "main" java.lang.RuntimeException: thrown
 at reading_clojure_stacktraces.core$_main$fn__9.invoke(core.clj:4)
 at reading_clojure_stacktraces.core$_main.invoke(core.clj:4)
 at clojure.lang.Var.invoke(Var.java:397)
 at user$eval38.invoke(NO_SOURCE_FILE:1)
 at clojure.lang.Compiler.eval(Compiler.java:6465)

Приведенная выше трассировка стека дает вам правильный файл и номер строки, из которой возникла проблема; однако вы заметите, что функция, вызвавшая исключение, стала немного менее легкой для идентификации. Мое использование анонимной функции привело к тому, что Clojure назвал функцию fn__9, и в этом нет ничего плохого. На самом деле этот пример особенно удобен для чтения, так как трассировка стека показывает, что fn__9 была создана внутри функции -main.

Я ожидаю, что вы сможете найти проблему с нашим надуманным примером без какой-либо дополнительной помощи; однако производственный код (часто использующий функции высокого порядка) может привести к значительно более сложным трассировкам стека. Вы можете отказаться от анонимных функций, но есть хорошая середина, которая также полезна для отладки — временно называйте свои анонимные функции.

Clojure»читатель преобразует литерал анонимной функции следующим образом.

#(...) => (fn [args] (...))

Следовательно, следующий код будет таким же, как в примере выше, с точки зрения Clojure.

(ns reading-clojure-stacktraces.core)

(defn -main []
  ((fn [] (throw (RuntimeException. "thrown")))))

Еще один быстрый ‘lein run’ подтверждает, что трассировка стека та же самая (и я не вижу смысла повторять это здесь). Однако теперь, когда мы перешли на fn, мы можем предоставить (редко используемое, необязательное) имя.

(ns reading-clojure-stacktraces.core)

(defn -main []
  ((fn i-throw [] (throw (RuntimeException. "thrown")))))

На этом этапе ‘lein run’ должен выдать следующий результат. 

Exception in thread "main" java.lang.RuntimeException: thrown
 at reading_clojure_stacktraces.core$_main$i_throw__9.invoke(core.clj:4)
 at reading_clojure_stacktraces.core$_main.invoke(core.clj:4)
 at clojure.lang.Var.invoke(Var.java:397)
 at user$eval38.invoke(NO_SOURCE_FILE:1)
 at clojure.lang.Compiler.eval(Compiler.java:6465)

Теперь наша строка содержит немного больше информации. Два знака $ по-прежнему указывают на то, что функция с проблемой — это функция, созданная внутри -main; тем не менее, наша трассировка стека также включает имя (выделено жирным шрифтом), которое мы указали для нашей функции. Вы можете использовать любые допустимые символы символов, поэтому не стесняйтесь указывать в имени все, что хотите, во время отладки.


примечание: символы начинаются с нецифровых символов и могут содержать буквенно-цифровые символы и *, +,!, -, _ и?

clojure.org .

До сих пор все примеры были несколько шумными, но их легко мысленно отфильтровать. К сожалению, идиоматический код Clojure также может привести к трассировке стека, которая перебрасывается назад и вперед между вашим кодом и стандартной библиотекой, оставляя вам возможность просматривать значительно более длинные трассировки стека.

Следующий фрагмент кода генерирует исключение NullPointerException из-за ошибки, которую я явно допустил, но последняя строка «моего кода» находится в нижней половине длинной трассировки стека.

(ns reading-clojure-stacktraces.core)

(defn foo []
  (map inc [0 1 nil]))

(defn -main []
  (println (foo)))

Приведенный выше пример кода создает следующую трассировку стека. 

Exception in thread "main" java.lang.NullPointerException
 at clojure.lang.Numbers.ops(Numbers.java:942)
 at clojure.lang.Numbers.inc(Numbers.java:110)
 at clojure.core$inc.invoke(core.clj:862)
 at clojure.core$map$fn__3811.invoke(core.clj:2430)
 at clojure.lang.LazySeq.sval(LazySeq.java:42)
 at clojure.lang.LazySeq.seq(LazySeq.java:60)
 at clojure.lang.RT.seq(RT.java:466)
 at clojure.core$seq.invoke(core.clj:133)
 at clojure.core$print_sequential.invoke(core_print.clj:46)
 at clojure.core$fn__4990.invoke(core_print.clj:140)
 at clojure.lang.MultiFn.invoke(MultiFn.java:167)
 at clojure.core$pr_on.invoke(core.clj:3264)
 at clojure.core$pr.invoke(core.clj:3276)
 at clojure.lang.AFn.applyToHelper(AFn.java:161)
 at clojure.lang.RestFn.applyTo(RestFn.java:132)
 at clojure.core$apply.invoke(core.clj:600)
 at clojure.core$prn.doInvoke(core.clj:3309)
 at clojure.lang.RestFn.applyTo(RestFn.java:137)
 at clojure.core$apply.invoke(core.clj:600)
 at clojure.core$println.doInvoke(core.clj:3329)
 at clojure.lang.RestFn.invoke(RestFn.java:408)
 at reading_clojure_stacktraces.core$_main.invoke(core.clj:7)
 at clojure.lang.Var.invoke(Var.java:397)
 at user$eval37.invoke(NO_SOURCE_FILE:1)
 at clojure.lang.Compiler.eval(Compiler.java:6465)
 at clojure.lang.Compiler.eval(Compiler.java:6455)

В подобных ситуациях я обычно смотрю на верхние несколько строк, чтобы получить немного контекста, а затем прокручиваю вниз, чтобы найти последнюю строку «моего кода». Глядя на верхние 4 строки из трассировки стека, я вижу, что проблема связана с функцией inc, которая была передана функции высокого порядка с именем map. Если я посмотрю на отца вниз по трассировке стека, то увижу, что в строке 7 в файле read-clojure-stacktraces.core проблема возникла в «моем коде».

Если вы посмотрите на строку 7 из (read-clojure-stacktraces) core.clj, вы заметите, что я просто печатаю результаты вызова foo — но проблема, похоже, связана с функцией map, которая вызывается внутри foo. Это потому что карта
лениваяи оценка откладывается до тех пор, пока мы не попытаемся напечатать результаты отображения inc. Хотя это не совсем очевидно, трассировка стека содержит все подсказки, необходимые для поиска проблемы. Строка 3 сообщает нам, что inc получает ноль. Строка 4 сообщает нам, что это происходит внутри карты. Строка 5 дает нам понять, что мы имеем дело с ленью. И строка, содержащая наше пространство имен, дает нам знать, с чего начать поиск.

Следующий пример очень похож; однако он использует частичное для достижения того же результата.

(ns reading-clojure-stacktraces.core)

(defn foo []
  (map (partial + 1) [0 1 nil]))

(defn -main []
  (println (foo)))

Приведенный выше пример кода создает следующую трассировку стека.

Exception in thread "main" java.lang.NullPointerException
 at clojure.lang.Numbers.ops(Numbers.java:942)
 at clojure.lang.Numbers.add(Numbers.java:126)
 at clojure.core$_PLUS_.invoke(core.clj:927)
 at clojure.lang.AFn.applyToHelper(AFn.java:163)
 at clojure.lang.RestFn.applyTo(RestFn.java:132)
 at clojure.core$apply.invoke(core.clj:602)
 at clojure.core$partial$fn__3794.doInvoke(core.clj:2341)
 at clojure.lang.RestFn.invoke(RestFn.java:408)
 at clojure.core$map$fn__3811.invoke(core.clj:2430)
 at clojure.lang.LazySeq.sval(LazySeq.java:42)
 at clojure.lang.LazySeq.seq(LazySeq.java:60)
 at clojure.lang.RT.seq(RT.java:466)
 at clojure.core$seq.invoke(core.clj:133)
 at clojure.core$print_sequential.invoke(core_print.clj:46)
 at clojure.core$fn__4990.invoke(core_print.clj:140)
 at clojure.lang.MultiFn.invoke(MultiFn.java:167)
 at clojure.core$pr_on.invoke(core.clj:3264)
 at clojure.core$pr.invoke(core.clj:3276)
 at clojure.lang.AFn.applyToHelper(AFn.java:161)
 at clojure.lang.RestFn.applyTo(RestFn.java:132)
 at clojure.core$apply.invoke(core.clj:600)
 at clojure.core$prn.doInvoke(core.clj:3309)
 at clojure.lang.RestFn.applyTo(RestFn.java:137)
 at clojure.core$apply.invoke(core.clj:600)
 at clojure.core$println.doInvoke(core.clj:3329)
 at clojure.lang.RestFn.invoke(RestFn.java:408)
 at reading_clojure_stacktraces.core$_main.invoke(core.clj:7)
 at clojure.lang.Var.invoke(Var.java:397)
 at user$eval37.invoke(NO_SOURCE_FILE:1)
 at clojure.lang.Compiler.eval(Compiler.java:6465)

Опять же, вы захотите просмотреть трассировку стека для подсказок. В приведенной выше трассировке стека мы видим, что строка 3 говорит нам, что + это проблема. Строка 7 сообщает нам, что частичное было использовано. И остальные подсказки такие же, как в предыдущем примере.

Снимание подсказок может поначалу показаться болезненным. Однако вы быстро научитесь отфильтровывать общий шум, связанный с Clojure. Например, все, что начинается с ‘clojure’ и выглядит как стандартное имя класса Java, вряд ли будет причиной возникновения проблемы. Например, clojure.lang.Numbers.ops вряд ли будет иметь ошибку. Кроме того, вы часто будете видеть одни и те же классы и методы, повторяемые при всех возможных ошибках — clojure.lang.AFn, clojure.lang.RestFn, clojure.core $ apply, clojure.lang.LazySeq, clojure.lang.RT, clojure. lang.MultiFn и т. д., и т. д. Эти функции часто используются как строительные блоки практически для всего, что делает Clojure. Эти линии обеспечивают немного сигнала, но (по большей части) можно смело игнорировать.

Снова, это может быть немного раздражающим иметь дело со следами стека Clojure, когда начинаешь; однако, если вы потратите время на то, чтобы понять, какие линии являются сигнальными, а какие — шумовыми, они становятся полезными инструментами отладки.

related: Если вам нужна библиотека тестирования, которая поможет вам отфильтровать часть шума трассировки стека, вы можете проверить
ожидания .