support for 'eb --trace' (REVIEW) by boegel · Pull Request #2285 · easybuilders/easybuild-framework

boegel · 2017-08-16T11:57:13Z

add --trace/-T command line option
trace messages in various steps executed by easyblock.py
trace messages for executed commands
discriminate between build & runtime deps in trace output
generate per-command output logs in temporary directory under --trace
require --experimental for --trace for now...
add test for --trace
update docs (see add documentation on 'eb --trace' easybuild#372)

…ns are set up

boegel · 2017-08-16T11:57:51Z

Example output in current state:

$ eb zlib-1.2.11-GCCcore-7.1.0.eb -df --trace
== temporary log file in case of crash /tmp/eb-0CIbCt/easybuild-AxH89P.log
== processing EasyBuild easyconfig /vscmnt/gent_vulpix/_/user/data/gent/gvo000/gvo00002/vsc40023/zlib-1.2.11-GCCcore-7.1.0.eb
== building and installing zlib/1.2.11-GCCcore-7.1.0...
  >> installation prefix: /user/home/gent/vsc400/vsc40023/eb_phanpyscratch/CO7/sandybridge/software/zlib/1.2.11-GCCcore-7.1.0
== fetching files...
  >> sources:
  >> /user/data/gent/vsc400/vsc40023/EasyBuild/sources/z/zlib/zlib-1.2.11.tar.gz [SHA256: c3e5e9fdd5004dcb542feda5ee4f0ff0744628baf8ed2dd5d66f8ca1197cb1a1]
== creating build dir, resetting environment...
  >> build dir: /tmp/vsc40023/easybuild_build/zlib/1.2.11/GCCcore-7.1.0
== unpacking...
  >> running command 'tar xzf /user/data/gent/vsc400/vsc40023/EasyBuild/sources/z/zlib/zlib-1.2.11.tar.gz'...
== patching...
== preparing...
  >> loading toolchain module: GCCcore/7.1.0
  >> loading modules for dependencies:
  >>  * binutils/2.28
  >> defining build environment for GCCcore/7.1.0 toolchain
== configuring...
  >> running command './configure --prefix=/user/home/gent/vsc400/vsc40023/eb_phanpyscratch/CO7/sandybridge/software/zlib/1.2.11-GCCcore-7.1.0'...
== building...
  >> running command 'make -j 16'...
== testing...
== installing...
  >> running command 'make install'...
== taking care of extensions...
== postprocessing...
== sanity checking...
  >> file 'include/zconf.h' found: OK
  >> file 'include/zlib.h' found: OK
  >> file 'lib/libz.a' found: OK
  >> file 'lib/libz.so' found: OK
== cleaning up...
== creating module...
  >> generating module file @ /user/home/gent/vsc400/vsc40023/eb_phanpyscratch/CO7/sandybridge/modules/all/zlib/1.2.11-GCCcore-7.1.0.lua...
== permissions...
== packaging...
== COMPLETED: Installation ended successfully
== Results of the build can be found in the log file(s) /user/home/gent/vsc400/vsc40023/eb_phanpyscratch/CO7/sandybridge/software/zlib/1.2.11-GCCcore-7.1.0/easybuild/easybuild-zlib-1.2.11-20170811.213253.log
== Build succeeded for 1 out of 1
== Temporary log file(s) /tmp/eb-0CIbCt/easybuild-AxH89P.log* have been removed.

…g to check value for 'trace' build option all the time

…ace + add more tests for run_cmd & run_cmd_qa

boegel · 2017-09-06T06:42:57Z

Example output with current implementation:

$ eb HDF5-1.10.1-intel-2017a.eb -df --trace --experimental
== temporary log file in case of crash /tmp/eb-ieEeg3/easybuild-Ouw3jV.log
== processing EasyBuild easyconfig /user/data/gent/vsc400/vsc40023/easybuild_easy_installed/lib/python2.7/site-packages/easybuild_easyconfigs-3.4.0.dev0-py2.7.egg/easybuild/easyconfigs/h/HDF5/HDF5-1.10.1-intel-2017a.eb
== building and installing HDF5/1.10.1-intel-2017a...
  >> installation prefix: /user/home/gent/vsc400/vsc40023/eb_phanpyscratch/CO7/haswell-ib/software/HDF5/1.10.1-intel-2017a
== fetching files...
  >> sources:
  >> /user/data/gent/vsc400/vsc40023/EasyBuild/sources/h/HDF5/hdf5-1.10.1.tar.gz [SHA256: 048a9d149fb99aaa1680a712963f5a78e9c43b588d0e79d55e06760ec377c172]
== creating build dir, resetting environment...
  >> build dir: /tmp/vsc40023/easybuild_build/HDF5/1.10.1/intel-2017a
== unpacking...
  >> running command 'tar xzf /user/data/gent/vsc400/vsc40023/EasyBuild/sources/h/HDF5/hdf5-1.10.1.tar.gz' (output in /tmp/eb-ieEeg3/easybuild-run_cmd-P9kf6c.log)... [started at: 2017-09-06 08:28:42]
== patching...
== preparing...
  >> loading toolchain module: intel/2017a
  >> (no build dependencies specified)
  >> loading modules for (runtime) dependencies:
  >>  * zlib/1.2.11-GCCcore-6.3.0
  >>  * Szip/2.1-intel-2017a
  >> defining build environment for intel/2017a toolchain
== configuring...
  >> running command './configure --prefix=/user/home/gent/vsc400/vsc40023/eb_phanpyscratch/CO7/haswell-ib/software/HDF5/1.10.1-intel-2017a  --with-szlib=/user/home/gent/vsc400/vsc40023/eb_phanpyscratch/CO7/haswell-ib/software/Szip/2.1-intel-2017a  --with-zlib=/user/home/gent/vsc400/vsc40023/eb_phanpyscratch/CO7/haswell-ib/software/zlib/1.2.11-GCCcore-6.3.0  --with-pic --with-pthread --enable-shared  --enable-cxx --enable-fortran FC="mpiifort"  --enable-unsupported --enable-parallel' (output in /tmp/eb-ieEeg3/easybuild-run_cmd-dPat3D.log)... [started at: 2017-09-06 08:28:44]
== building...
  >> running command 'make -j 24  CXXFLAGS="$CXXFLAGS -DMPICH_IGNORE_CXX_SEEK"  FC="mpiifort"' (output in /tmp/eb-ieEeg3/easybuild-run_cmd-25vKdK.log)... [started at: 2017-09-06 08:31:01]
== testing...
== installing...
  >> running command 'make install' (output in /tmp/eb-ieEeg3/easybuild-run_cmd-BepE8P.log)... [started at: 2017-09-06 08:34:09]
== taking care of extensions...
== postprocessing...
== sanity checking...
  >> file 'bin/h52gif' found: OK
  >> file 'bin/h5c++' found: OK
  >> file 'bin/h5copy' found: OK
  >> file 'bin/h5debug' found: OK
  >> file 'bin/h5diff' found: OK
  >> file 'bin/h5dump' found: OK
  >> file 'bin/h5import' found: OK
  >> file 'bin/h5jam' found: OK
  >> file 'bin/h5ls' found: OK
  >> file 'bin/h5mkgrp' found: OK
  >> file 'bin/h5perf_serial' found: OK
  >> file 'bin/h5redeploy' found: OK
  >> file 'bin/h5repack' found: OK
  >> file 'bin/h5repart' found: OK
  >> file 'bin/h5stat' found: OK
  >> file 'bin/h5unjam' found: OK
  >> file 'bin/gif2h5' found: OK
  >> file 'bin/h5perf' found: OK
  >> file 'bin/h5pcc' found: OK
  >> file 'bin/h5pfc' found: OK
  >> file 'bin/ph5diff' found: OK
  >> file 'lib/libhdf5.so' found: OK
  >> file 'lib/libhdf5_cpp.so' found: OK
  >> file 'lib/libhdf5_fortran.so' found: OK
  >> file 'lib/libhdf5_hl_cpp.so' found: OK
  >> file 'lib/libhdf5_hl.so' found: OK
  >> file 'lib/libhdf5hl_fortran.so' found: OK
  >> (non-empty) directory 'include' found: OK
== cleaning up...
== creating module...
  >> generating module file @ /user/home/gent/vsc400/vsc40023/eb_phanpyscratch/CO7/haswell-ib/modules/all/HDF5/1.10.1-intel-2017a.lua...
== permissions...
== packaging...
== COMPLETED: Installation ended successfully
== Results of the build can be found in the log file(s) /user/home/gent/vsc400/vsc40023/eb_phanpyscratch/CO7/haswell-ib/software/HDF5/1.10.1-intel-2017a/easybuild/easybuild-HDF5-1.10.1-20170906.083425.log, /user/home/gent/vsc400/vsc40023/eb_phanpyscratch/CO7/haswell-ib/software/HDF5/1.10.1-intel-2017a/easybuild/easybuild-HDF5-1.10.1-20170906.083425.log.1
== Build succeeded for 1 out of 1
== Temporary log file(s) /tmp/eb-ieEeg3/easybuild-Ouw3jV.log* have been removed.
== Temporary directory /tmp/eb-ieEeg3 has been removed.

wpoely86 · 2017-09-06T09:44:37Z


+        # trace output for sources & patches
+        if self.src:
+            trace_msg("sources:")


space behind sources:? (Same below)

a wait, it's a new line, please ignore.

wpoely86 · 2017-09-06T09:46:11Z

+    if build_option('trace'):
+        _log.experimental("Using --trace")
+        if timestamp:
+            message += " [started at: %s]" % datetime.now().strftime('%Y-%m-%d %H:%M:%S')


Don't your normally put the time first and then the message?

Yeah, I've tried both approaches, not happy with either (because of the >>). I'm open to suggestions.

I'm up for reformatting this, but we can do that later since --trace requires --experimental for now; I want to avoid this being blocked by a bike-shedding discussion and get it merged ASAP to be included in EB v3.4.0...

wpoely86 · 2017-09-06T09:47:01Z

        """
        for patch in self.patches:
            self.log.info("Applying patch %s" % patch['name'])
+            trace_msg("applying patch %s..." % patch['name'])


but here I would add a space after the dots.

Why, each call to trace_msg prints a separate line, what's the use of having a space after ... if it's followed by a \n?

I mean a seperate between the filename of the patch and the dots. Or why the dots at all?

OK, so before the dots. ;-)

But yeah, just dropping the dots makes sense, will change.

wpoely86 · 2017-09-06T09:47:58Z

                    self.log.warning("Sanity check: %s" % self.sanity_check_fail_msgs[-1])

+                cand_paths = ' or '.join(["'%s'" % x for x in xs])
+                trace_msg("%s %s found: %s" % (typ, cand_paths, ('FAILED', 'OK')[found]))


Don't you want to print here first a line what you're about to print?

that's done higher up, output looks like:

== sanity checking... >> file 'bin/h52gif' found: OK >> file 'bin/h5c++' found: OK

wpoely86 · 2017-09-06T09:48:37Z

            else:
                self.log.info("sanity check command %s ran successfully! (output: %s)" % (command, out))

+            trace_msg("running command '%s'... %s" % (command, ('FAILED', 'OK')[ec == 0]))


I wouldn't to this here. Put such a thing inside run_cmd.

I'm deliberately not using the standard trace message printed for run_cmd here because this is the sanity check; the output of the command doesn't matter here, just whether it exits with 0 (OK) or not (FAILED)

wpoely86 · 2017-09-06T09:58:02Z


 import easybuild.tools.toolchain
-from easybuild.tools.build_log import EasyBuildError, dry_run_msg
+from easybuild.tools.build_log import EasyBuildError, dry_run_msg 


Run pep8 to find these things?

Yeah, I should, but there's a lot of noise there too currently... Fixed, thx

wpoely86 · 2017-09-06T09:59:27Z

+                    for dep_mod in run_dep_mods:
+                        trace_msg(' * ' + dep_mod)
+                else:
+                    trace_msg("(no build dependencies specified)")


s/build/runtime/

boegel added 3 commits August 11, 2017 20:09

add support for --trace

f5bf839

trace executed commands, except those that are run before build optio…

7a955a7

…ns are set up

add useful trace output during installation procedure

47112dc

boegel added this to the 3.4.0 milestone Aug 16, 2017

boegel added 8 commits August 29, 2017 14:20

Merge branch 'develop' into trace

c323708

add timestamp in trace output for run_cmd

4629b77

fix tracing in run_cmd_qa

b253388

Merge branch 'develop' into trace

9765227

move trace_msg from tools.build_log to tools.utilities to avoid havin…

db30ba1

…g to check value for 'trace' build option all the time

discriminate between build & runtime deps in --trace output

5204aac

collect output of executed commands in temporary log files under --tr…

219f3d0

…ace + add more tests for run_cmd & run_cmd_qa

minor tweak to log.experimental message

25906c5

easybuilders deleted a comment from boegelbot Sep 4, 2017

require --experimental with --trace

27d09b8

boegel force-pushed the trace branch from f856a45 to 27d09b8 Compare September 4, 2017 19:51

fix broken tests

039e614

boegel force-pushed the trace branch from 84089dc to 039e614 Compare September 4, 2017 20:07

boegel added 2 commits September 4, 2017 22:21

add dedicated test for --trace

46ea015

fix typo

07f2548

easybuilders deleted a comment from boegelbot Sep 5, 2017

avoid hard check for Lua module file in test_toy_build_trace

9ebda84

easybuilders deleted a comment from boegelbot Sep 5, 2017

boegel changed the title ~~support for 'eb --trace' [WIP]~~ support for 'eb --trace' (REVIEW) Sep 5, 2017

boegel mentioned this pull request Sep 6, 2017

add documentation on 'eb --trace' easybuilders/easybuild#372

Merged

wpoely86 reviewed Sep 6, 2017

View reviewed changes

boegel added 2 commits September 6, 2017 18:52

fix minor remarks

75ba657

drop '...' in trace messages

95b3180

wpoely86 approved these changes Sep 6, 2017

View reviewed changes

wpoely86 merged commit e1ff518 into easybuilders:develop Sep 6, 2017

boegel deleted the trace branch September 6, 2017 19:15

boegel mentioned this pull request Sep 7, 2017

Rough indicators for remaining installation times #2297

Open

Conversation

boegel commented Aug 16, 2017 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

boegel commented Aug 16, 2017

Uh oh!

boegel commented Sep 6, 2017

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

boegel commented Aug 16, 2017 •

edited

Loading