Output test log path (optionally contents) post-install, include post-install times by tldahlgren · Pull Request #35315 · spack/spack

tldahlgren · 2023-02-03T03:55:47Z

(UPDATED) This PR provides more post-install test information:

prints the test log path IF a test failure occurs;
prints the contents of the test log IF -v option is passed to spack install; and
times and prints post-install operations (e.g., post-install tests).

For example, with -v --test=root for a package with a (fake) test failure:

$ spack install -v --test=root [email protected]
...
==> Installing py-libensemble-0.9.2-lr5qi7bfilbfm7ci5jvwno5kccjavc7d
==> No binary for py-libensemble-0.9.2-lr5qi7bfilbfm7ci5jvwno5kccjavc7d found: installing from source
==> Using cached archive: $spack/var/spack/cache/_source-cache/archive/e4/e46598e5696f770cbff4cb90507b52867faad5654f1b80de35405a95228c909f.tar.gz
==> No patches needed for py-libensemble
==> py-libensemble: Executing phase: 'install'
...
Successfully built libensemble
Installing collected packages: libensemble

Successfully installed libensemble-0.9.2
...
==> Testing package py-libensemble-0.9.2-lr5qi7b
==> [2023-02-24-16:08:32.534705] Running install-time tests
==> [2023-02-24-16:08:32.536319] Installing $/spack/opt/spack/linux-rhel7-broadwell/gcc-8.3.1/py-libensemble-0.9.2-lr5qi7bfilbfm7ci5jvwno5kccjavc7d/.spack/test to /var/tmp/dahlgren/spack-stage/spack-stage-py-libensemble-0.9.2-lr5qi7bfilbfm7ci5jvwno5kccjavc7d/py-libensemble-0.9.2-lr5qi7b/cache/py-libensemble
==> [2023-02-24-16:08:32.811530] RUN-TESTS: install-time tests [test]
==> [2023-02-24-16:08:32.876125] Detected the following modules: ['libensemble', 'libensemble.alloc_funcs', 'libensemble.comms', 'libensemble.executors', 'libensemble.executors.balsam_executors', 'libensemble.gen_funcs', 'libensemble.resources', 'libensemble.sim_funcs', 'libensemble.sim_funcs.branin', 'libensemble.tests', 'libensemble.tests.regression_tests', 'libensemble.tests.unit_tests', 'libensemble.tools', 'libensemble.utils']
==> [2023-02-24-16:08:32.877048] checking import of libensemble
==> [2023-02-24-16:08:32.877751] '/usr/tce/bin/python3.7' '-c' 'import libensemble'
PASSED
...
==> [2023-02-24-16:08:45.706608] test: run test_1d_sampling.py example
==> [2023-02-24-16:08:45.707351] '/usr/tce/bin/python3.7' 'test_1d_sampling.py' '--comms' 'local' '--nworkers' '2'

libEnsemble with random sampling has generated enough points
libensemble.tools.tools: ------------------ Run completed -------------------
Saving results to file: 1d_sampling_history_length=1000_evals=502_workers=2
PASSED
==> [2023-02-24-16:08:47.117321] test: fail
==> [2023-02-24-16:08:47.118023] '/usr/tce/bin/python3.7' '-c' 'raise RuntimeError("fail")'
Traceback (most recent call last):
  File "<string>", line 1, in <module>
RuntimeError: fail
FAILED: Command exited with status 1:
    '/usr/tce/bin/python3.7' '-c' 'raise RuntimeError("fail")'
Traceback (most recent call last):
  File "<string>", line 1, in <module>
RuntimeError: fail
...
  File "$spack/var/spack/repos/builtin/packages/py-libensemble/package.py", line 100, in test
    purpose="test: fail",
==> [2023-02-24-16:08:47.450596] Completed testing
==> Error: TestFailure: 1 tests failed.

Command exited with status 1:
    '/usr/tce/bin/python3.7' '-c' 'raise RuntimeError("fail")'
Traceback (most recent call last):
  File "<string>", line 1, in <module>
