racket-tests/indent-speed-* can fail on slow / loaded hosts.

[bremner]

I noticed that on some slower / overloaded CI hosts, at least indent-speed-1 can fail (13s versus the expected 10s). For the moment I've just disabled these tests on Debian, but of course it would be nice not to have to do that. Maybe the run times could be adjusted relative to the time to do some simple indentation? Failing that, maybe use ERT tags to tag those tests not expected to run in CI.

((alist-get 'racket-mode package-alist))
((emacs-version "28.2")
 (system-type gnu/linux)
 (x-gtk-use-system-tooltips t)
 (major-mode racket-mode)
 (racket--el-source-dir "/usr/share/emacs/site-lisp/elpa/racket-mode-20230425snapshot0/")
 (racket--rkt-source-dir "/usr/share/emacs/site-lisp/elpa/racket-mode-20230425snapshot0/racket/")
 (racket-program "racket")
 (racket-command-timeout 10)
 (racket-path-from-emacs-to-racket-function UNDEFINED)
 (racket-path-from-racket-to-emacs-function UNDEFINED)
 (racket-browse-url-function racket-browse-url-using-temporary-file)
 (racket-documentation-search-location "https://docs.racket-lang.org/search/index.html?q=%s")
 (racket-xp-after-change-refresh-delay 1)
 (racket-xp-mode-lighter
  (:eval
   (racket--xp-mode-lighter)))
 (racket-xp-highlight-unused-regexp "^[^_]")
 (racket-repl-buffer-name-function nil)
 (racket-submodules-to-run
  ((test)
   (main)))
 (racket-memory-limit 2048)
 (racket-error-context medium)
 (racket-repl-history-directory "~/.emacs.d/racket-mode/")
 (racket-history-filter-regexp "\\`\\s *\\'")
 (racket-images-inline t)
 (racket-imagemagick-props nil)
 (racket-images-keep-last 100)
 (racket-images-system-viewer "display")
 (racket-pretty-print t)
 (racket-use-repl-submit-predicate nil)
 (racket-pretty-print t)
 (racket-indent-curly-as-sequence t)
 (racket-indent-sequence-depth 0)
 (racket-pretty-lambda nil)
 (racket-smart-open-bracket-enable nil)
 (racket-module-forms "\\s(\\(?:module[*+]?\\|library\\)")
 (racket-logger-config
  ((cm-accomplice . warning)
   (GC . info)
   (module-prefetch . warning)
   (optimizer . info)
   (racket/contract . error)
   (racket-mode-debugger . info)
   (sequence-specialization . info)
   (* . fatal)))
 (racket-show-functions
  (racket-show-pseudo-tooltip)))
(enabled-minor-modes
 (auto-composition-mode)
 (auto-compression-mode)
 (auto-encryption-mode)
 (auto-fill-mode)
 (auto-save-mode)
 (blink-cursor-mode)
 (electric-indent-mode)
 (file-name-shadow-mode)
 (font-lock-mode)
 (global-eldoc-mode)
 (global-font-lock-mode)
 (hs-minor-mode)
 (line-number-mode)
 (menu-bar-mode)
 (mouse-wheel-mode)
 (semantic-minor-modes-format)
 (shell-dirtrack-mode)
 (show-paren-mode)
 (tooltip-mode)
 (transient-mark-mode))
(disabled-minor-modes
 (abbrev-mode)
 (auto-fill-function)
 (auto-save-visited-mode)
 (buffer-face-mode)
 (buffer-read-only)
 (button-mode)
 (cl-old-struct-compat-mode)
 (column-number-mode)
 (compilation-minor-mode)
 (compilation-shell-minor-mode)
 (completion-in-region-mode)
 (context-menu-mode)
 (defining-kbd-macro)
 (eldoc-mode)
 (electric-layout-mode)
 (electric-quote-mode)
 (global-prettify-symbols-mode)
 (global-semantic-highlight-edits-mode)
 (global-semantic-highlight-func-mode)
 (global-semantic-show-parser-state-mode)
 (global-semantic-show-unmatched-syntax-mode)
 (global-semantic-stickyfunc-mode)
 (global-visual-line-mode)
 (horizontal-scroll-bar-mode)
 (indent-tabs-mode)
 (isearch-mode)
 (jit-lock-debug-mode)
 (lock-file-mode)
 (next-error-follow-minor-mode)
 (overwrite-mode)
 (paragraph-indent-minor-mode)
 (prettify-symbols-mode)
 (racket-smart-open-bracket-mode)
 (racket-xp-mode)
 (semantic-highlight-edits-mode)
 (semantic-highlight-func-mode)
 (semantic-mode)
 (semantic-show-parser-state-mode)
 (semantic-show-unmatched-syntax-mode)
 (semantic-stickyfunc-mode)
 (sh-electric-here-document-mode)
 (size-indication-mode)
 (tab-bar-history-mode)
 (tab-bar-mode)
 (temp-buffer-resize-mode)
 (text-scale-mode)
 (tool-bar-mode)
 (unify-8859-on-decoding-mode)
 (unify-8859-on-encoding-mode)
 (url-handler-mode)
 (use-hard-newlines)
 (view-mode)
 (visible-mode)
 (visual-line-mode)
 (window-divider-mode)
 (xref-etags-mode))

[greghendershott]

racket-tests.el already checks for a CI environment variable being defined (value doesn't matter, e.g. CI=1); this seems to be a convention in circles like Travis CI, GitHub Actions, and more. In that case all the test timeouts are 30 seconds instead of 10.

(defconst ci-p (getenv "CI")
  "Is there an environment variable saying we're running on CI?")

(defconst racket-tests/timeout (if ci-p 30 10))

I don't know what control you have over how the tests are run in the Debian test environment.

• Can you arrange for a CI env var to be defined there?
• If not, can you define it for the make invocation, e.g. CI=1 make test?
• Other similar technique?

If nothing like that works, let me know.

[greghendershott]

p.s. Whether for Emacs or Racket, I find timing tests to be useful. They can help catch well-meaning changes that have bad performance surprises (usually my own, but sometimes PRs from other folks). Changes to stuff like parsers and indenters are good candidates.

But timing tests are certainly tricky in arbitrary test environments, including your case, the Racket build server, or other CI hosts like GitHub Actions.

I feel like there must be some smart way to do this, that someone has already figured out.

---

Hand waving: You know how time reports both "real time" and "CPU time"? Maybe if these tests could somehow work in terms of the latter, it would avoid some of these problems? (Assuming the problem arises when a test server or hypervisor is heavily loaded... as opposed to being just simply very old/slow hardware, which I guess could sometimes also be the case.)

[greghendershott]

Oh as is often the case I am an idiot. You are talking not about how all tests eventually timeout, you're talking about the tests using racket-tests/indent-time to measure indent speed --- the sort of intentional timing test I was talking about. I could probably do the sort of thing I was also talking about, i.e. change this to work in terms of CPU time instead of real time. It looks like Emacs has get-internal-run-time, which is supposed to do that.

So:

1. I should think more before I start typing.
2. I'll look at changing this.

[greghendershott]

To follow-up:

1. What I originally said about the CI environment variable was actually relevant. When that's defined, the indent speed tests will run, so the messages about the timings display in the test logs, but failures will be ignored:

(ert-deftest racket-tests/indent-speed-1 ()
  (should (or (< (racket-tests/indent-time "example/class-internal.rkt") 10)
              ci-p)))

(ert-deftest racket-tests/indent-speed-2 ()
  (should (or (< (racket-tests/indent-time "example/core.scm") 10)
              ci-p)))

So if you have a way to define the CI environment variable, that should solve the specific problem you raised --- as well as cause all the other tests to avoid timing out after 10 seconds, instead they get 30.

2. The following change ought to cause the two indent speed tests to work in terms of CPU not real time:

modified   test/racket-tests.el
@@ -677,13 +677,17 @@ want to use the value of `racket-program' at run time."
 ;; call `racket-indent-line' for every one of the thousands of lines
 ;; in these files. The huge example files are just a convenient way to
 ;; get a large, varied amount of test data.
+;;
+;; Note that we use `get-internal-runtime' to get CPU time (not real
+;; time) in an effort to make the timing test work when run on CI/test
+;; systems that might be loaded with various tasks.

 (defun racket-tests/indent-time (file)
   (with-current-buffer (find-file (expand-file-name file racket-tests/here-dir))
     (racket-mode)
-    (let* ((start (float-time))
+    (let* ((start (float-time (get-internal-run-time)))
            (_ (racket-tests/indent-region))
-           (finish (float-time))
+           (finish (float-time (get-internal-run-time)))
            (dur (- finish start)))
       (message "indent %s took %s seconds" file dur)
       (revert-buffer t t t)

I'm not sure whether to commit this. I like the principle. But it might be moot if you're CI-env-ing this away in the first place.

Maybe I'll experiment with running this on e.g. GitHub Actions.

[bremner]

Greg Hendershott @.***> writes:

To follow-up:

1. What I originally said about the CI environment variable was actually relevant. When that's defined, the indent speed tests will run, so the messages about the timings display in the test logs, but failures will be ignored:

(ert-deftest racket-tests/indent-speed-1 ()
  (should (or (< (racket-tests/indent-time "example/class-internal.rkt") 10)
              ci-p)))

(ert-deftest racket-tests/indent-speed-2 ()
  (should (or (< (racket-tests/indent-time "example/core.scm") 10)
              ci-p)))

So if you have a way to define the CI environment variable, that should solve the specific problem you raised --- as well as cause all the other tests to avoid timing out after 10 seconds, instead they get 30.

Running (setenv "CI" "1") seems to work at least on a machine that I have shell access to (for Debian-specific tooling reasons it's easier to run elisp than add a shell wrapper). I will have to wait to see if it works on the CI hosts. One thing I did notice is that 30s might not be generous enough. I saw several tests taking 26s and 27s, so I could imagine still getting timeouts on some older hardware (or low resource virtual machines).

2. The following change ought to cause the two indent speed tests to work in terms of CPU not real time:

modified   test/racket-tests.el
@@ -677,13 +677,17 @@ want to use the value of `racket-program' at run time."
 ;; call `racket-indent-line' for every one of the thousands of lines
 ;; in these files. The huge example files are just a convenient way to
 ;; get a large, varied amount of test data.
+;;
+;; Note that we use `get-internal-runtime' to get CPU time (not real
+;; time) in an effort to make the timing test work when run on CI/test
+;; systems that might be loaded with various tasks.

 (defun racket-tests/indent-time (file)
   (with-current-buffer (find-file (expand-file-name file racket-tests/here-dir))
     (racket-mode)
-    (let* ((start (float-time))
+    (let* ((start (float-time (get-internal-run-time)))
            (_ (racket-tests/indent-region))
-           (finish (float-time))
+           (finish (float-time (get-internal-run-time)))
            (dur (- finish start)))
       (message "indent %s took %s seconds" file dur)
       (revert-buffer t t t)

I'm not sure whether to commit this. I like the principle. But it might be moot if you're CI-env-ing this away in the first place.

Probably I am setting the CI environment variable. Is there an easy way to see how much CPU time the tests are using now? I have a sneaking suspicion that the slower the machine, the closer CPU time matches wall time, but I have no hard data to back that.

d

[greghendershott]

I experimented with "real" vs. "CPU" times both locally and on GitHub Actions, and didn't see any meaningful difference.

Maybe someday I'll tilt at this windmill, more, but....

I pushed a commit that bumps the CI test timeout from 30 to 60 seconds, and just outright skips the indent timing tests there.

Assuming you can use the "CI" environment variable approach to get this behavior, merging that commit should close this issue. But of course let me know if you have any other problems or questions.

[greghendershott]

I think those changes are good, so I merged that commit, which auto-closed this issue.

However if you can't use the "CI" env var approach, or have any other questions/needs, of course feel free to re-open this!