Shinmera / parachute

An extensible and cross-compatible testing framework.
https://shinmera.github.io/parachute
zlib License
94 stars 9 forks source link

Regarding the use of the output stream in the plain reporter #9

Closed eduardoacye closed 5 years ago

eduardoacye commented 5 years ago

Hello, I've been using your library and been quite happy with its implementation and extensibility.

I encountered an unexpected behavior when using the plain reporter. The output of the report looks weird when running in a terminal, but looks beautiful in Slime.

I like using Slime when running the tests during development, but also, I have a CI pipeline that runs a test script using SBCL directly.

The problem is in the way output functions are being used.

The plain reporter has an output stream associated with it, and in its implementation the following functions make use of this stream:

Summarize could be using two different output streams

The summarize implementation uses the value of (output report) for printing the main summary but also uses T for printing the failures.

I think it would be better to either use (output report) for the failure report, or have an additional output stream in the plain reporter to use as a failure output stream.

Implicit use of terminal-io and standard-output

The write-string, terpri, and force-output functions receive an output stream designator argument.

The format function uses these values differently, when the destination is T the output goes to *standard-output*.

These differences will not cause issues when running the tests in Slime, because of the way Swank sets up *terminal-io* and *standard-output*. But when running a Lisp script in the terminal, it could cause some visual issues, mainly because force-output will make use of *terminal-io*.

I think it would be better to modify the plain class definition to have:

(:default-initargs :stream *standard-output*)

or

(:default-initargs :stream *terminal-io*)

Regarding output stream flushing

You might want to consider using finish-output instead of force-output. From the CLHS:

finish-output attempts to ensure that any buffered output sent to output-stream has reached its destination, and then returns.

force-output initiates the emptying of any internal buffers but does not wait for completion or acknowledgment to return.

I'm not sure about how different implementations handle these two. SBCL seems to return nil in both functions for the fundamental-steams, and in Slime, the slime-output-stream specialization of these two functionalities makes force-output call finish-output with a deadline of 0.1 seconds.

Verifying the described behavior

Using the default output for the plain reporter

CL-USER> (ql:quickload :parachute)
To load "parachute":
  Load 1 ASDF system:
    parachute
; Loading "parachute"

(:PARACHUTE)
CL-USER> (in-package :parachute)
#<PACKAGE "PARACHUTE">
PARACHUTE> (defvar *custom-output-a* (make-string-output-stream))
*CUSTOM-OUTPUT-A*
PARACHUTE> (defvar *custom-output-b* (make-string-output-stream))
*CUSTOM-OUTPUT-B*
PARACHUTE> (define-test report-output
             (is = 1 1)
             (is = 0 1))
REPORT-OUTPUT
PARACHUTE> (let ((*standard-output* *custom-output-a*)
                 (*terminal-io* *custom-output-b*))
             (test 'report-output :report 'plain))
#<PLAIN 3 results>
PARACHUTE> (get-output-stream-string *custom-output-a*)
"        ?
  0.003 ✔
  0.000 ✘
  0.010 ✘

;; Summary:
Passed:     1
Failed:     1
Skipped:    0

;; Failures:
   1/   2 tests failed in PARACHUTE::REPORT-OUTPUT
The test form   1
evaluated to    1
when            0
was expected to be equal under =.

"
PARACHUTE> (get-output-stream-string *custom-output-b*)
"PARACHUTE::REPORT-OUTPUT
(is = 1 1)
(is = 0 1)
PARACHUTE::REPORT-OUTPUT
"

Using a custom output stream for the plain reporter

CL-USER> (ql:quickload :parachute)
To load "parachute":
  Load 1 ASDF system:
    parachute
; Loading "parachute"

(:PARACHUTE)
CL-USER> (in-package :parachute)
#<PACKAGE "PARACHUTE">
PARACHUTE> (defvar *custom-output-a* (make-string-output-stream))
*CUSTOM-OUTPUT-A*
PARACHUTE> (defvar *custom-output-b* (make-string-output-stream))
*CUSTOM-OUTPUT-B*
PARACHUTE> (defvar *custom-output-c* (make-string-output-stream))
*CUSTOM-OUTPUT-C*
PARACHUTE> (define-test report-output
             (is = 1 1)
             (is = 0 1))
REPORT-OUTPUT
PARACHUTE> (let ((*standard-output* *custom-output-a*)
                 (*terminal-io* *custom-output-b*))
             (test 'report-output :report 'plain :stream *custom-output-c*))
#<PLAIN 3 results>
PARACHUTE> (get-output-stream-string *custom-output-a*)
"
;; Failures:
   1/   2 tests failed in PARACHUTE::REPORT-OUTPUT
The test form   1
evaluated to    1
when            0
was expected to be equal under =.

"
PARACHUTE> (get-output-stream-string *custom-output-b*)
""
PARACHUTE> (get-output-stream-string *custom-output-c*)
"        ? PARACHUTE::REPORT-OUTPUT
  0.003 ✔   (is = 1 1)
  0.000 ✘   (is = 0 1)
  0.010 ✘ PARACHUTE::REPORT-OUTPUT

;; Summary:
Passed:     1
Failed:     1
Skipped:    0
"
Shinmera commented 5 years ago

The use of force-output is intentional, as it isn't particularly important for the code to know whether the flush has completed or not.