RuntimeError: fail

1 error found in test log:
...
See build log for details:
  $TMPDIR/spack-stage/spack-stage-py-libensemble-0.9.2-lr5qi7bfilbfm7ci5jvwno5kccjavc7d/spack-build-out.txt

See test log for details:
  $TMPDIR/spack-stage/spack-stage-py-libensemble-0.9.2-lr5qi7bfilbfm7ci5jvwno5kccjavc7d/install-time-test-log.txt

193.295u 23.579s 3:59.98 90.3%	0+0k 1816+6256io 1pf+0w

While running tests without -v for the same package results in:

$ spack install --test=root [email protected]
...
==> Installing py-libensemble-0.9.3-5prbuneeootut5fplscnx7mv2ews3xin
==> No binary for py-libensemble-0.9.3-5prbuneeootut5fplscnx7mv2ews3xin found: installing from source
==> Using cached archive: /usr/WS1/dahlgren/releases/spack/var/spack/cache/_source-cache/archive/00/00e5a65d6891feee6a686c048d8de72097b8bff164431f163be96ec130a9c390.tar.gz
==> No patches needed for py-libensemble
==> py-libensemble: Executing phase: 'install'
==> Error: TestFailure: 1 tests failed.

Command exited with status 1:
    '/usr/tce/bin/python3.7' '-c' 'raise RuntimeError("fail")'
Traceback (most recent call last):
  File "<string>", line 1, in <module>
RuntimeError: fail
...
See build log for details:
  /var/tmp/dahlgren/spack-stage/spack-stage-py-libensemble-0.9.3-5prbuneeootut5fplscnx7mv2ews3xin/spack-build-out.txt

See test log for details:
  /var/tmp/dahlgren/spack-stage/spack-stage-py-libensemble-0.9.3-5prbuneeootut5fplscnx7mv2ews3xin/install-time-test-log.txt

199.725u 30.088s 4:00.49 95.5%	0+0k 1024+5688io 0pf+0w

Note:

$ spack  -v test run [email protected]  # shows tests and, if a failure, log path
$ spack test run [email protected]  # does not show details or the log path

TODO

- [x] add/update unit tests

tldahlgren · 2023-02-22T19:49:16Z

@adamjstewart @alalazo Resolved conflicts. The patch coverage is reported at 100% and project coverage up +.13%. Also re-confirmed the example output shown in the description.

adamjstewart

Tested with py-six and works as expected! A few comments related to the output and when/where we print it. Also, the build output uses green for the ==>, but the test output uses no color. Probably simple to fix.

lib/spack/spack/installer.py

- added typing for _print_install_test_log arg(s); - added timing of post-install (to capture testing timing data); - changed to output test log path only on failures; and - colorized test log markers green. Also: - Added "Completed testing" log message for post-install tests; and - colorized test log messages.

adamjstewart · 2023-02-24T03:19:01Z

This is looking much better now. A few final things I noticed:

The install-time-test-log.txt file that gets installed is executable and prob shouldn't be
The font used for ==> during testing is bold, but the font used for ==> during build isn't

The test start/complete messages are printed twice:

==> Testing package py-six-1.15.0-6ev665z
==> [2023-02-23-21:12:48.859872] Running install-time tests
==> [2023-02-23-21:12:48.861115] RUN-TESTS: install-time tests [test]
==> [2023-02-23-21:12:48.911128] Completed testing
==> Testing package py-six-1.15.0-6ev665z
==> [2023-02-23-21:12:48.859872] Running install-time tests
==> [2023-02-23-21:12:48.861115] RUN-TESTS: install-time tests [test]
==> [2023-02-23-21:12:48.863071] Detected the following modules: ['six']
==> [2023-02-23-21:12:48.864000] checking import of six
==> [2023-02-23-21:12:48.864307] '/Users/Adam/spack/opt/spack/darwin-catalina-ivybridge/apple-clang-12.0.0/python-3.10.8-vtplktw577cpgtkbjew4bjbetrxjttbu/bin/python3.10' '-c' 'import six'
PASSED
==> [2023-02-23-21:12:48.911128] Completed testing

