`alchemist-report-filter` fails to display relevant output

[renatomassaro]

Hello,

When using Alchemist Test Report, I noticed three common issues:

1. Sometimes, when there is a syntax error or compilation error, the error itself is not displayed at the test report buffer.
2. Sometimes, when the test finishes, the test summary (x tests, y failures, z skipped) is not displayed.
3. When multiple tests fail, only the first failed test is displayed.

Hacking around Alchemist's codebase I noticed you apply alchemist-report-filter as a filter to the output from start-process-shell-comand at function alchemist-report-fun. I disabled this filter by commenting out the set-process-filter, which forces Emacs to use its default process filter, and the result is:

• All three issues described above are gone.
• Output is no longer colored (as expected, since ansi-color isn't applied).

Ok, but I want colored output, so I went and "bisected" the filter to find the culprit. I used this minimal function:

(defun alchemist-report-filter (process output)
  (with-current-buffer (process-buffer process)
    (let* ((buffer-read-only nil))
      (insert output))))

And the three issues reappeared. Sigh. So, the default filter works fine, but this minimal filter above (without ansi-color) doesn't. But good news, it means it's not related to ansi-color. Then maybe the output is being batched and, for some reason, the final bits does not get written to the buffer.

I then stumbled upon this bit on the Emacs manual:

To make the filter force the process buffer to be visible whenever new text arrives, you could insert a line like the following just before the with-current-buffer construct: (display-buffer (process-buffer proc))

And it works! Now every time I run alchemist-report-run, the full output is displayed and it is colored!

I'm surprised to see no one else ever mentioned this, so maybe this is something that only affects my setup somehow, but in any case I'm opening this issue in the hopes that it may help someone out there.

My setup:

• Emacs 27.0.50
• Alchemist 1.8.2
• FreeBSD 12.0-RELEASE

The final filter function is:

(defun alchemist-report-filter (process output)
  "Process filter for report buffers."
  (display-buffer (process-buffer process)) ;; added line
  (with-current-buffer (process-buffer process)
    (let* ((buffer-read-only nil)
           (output (if (string= (process-name process) alchemist-test-report-process-name)
                       (alchemist-test-clean-compilation-output output)
                     output))
           (moving (= (point) (process-mark process))))
      (save-excursion
        (goto-char (process-mark process))
        (insert output)
        (set-marker (process-mark process) (point))
        (ansi-color-apply-on-region (point-min) (point-max)))
      (if moving (goto-char (process-mark `process))))))

[renatomassaro]

After a lot of debugging, I realized that the above "fix" is pretty much useless. It did reduce the occurrences of the described problem (maybe a placebo effect?), but it was clear the problem still persisted.

On a vanilla Emacs the output was never truncated, so I bisected my config to find what was wrong. Turns out the problem is the line number mode.

I use display-line-numbers-mode, with relative type. Since I use it everywhere, it is applied globally. As soon as I turned it off, there were no more occurrences of the problem. Out of curiosity I tried without relative, and the problem persists, so having display-line-numbers enabled on Alchemist Test Report is the root cause of this bug.

I don't know if this is a bug from Alchemist or Emacs (since display-line-numbers is a new, built-in library), but in any case I'll be closing this issue here. It makes little sense to have line numbers enabled on the Test Report buffer.

[renatomassaro]

So, uh, I stand corrected once again. It may happen with display-line-numbers-mode disabled. Sometimes the bug happens on the first couple runs, sometimes it will happen for the first time only after several test runs.

This bug happened with vanilla Emacs for me (nothing added except for the Alchemist package). I thought maybe it could lose some output due to GC, so I tuned gc-cons-threshold to a very low value (glitch happens) and a very large value (glitch also happens).

Given its lack of reproducibility, I'm unable to use a profiler or a debugger in a proper fashion. In order to preserve my mental sanity, I'm officially giving up. If someone else experiences something similar, please let me know.

I'll keep this issue closed because I don't know if it's at all related to Alchemist.

At the moment, as a workaround, I added "> /tmp/test.out" on alchemist-mix-test-default-options and keep a buffer open with the contents of file /tmp/test.out being tailed with auto-revert-tail-mode. Poor man's Report Mode :man_shrugging: