Explanation of the logs in AVA

[jcubic]

I have tests written in my Scheme interpreter. And I have a weird issue; it looks like a race condition.

(test "parser: should throw in invalid splice syntax extension"
      (lambda (t)
        ;; exception from (lips.parse ...) was affecting other tests #483
        (let ((throws (lambda (code)
                        ((self.eval "(async (lips, code) => {
                                       try {
                                         await lips.parse('$$10');
                                         return false;
                                        } catch(e) {
                                          return true;
                                        }
                                     })") lips code))))
          (t.is (throws "$$10") #t)
          (t.is (throws "&&10") #t)
          (t.is (to.throw (lips.parse "$$10")) #t)
          (t.is (to.throw (lips.parse "&&10")) #t))))

(test "numbers: exact->inexact"
      (lambda (t)
        (t.is (exact->inexact 10) 10.0)
        (t.is (exact->inexact 1/2) 0.5)
        (t.is (exact->inexact 0.5) 0.5)
        (t.is (exact->inexact 10+10i) 10.0+10.0i)
        (t.is (exact->inexact 1/2+1/2i) 0.5+0.5i)
        (t.is (exact->inexact 10.0+10.0i) 10.0+10.0i)))

This is the output of the tests:

(throws $$10)
  ✘ [fail]: numbers: exact->inexact failed: 10+10i != 10.0+10.0i in (exact->inexact 10.0+10.0i)
  ✔ parser: should throw in invalid splice syntax extension (1.5s)
(exact->inexact 10)
(exact->inexact 1/2)
(exact->inexact 0.5)
(exact->inexact 10+10i)
(throws &&10)
(exact->inexact 1/2+1/2i)
(to.throw (lips.parse $$10))
(exact->inexact 10.0+10.0i)
(to.throw (lips.parse &&10))
  ─

  numbers: exact->inexact

  failed: 10+10i != 10.0+10.0i in (exact->inexact 10.0+10.0i)

The t.is is a wrapper that does some comparison, and I added console.log to the first element.

(define-macro (t.is a b)
  "(t.is a b)

   Helper comparator for ava. It use equal? so it match two lists and strings.
   It use undecumented API that allow to delete StackTrace when assertion fail."
  (let ((attempt (gensym))
        (a_name (gensym))
        (b_name (gensym)))
    `(let ((,attempt (t.try (lambda (e)
                              (let ((,a_name (round-number ,a))
                                    (,b_name (round-number ,b)))
                                (print ,a_name)
                                (print ,b_name)
                                (if (equal? ,a_name ,b_name)
                                    (--> e (pass))
                                    (--> e (fail (concat "failed: " (repr ,a_name true)
                                                         " != " (repr ,b_name true)
                                                         " in " (repr ',a true))))))))))
       (if (not (. ,attempt 'passed))
           (--> (. ,attempt 'errors)
                (forEach (lambda (e)
                           (set-obj! e 'savedError #void)))))
       (--> ,attempt (commit)))))

Does this output mean that the code executed after the test finished? Or maybe it doesn't matter that all logs are after the title of the test.

Is it possible that the tests from one function execute at the same time as another function?

I'm not sure why the logs are out of sync. Is this something that AVA is doing? I'm trying to debug my code, and I'm trying to rule out the issue with the testing framework I'm using.

[novemberborn]

IIRC stdout/stderr are forwarded separately from tests results. t.log() should order correctly.

[jcubic]

Thanks. Will check next time when I have such a problem.