Error location in test submodules

[zeRusski]

I am a big fan of having tests alongside code so (module+ test ...) is magic. The only annoyance I've been running into lately is error reporting. If I have many test chunks spread around my code and some code change throws an exception or a contract violation it is impossible to tell which test triggered it. The only thing in the context is (submod "file.rkt" test):1:1. On occasion you get the exact point the exception happened but again no context, so no way to figure which check specifically ran the buggy code. Normally I would go through a dance of bisecting to pinpoint the culprit, but now that I have many tests its become a major pain. Is there a better way?

Thanks

[Tom Gillespie]

Are you using emacs racket-mode? I have experience this issue only in that mode since it does not (to my knowledge) implement all the error anchoring features of DrRacket. If you run in DrRacket the errors and contract violations should be highlighted as in the screengrab below. Best,

Tom

On Tue, Apr 2, 2019 at 3:41 PM zeRusski <vladile...@gmail.com> wrote:

I am a big fan of having tests alongside code so (module+ test ...) is magic. The only annoyance I've been running into lately is error reporting. If I have many test chunks spread around my code and some code change throws an exception or a contract violation it is impossible to tell which test triggered it. The only thing in the context is (submod "file.rkt" test):1:1. On occasion you get the exact point the exception happened but again no context, so no way to figure which check specifically ran the buggy code. Normally I would go through a dance of bisecting to pinpoint the culprit, but now that I have many tests its become a major pain. Is there a better way?

Thanks

--
You received this message because you are subscribed to the Google Groups "Racket Users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to racket-users...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Eric Griffis]

On Tue, Apr 2, 2019 at 1:04 PM Tom Gillespie <tgb...@gmail.com> wrote:
>
> Are you using emacs racket-mode?

I am, almost exclusively. Exception and check failure locations can be a pain, but they work in general.

> On Tue, Apr 2, 2019 at 3:41 PM zeRusski <vladile...@gmail.com> wrote:
>>
>> If I have many test chunks spread around my code and some code change throws an exception or a contract violation it is impossible to tell which test triggered it. The only thing in the context is (submod "file.rkt" test):1:1.

Let's make this concrete. If I create a /tmp/somefile.rkt in Emacs:

