test line reporting doesn't always report test's file & line number

Question

If an Exception is thrown during test execution, the filename and line number are frequently not helpful for finding the problem. For instance, this code:

`
(require '[clojure.test :refer [deftest test-var]])

(deftest foo
(meta))

(test-var #'foo)
`

Will output an error at AFn.java:429.

`
ERROR in (foo) (AFn.java:429)
Uncaught exception, not in assertion.
expected: nil
actual: clojure.lang.ArityException: Wrong number of args (0) passed to: core/meta--4144
at clojure.lang.AFn.throwArity (AFn.java:429)

clojure.lang.AFn.invoke (AFn.java:28)
user/fn (error_reporting.clj:4)
clojure.test$test_var$fn__7670.invoke (test.clj:704)
clojure.test$test_var.invoke (test.clj:704)
user$eval6.invoke (error_reporting.clj:6)
clojure.lang.Compiler.eval (Compiler.java:6782)
...etc

`

(link: http://dev.clojure.org/jira/browse/CLJ-377?focusedCommentId=24016&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-24016 text: Rich's Comment 24016 on CLJ-377) says that he thinks the message should report the test file line rather than where the exception was thrown.

Approach: Filter the stacktrace class prefix {{clojure.lang.AFn}} from the top of error stacktraces.

After applying the patch, the above example outputs error_reporting.clj:4:

`
ERROR in (foo) (error_reporting.clj:4)
Uncaught exception, not in assertion.
expected: nil
actual: clojure.lang.ArityException: Wrong number of args (0) passed to: core/meta--4141
at clojure.lang.AFn.throwArity (AFn.java:429)

clojure.lang.AFn.invoke (AFn.java:28)
user$fn__3.invokeStatic (error_reporting.clj:4)
user/fn (error_reporting.clj:3)
clojure.test$test_var$fn__114.invoke (test.clj:705)
clojure.test$test_var.invokeStatic (test.clj:705)
clojure.test$test_var.invoke (test.clj:-1)
user$eval6.invokeStatic (error_reporting.clj:6)
user$eval6.invoke (error_reporting.clj:-1)
clojure.lang.Compiler.eval (Compiler.java:6939)
...etc

`

Patch: clj-1811.patch

Answer 1

Comment made by: ryfow

example file from description

Answer 2

Comment made by: alexmiller

A quick search on Github shows many cases where people call into the (admittedly private) file-and-line function. These users would be broken by the patch. Perhaps it would be better to create a new function or a new arity rather than removing the existing arity.

Just eyeballing it, but I suspect you've introduced reflection in a couple places in the new code, particularly these might need another type hint:

1. (.getName (.getClass (:test (meta test-var))))

2. (= (.getClassName %) test-var-class-name)

I need to look at more of the code to make a judgement on everything else. Seeing testing-vars in there means that this function is now dependent on external state, so need to think carefully to be sure that every calling context has that global state (or won't fail in bad ways if it doesn't). It would be helpful to see a discussion of your thinking about that in the "approach" section of the ticket description.

Answer 3

Comment made by: ryfow

Second attempt at a patch to resolve this issue. Corrects issues (link: http://dev.clojure.org/jira/browse/CLJ-1811?focusedCommentId=41115&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-41115 text: Alex pointed out)

Answer 4

Comment made by: ryfow

I've filled in some detail in the approach section.

I also added a new patch LINE_REPORTING_2.patch that addresses reflection warnings, restores the old arity of {{file-and-line}} and adds protection from people calling {{file-and-line}} from outside a testing context.

Answer 5

Comment made by: ryfow

While discussing an issue with my coworker James, I realized that this fix helps with shared functions calling {{(is)}}. Notice how the run of this sample code reports line 7 with LINE_REPORTING_2.patch applied. This test line is generally much more useful than the shared function line.

`
ryans-mbp:~/oss/clojure% cat -n error_reporting.clj

 1  (require '[clojure.test :refer [deftest test-var is]])
 2
 3  (defn shared-code [arg]
 4    (is arg))
 5
 6  (deftest test-shared-code
 7    (shared-code false))
 8
 9  (test-var #'test-shared-code)

ryans-mbp:~/oss/clojure% java -jar ~/.m2/repository/org/clojure/clojure/1.7.0/clojure-1.7.0.jar ./error_reporting.clj

FAIL in (test-shared-code) (error_reporting.clj:4)
expected: arg
actual: false
ryans-mbp:~/oss/clojure% java -jar target/clojure-1.8.0-master-SNAPSHOT.jar ./error_reporting.clj

FAIL in (test-shared-code) (error_reporting.clj:7)
expected: arg
actual: false
`

Answer 6

Comment made by: michaelblume

Patch doesn't apply anymore, but maybe this has been sorted by CLJ-1856?

Answer 7

Comment made by: alexmiller

This is not fixed by CLJ-1856, but could be if clojure.lang.AFn was filtered out of error stacktraces when finding the location. This is pretty specific - it might make sense to broaden to other calling paths too, not sure.

Attached a new patch that applies this filtering.

Answer 8

Reference: https://clojure.atlassian.net/browse/CLJ-1811 (reported by ryfow)