…test.

adamjstewart · 2023-02-25T19:18:27Z

With the latest commit, spack install -v --test=root no longer prints the test output.

tldahlgren · 2023-02-27T16:33:10Z

With the latest commit, spack install -v --test=root no longer prints the test output.

Can you try spack -v install --test=root? I will revisit getting the option passed the other way as well.

adamjstewart · 2023-02-27T20:33:11Z

Still didn't display the tests even with:

$ spack -v install -v --test=root py-six

tldahlgren · 2023-05-08T21:15:57Z

Closing this PR since the changes originated in #34236, which has refactoring that causes redundant work iterating on this and the other PR.

spackbot-app bot added the core PR affects Spack core functionality label Feb 3, 2023

tldahlgren force-pushed the print_test_log_path branch from 9d8c09d to 635a673 Compare February 7, 2023 01:52

spackbot-app bot added the tests General test capability(ies) label Feb 7, 2023

tldahlgren force-pushed the print_test_log_path branch from 0970708 to 6671331 Compare February 13, 2023 20:12

spackbot-app bot added new-version stand-alone-tests Stand-alone (or smoke) tests for installed packages commands labels Feb 13, 2023

tldahlgren requested review from adamjstewart and alalazo February 16, 2023 17:39

tldahlgren force-pushed the print_test_log_path branch from e28fcec to 7e83d46 Compare February 22, 2023 03:24

adamjstewart reviewed Feb 22, 2023

View reviewed changes

lib/spack/spack/installer.py Outdated Show resolved Hide resolved

lib/spack/spack/installer.py Outdated Show resolved Hide resolved

lib/spack/spack/installer.py Show resolved Hide resolved

adamjstewart self-assigned this Feb 22, 2023

tldahlgren added 4 commits February 23, 2023 14:40

Output test log path (optionally contents) post-install

784cc04

Add unit tests

6b985a0

Don't output the test log if the tests weren't run

b8a3f9d

tldahlgren force-pushed the print_test_log_path branch from 550f56e to c10eecb Compare February 23, 2023 22:40

tldahlgren changed the title ~~Output test log path (optionally contents) post-install~~ Output test log path (optionally contents) post-install, include post-install times Feb 24, 2023

tldahlgren added 2 commits February 24, 2023 14:19

Fix test log perms; log mark coloring; test output duplication; unit …

86f920f

…test.

Only show the test log path on failure

bcf74cd

spackbot-app bot added the build-environment label Feb 25, 2023

tldahlgren mentioned this pull request Apr 7, 2023

Stand-alone testing: Make recipe support and processing spack-/pytest-like #34236

Merged

tldahlgren closed this May 8, 2023

tldahlgren deleted the print_test_log_path branch August 27, 2024 01:17

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Output test log path (optionally contents) post-install, include post-install times#35315

Output test log path (optionally contents) post-install, include post-install times#35315
tldahlgren wants to merge 6 commits intospack:developfrom
tldahlgren:print_test_log_path

tldahlgren commented Feb 3, 2023 •

edited

Loading

Uh oh!

tldahlgren commented Feb 22, 2023

Uh oh!

adamjstewart left a comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

adamjstewart commented Feb 24, 2023

Uh oh!

adamjstewart commented Feb 25, 2023

Uh oh!

tldahlgren commented Feb 27, 2023

Uh oh!

adamjstewart commented Feb 27, 2023

Uh oh!

tldahlgren commented May 8, 2023

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

Conversation

tldahlgren commented Feb 3, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

tldahlgren commented Feb 22, 2023

Uh oh!

adamjstewart left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

adamjstewart commented Feb 24, 2023

Uh oh!

adamjstewart commented Feb 25, 2023

Uh oh!

tldahlgren commented Feb 27, 2023

Uh oh!

adamjstewart commented Feb 27, 2023

Uh oh!

tldahlgren commented May 8, 2023

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

tldahlgren commented Feb 3, 2023 •

edited

Loading