#lang racket/base
(define f (λ _ (error 'FAIL)))
(module+ test
  (require rackunit)
  (define OK (string->unreadable-symbol "OK"))
  (define-simple-check (check-OK val)
    (eq? val OK))
  (check-OK OK)
  (check-OK #f)
  (check-OK (f)))

and hit C-c C-c with my cursor inside the test sub-module, it prints this in my Racket REPL:

--------------------
; FAILURE
; /tmp/somefile.rkt:9:2
name:       check-OK
location:   somefile.rkt:9:2
params:     '(#f)
--------------------
; error: FAIL
; Context:
;  (submod "/tmp/somefile.rkt" test):1:1 [running body]

The first check succeeds silently.

The second check fails because #f is not OK. The location is accurate and automatically linked to the source.

The third check is never invoked. While evaluating the argument, f throws an exception and the REPL gives no useful context. I think you're asking specifically about this case. If the error is in the code being tested and not in the test itself, I'd want to know where the exception was raised.

In Emacs, hitting C-u C-c C-c inside the test sub-module exposes the context I'm looking for:

; ...
--------------------
; error: FAIL
; Context (errortrace):
;    /tmp/somefile.rkt:2:15: (error (quote FAIL))
; ...

If I'm generating tests with macros, getting the source locations right can be a hassle. Sometimes, it's easier to just add with-check-info:

#lang racket/base
(define f (λ _ (error 'FAIL)))
(module+ test
  (require rackunit)
  (define OK (string->unreadable-symbol "OK"))
  (define-syntax-rule (check-OK-form expr)
    (let ([val expr])
      (with-check-info (['input 'expr] ['expected OK] ['actual val])
        (check eq? val OK))))
  (check-OK-form OK)
  (check-OK-form (values #f))
  (check-OK-form (f)))

Even without a C-u prefix, the input can help locate the offending check:

--------------------
; FAILURE
; /tmp/somefile.rkt:9:8
input:      (values #f)
expected:   OK
actual:     #f
name:       check
location:   somefile.rkt:9:8
--------------------
; error: FAIL
; Context:

;  (submod "/tmp/somefile.rkt" test):1:1 [running body]

Most of the time, this is enough for me and I have a habit of polishing cannon balls.

Eric

[zeRusski]

> Are you using emacs racket-mode?

I am, almost exclusively. Exception and check failure locations can be a pain, but they work in general.

 

What Eric said :) But when in doubt I always compare behavior with DrRacket and raco, and racket-mode stands tall here and does at least what they do, so it isn't one to point fingers at.

 

The third check is never invoked. While evaluating the argument, f throws an exception and the REPL gives no useful context. I think you're asking specifically about this case. If the error is in the code being tested and not in the test itself, I'd want to know where the exception was raised.

In Emacs, hitting C-u C-c C-c inside the test sub-module exposes the context I'm looking for:

; ...
--------------------
; error: FAIL
; Context (errortrace):
;    /tmp/somefile.rkt:2:15: (error (quote FAIL))
; ...

Eric, that's exactly what I'm asking about - perfect example - thank you. However that "context" you speak of isn't terribly helpful. It does indeed point where error occurs - ok'ish when its in the surrounding module you control, completely useless when its in some library or collection or kernel - but notice how it doesn't tell you which (check ...) triggered it, so if you have many of those, how in the world could you tell? That f-function that throws could be called by any number of other functions and code. See what I mean?

 

If I'm generating tests with macros, getting the source locations right can be a hassle. Sometimes, it's easier to just add with-check-info:

Oh wow, this is great. Wasn't aware of this nifty macro! I can see how I could wrap every rackunit check in something that effectively names it, so that you could see who triggered an error. Just like in your example. That's basically wrapping rackunit with your preferred interface - requires work, but would help. Your solution comes very close to what I want. I wonder why something like this isn't the default. Simply haven't the time to implement and provide it to public, or people don't usually feel the need for it? If the latter, then is my test-debug flow doesn't match what Racket expects me to do?

 Thanks

[zeRusski]

Argh, I was too hasty to declare the with-check-info the winner here. Note that you get this extra info when the check actually fails, in your example above the (values #f) case fails, note the next one that calls (f) that throws. In this latter case the stack is nowhere to be found and no extra check info is present, so you are essentially back to square one, sigh. Now this really bothers me cause all of my tests turn into a black box that I need to poke and prod whenever something breaks.

[Lukas Lazarek]

If you want your tests to catch exceptions you need to wrap them in exception handlers, which you could write a macro to do for you; as Eric noted though you need to be careful to preserve source locations.

These kinds of issues (error messages and managing source locations when using macros) led me to write a small testing package that might suit your needs.

Using the package you could do something like this:

#lang racket

(require ruinit)

(define (f x)
  (error 'f))

(define-test-syntax (fail-if-throws test)
  #'(with-handlers ([exn?
                     (λ (e)
                       ((error-display-handler) (exn-message e) e)
                       (fail "Exception thrown during test (see above)"))])
      test))

(test-begin
  (fail-if-throws (test-= (f 2) 2)))

which shows a message like this: (running with errortrace to get the exception context)

; error: f
; Context (errortrace):
;    tmp.rkt:6:2: (error (quote f))
;    tmp.rkt:16:18: (test-= (f 2) 2)
;    ...
--------------- FAILURE ---------------
location: test4.rkt:16:2
test:     (fail-if-throws (test-= (f 2) 2))
message:  Exception thrown during test (see above)
---------------------------------------

As requested, this points you to both the source of the exception and the test in which it was thrown.

Lukas

[David Storrs]

I'll also throw my hat in the ring with handy/test-more, which I'm in the process of breaking out into a separate module but have not yet found the tuits to finish.

It takes a different approach than rackunit:  Tests always have output regardless of whether they succeed or fail.  Running a different number of tests than expected is an error.  Not declaring how many tests you will run (or, equivalently, putting (done-testing) at the bottom of your file) is a warning.  Tests return their final value so that you can use the results of a test as part of a separate test.

Typically you will group tests in a test-suite.  A test suite is itself a test, the nature of which is "none of my tests threw an exception that they didn't handle."  As such, the test suite will report a failing test if an exception occurs, but the test script as a whole will continue.

#lang racket

(require "../collaborations.rkt" handy/test-more)

  (test-suite
   "collaboration-id"

   (is (collaboration-id "public")
       1
       "happy path: found the public collaboration")

   (throws (thunk (collaboration-id "foo"))
           exn:fail:db:num-rows:zero?
           "collaboration-id throws if there was no such collaboration and #:create was #f")

   (define foo-id (lives (thunk (collaboration-id "foo" #:create #t))
                         "(collaboration-id 'foo' #:create #t) worked when the collaboration w\
as NOT there "))
   (if (equal? 'windows (system-type 'os))
       (ok 'do-some-windows-only-tests "did the windows-only tests")
       (ok #t "did NOT do the windows-only tests because this isn't Windows")))

> racket example.rkt

######## (START test-suite:  collaboration-id)
ok 1 - happy path: found the public collaboration
ok 2 - collaboration-id throws if there was no such collaboration and #:create was #f
ok 3 - (collaboration-id 'foo' #:create #t) worked when the collaboration was NOT there
ok 4 - did NOT do the windows-only tests because this isn't Windows
ok 5 - test-suite completed without throwing uncaught exception

Total tests passed so far: 5
Total tests failed so far: 0
######## (END test-suite:  collaboration-id)
WARNING: Neither (expect-n-tests N) nor (done-testing) was called.  May not have run all tests.

--

[zeRusski]

If you want your tests to catch exceptions you need to wrap them in exception handlers, which you could write a macro to do for you; as Eric noted though you need to be careful to preserve source locations.

This gave me an idea, so I've been reading rackunit docs finally. I'm about halfway through and I don't exactly understand the machinery yet but with your note above and what I've read so far the following code actually does what I want:

(module+ test
  (require rackunit)
  (define-check (my-check pred thunk)
    (with-handlers ((;; exn predicate
                     (λ (exn) (and (not (exn:test:check? exn))
                                   (exn:fail? exn)))
                     ;; exn handler
                     (λ (e) (with-check-info (('exn (make-check-info 'error e)))
                              (fail-check)))))
      (check-pred pred (thunk))))
  ;; throws
  (my-check identity (thunk (f)))
  ;; fails
  (check eq? 2 3)
  ;; succeeds
  (check eq? 3 3))

Here's the output that preserves location of the check that failed:

--------------------
; FAILURE
; /Users/russki/Code/fcgi-rkt/play.rkt:24:2
name: my-check
location: play.rkt:24:2
params: '(#<procedure:identity> #<procedure:temp4>)
exn:
#(struct:check-info error #(struct:exn:fail "f-failed" #<continuation-mark-set>))
--------------------
--------------------
; FAILURE
; /Users/russki/Code/fcgi-rkt/play.rkt:26:2
name: check
location: play.rkt:26:2
params: '(#<procedure:eq?> 2 3)
--------------------

This is a good start I think. To make it useful you'd want to capture the errortrace somehow, unpack and report it in the check-info. That is you report both the failed test location and the exception with its errortrace. I'm sure I'll soon find out how to do all that so that a) rackunit API is used and b) report follows Racket and rackunit style as much as possible. If you can help of top of your head, that'd be great. Also note the necessity of wrapping the test body in a thunk, which is annoying but understandable and the docs make a note as to why that is. We could fix that and other boilerplate with a macro. I'm just trying to think how I could minimize the damage to rackunit proper. Speaking of ...

It is tempting to build my own thing for testing but I'll resist it as best I can. I'd much rather just have a tiny macro that doesn't interfere with rackunit and doesn't impose my oft ill-advised and rash preconceptions. The more I read rackunit docs the more I'm convinced I wouldn't be able to improve on it without making a big mess. It is possible that I'm going to run into more annoying little gotchas that I'd want to fix, but I'm not there, yet. Please, don't let my current attitude stop you.

[Greg Hendershott]

> Are you using emacs racket-mode? I have experience this issue only in that mode since it does not (to my knowledge) implement all the error anchoring features of DrRacket.

It might just be that you have DrRacket set to user a higher
errortrace level than racket-mode?

That is, in DrR, Language | Choose Language | Dynamic Properties, you
may have chosen one of the "Debugging" radio buttons and checked
"Preserve stack trace".

In racket-mode, the equivalent is the `racket-error-context` variable:

https://github.com/greghendershott/racket-mode/blob/master/Reference.md#racket-error-context

If you have it set to 'low or 'medium, you might not get as much error
context as with 'high (just like if you had "weaker" options in that
DrR dialog box, DrR wouldn't show you as good error context).

As Eric notes, you can leave this set to 'low or 'medium, and do C-u
C-c C-c to re-reun with it temporarily set to 'high. This can be a
nice way to get the best of both worlds: Normally things build and run
faster (errortrace can be slow). If you experience an error, and the
message isn't ideal, you can C-u C-c C-c.


Finally, racket-repl-mode tries to notice Racket error messages in the
output and "linkify" them. You can click them with the mouse, or use
the standard M-x next-error (often bound to C-x `) to go to the error
location. This works with rackunit failures as well as errors.

Of course, it helps if the error file is /path/to/foo.rkt instead of
foo.rkt. Sometimes Racket tries to be helpful and abbreviate long
pathnames to be <pkgs>. racket-mode tries to defeat this abbreviation
so go-to-error can work. :)

Also, some macros don't do the ideal thing -- i.e. don't use e.g.
syntax/loc or quasisyntax/loc -- and the error location is inside the
macro when it might make more sense for it to be the macro use site.
There's not much racket-mode can do about that, AFAICT.


p.s. I didn't feel like you were dissing racket-mode, so I hope the
above doesn't sound defensive. I want to explain what it attempts to
do. I dogfood it heavily and I don't like it to annoy me. :) However
I know it's far from perfect. Also there are sometimes long stretches
where I have to be mostly just another user of racket-mode for $WORK,
and can't really detour to work on racket-mode much. Fortunately there
are other people who help contribute fixes and improvements (although
sometimes I get so busy I can barely keep up with their offered help,
and feel doubly guilty).

[Tom Gillespie]

Hi Greg,

    Thank you for the very detailed explanation. I was also very much not my intention to belittle racket-mode and I will evoke my "yes indeed my knowledge was quite incomplete." I have learned many very useful things from this thread (C-u C-c C-c is a reminder that stopping by the manual is usually surprisingly productive in all parts of the racket world)! As you suggest, I'm also fairly certain that some of my issues came from me writing my own macros and stripping the loc without realizing what I was doing (syntax vs syntax/loc was on the list of things to contribute to the docs but has now been bumped up). I wonder if there is a way to indicate that the source location of a piece of code has been stripped and warn the user about it and whether that would result in a blizzard of warnings or whether it might be useful for indicating a potential source of missing debug information (a hard problem).

Best!

Tom

PS Extra major thank you for all your work on racket-mode I find myself missing many of its features whenever I have to work in another language or editor!

[zeRusski]

Alright, tried to fix it as I see fit. Naturally, my understanding of rackunit source doesn't go far, but here's the PR: https://github.com/racket/rackunit/pull/107

Just keeping it real with Racket, I guess.