Opened 9 years ago

Closed 9 years ago

#10040 closed enhancement (fixed)

Don't ask for verbose output from tar when installing packages

Reported by: mpatel Owned by: drkirkby
Priority: minor Milestone: sage-4.6.1
Component: build Keywords:
Cc: leif Merged in: sage-4.6.1.alpha1
Authors: Leif Leonhardy Reviewers: Mitesh Patel
Report Upstream: N/A Work issues:
Branch: Commit:
Dependencies: Stopgaps:

Description (last modified by leif)

The sage-spkg script runs tar with the v option to extract spkgs. This significantly increases the size of many installation logs. Not adding the option would make the logs easier to navigate and search for errors and warnings, too.

I think Leif Leonhardy proposed this, somewhere.

Attachments (2)

trac_10040-untar_non-verbosely_by_default-sage_scripts.patch (1.8 KB) - added by leif 9 years ago.
Apply to Sage scripts repository. Based on Sage 4.6.rc0pre1.
trac_10040-document_SAGE_SPKG_LIST_FILES-sage_library.patch (4.8 KB) - added by leif 9 years ago.
Apply to Sage library. Based on Sage 4.6.rc0pre1. (Updated version s.t. more people can read it.)

Download all attachments as: .zip

Change History (40)

comment:1 Changed 9 years ago by mpatel

Are there good reasons to keep the verbose non-error output?

Smaller logs would also help with #3524.

comment:2 follow-up: Changed 9 years ago by drkirkby

I think Leif said the verbose output could be useful to find packages which have unnecessary files in them. But personally I think that issue should be resolved when packages are reviewed. I've not objections to adding an environment variable to control it, but it's more work than a one-character patch!

As you say, it would also help with buildbot too.

Dave

comment:3 in reply to: ↑ 2 Changed 9 years ago by leif

  • Description modified (diff)

Replying to drkirkby:

I think Leif said the verbose output could be useful to find packages which have unnecessary files in them.

That was meant a joke. (I don't expect people to read the full, nearly 300,000-lines install.log, but incidentally noticed the mentioned obsolete SageNB files when watching the build process.)

But personally I think that issue should be resolved when packages are reviewed.

Of course. Unfortunately it's unlikely people look into the Mercurial repository for deleted files. (Ok, you can see them when verbosely unpacking an spkg manually, or do du -sh on the spkg's directory, which a reviewer should perhaps also do.)

I've not objections to adding an environment variable to control it, but it's more work than a one-character patch!

Obviously, but shouldn't carry much more of a danger.

comment:4 follow-up: Changed 9 years ago by leif

Perhaps (on another ticket) we should also address the almost useless "copying ..." messages that afaik originate from distutils. These make up another fair amount of the logs.

comment:5 follow-up: Changed 9 years ago by drkirkby

Are you two happy with just removing the 'v', and not bothering with an environment variable? I certainly am. If so, let's create a patch.

Anything to cut down the log size is a good thing, so feel free to create a ticket for this other issue.

Dave

Changed 9 years ago by leif

Apply to Sage scripts repository. Based on Sage 4.6.rc0pre1.

comment:6 Changed 9 years ago by leif

  • Authors set to Leif Leonhardy
  • Status changed from new to needs_review

I've attached a patch to sage-spkg that honors SAGE_SPKG_LIST_FILES=yes, and calls tar without "v" otherwise.

comment:7 Changed 9 years ago by leif

Btw, #9799 is also related (in case of build errors), since without that running make will also attempt to build the documentation regardless if the build succeeded or not, and obscure (and unnecessarily grow) the log or even "hide" the build error.

(Build errors do not always cause failures in building the documentation, so it might look as if the whole build succeeded, which probably William meant by "leading to all kinds of confusion".)

comment:8 in reply to: ↑ 4 Changed 9 years ago by leif

Replying to leif:

Perhaps (on another ticket) we should also address the almost useless "copying ..." messages that afaik originate from distutils. These make up another fair amount of the logs.

leif@quadriga:~/Sage/sage-4.6.rc0pre1$ grep "^copying" install.log | wc -lc
  65512 11147892

(That's more than 34% of the log file size.)

Maybe it's setuptools, not distutils; I don't know yet.

comment:9 Changed 9 years ago by leif

  • Owner changed from GeorgSWeber to leif

More detailed:

leif@quadriga:~/Sage/sage-4.6.rc0pre1$ grep -c "^copying" spkg/logs/* | awk 'BEGIN { FS=":" } { if ($2!=0) printf "%5d  %s\n", $2, $1 }' | sort -rn
43543  spkg/logs/moin-1.9.1.p1.log
 8419  spkg/logs/sagenb-0.8.7.log
 2702  spkg/logs/sage-4.6.rc0pre1.log
 2142  spkg/logs/matplotlib-1.0.0.log
 1797  spkg/logs/twisted-9.0.p2.log
 1096  spkg/logs/scipy-0.7.p5.log
  773  spkg/logs/sympy-0.6.4.p0.log
  661  spkg/logs/ipython-0.9.1.p0.log
  620  spkg/logs/numpy-1.3.0.p4.log
  429  spkg/logs/zodb3-3.7.0.p4.log
  388  spkg/logs/mercurial-1.3.1.p2.log
  367  spkg/logs/scons-1.2.0.log
  363  spkg/logs/networkx-1.2.p1.log
  349  spkg/logs/cython-0.13.p1.log
  307  spkg/logs/sphinx-0.6.3.p4.log
  292  spkg/logs/weave-0.4.9.p0.log
  260  spkg/logs/docutils-0.5.p0.log
  183  spkg/logs/pycrypto-2.1.0.log
  169  spkg/logs/pil-1.1.6.p2.log
  157  spkg/logs/sqlalchemy-0.5.8.log
  154  spkg/logs/mpmath-0.15.log
  122  spkg/logs/pygments-0.11.1.p0.log
   76  spkg/logs/setuptools-0.6c9.p0.log
   69  spkg/logs/python-2.6.4.p9.log
   68  spkg/logs/rpy2-2.0.8.log
   68  spkg/logs/r-2.10.1.p4.log
   65  spkg/logs/jinja2-2.1.1.p0.log
   27  spkg/logs/python_gnutls-1.1.4.p7.log
   22  spkg/logs/scipy_sandbox-20071020.p7.log
   21  spkg/logs/cvxopt-0.9.p9.log
   15  spkg/logs/sagetex-2.2.5.log
    3  spkg/logs/gdmodule-0.56.p7.log
    2  spkg/logs/pexpect-2.0.p4.log
    1  spkg/logs/gsl-1.14.log

So it's perhaps more worth addressing that in those spkgs that produce a huge number of such lines. There's a "verbose" option to distutils' setup() which is enabled by default (and also a "quiet" one), but I think we only want to suppress the verbose copying, so we'd have to configure just that command.

comment:10 follow-up: Changed 9 years ago by leif

Oh, the "copying ..." messages appear to be a distutils bug; distutils.file_util.copy_file() has a verbose (default: 0) parameter, but doesn't use it!

If I change it to the following:

    ...
    if verbose: # added just this line
        if os.path.basename(dst) == os.path.basename(src):
            log.info("%s %s -> %s", action, src, dir)
        else:
            log.info("%s %s -> %s", action, src, dst)
    ...

the "copying ..." messages vanish at least for mpmath (I only tried that so far).

Opinions? (before I open a ticket for that)

comment:11 in reply to: ↑ 10 Changed 9 years ago by leif

Replying to leif:

If I change it [...] the "copying ..." messages vanish at least for mpmath (I only tried that so far).

Also works for the record holders MoinMoin and SageNB...

comment:12 in reply to: ↑ 5 ; follow-up: Changed 9 years ago by jhpalmieri

Replying to drkirkby:

Are you two happy with just removing the 'v', and not bothering with an environment variable? I certainly am. If so, let's create a patch.

Would it make sense to have a make target which produced verbose logs? Then you wouldn't have to explicitly set an environment variable. The same might go for parallel building, by the way.

comment:13 in reply to: ↑ 12 Changed 9 years ago by leif

Replying to jhpalmieri:

Would it make sense to have a make target which produced verbose logs? Then you wouldn't have to explicitly set an environment variable.

No problem to add such.

The same might go for parallel building, by the way.

Not a bad idea. I vaguely remember what I had in mind for the "global" log and parallel builds: Since our "deps" Makefile does nothing but call sage-spkg, we can move the logging (i.e. the use of pipestatus) there, just passing in addition the name(s) of the logfile(s) in the Make rules.

sage-spkg can then take control of what (and how much) to log where (depending on command line options and/or environment variables), e.g. not teeing but just redirecting the output of spkg-install to the logfile, and printing short messages to stdout on parallel builds.

comment:14 Changed 9 years ago by leif

OT: A target for building the documentation (at least some parts) in parallel would be nice, too.

(We'd have to split the meaning of "all", which isn't defined by/in sage-sage but devel/sage/doc/common/builder.py in the Makefile. I'm not sure if we need that buggy Python script at all btw, which finally does an equivalent of os.system("sphinx ...") rather than importing it to build the docs...)

comment:15 follow-up: Changed 9 years ago by drkirkby

This works fine for me on OpenSolaris, and I can't possibly see it would be platform dependent.

However, the meaning of SAGE_SPKG_LIST_FILES should be added to the installation guide, along with the other environment variables.

I think in many cases one might want to set SAGE_SPKG_LIST_FILES=yes when installing a particular package. i.e.

$  export SAGE_SPKG_LIST_FILES=yes
$ ./sage -f somepackage.spkg

or something like that. As such, I think SAGE_SPKG_LIST_FILES should be documented in the installation guide, which will need another patch.

comment:16 Changed 9 years ago by drkirkby

  • Status changed from needs_review to needs_work
  • Work issues set to Add a patch to document the new environment variable

comment:17 in reply to: ↑ 15 Changed 9 years ago by leif

  • Status changed from needs_work to needs_review
  • Work issues Add a patch to document the new environment variable deleted

Replying to drkirkby:

However, the meaning of SAGE_SPKG_LIST_FILES should be added to the installation guide, along with the other environment variables.

Done.

I think in many cases one might want to set SAGE_SPKG_LIST_FILES=yes when installing a particular package.

You previously said you were happy with just removing the "v"... ;-)


Though the installation guide really needs work (it is fairly out-dated), I've in addition only reformatted one paragraph to (less than) 80 columns and moved the description of CFLAG64 up s.t. it's now immediately below that of SAGE64, where it IMHO belongs.

comment:18 follow-up: Changed 9 years ago by drkirkby

  • Owner changed from leif to drkirkby

What does the s.t. standard for, in the sentence Since some spkgs contain a huge number of files s.t. the log files get very large and harder to search (and listing the contained ?

It's not obvious to me, so either I'm think or perhaps it wont be obvious to others too.

I agree the installation guide is outdated, but was keen it did not get even more outdated!

I was happy to just omit -v, but if we are going to have the option to configure it, we should document it. I would have been quite happy not to have the option myself.

Dave

comment:19 Changed 9 years ago by jhpalmieri

I think "s.t." stands for "such that". Maybe that sentence could be rephrased as

Since some spkgs contain a huge number of files, the log files can 
get very large and hard to search (and listing the contained files is
usually not very valuable), so this is turned off by default.

comment:20 in reply to: ↑ 18 ; follow-up: Changed 9 years ago by leif

Replying to drkirkby:

What does the s.t. standard for, in the sentence Since some spkgs contain a huge number of files s.t. the log files get very large and harder to search (and listing the contained ?

It does not mean "sine tempore" (nor "subject to")...

Of course I can change that.

I was happy to just omit -v, but if we are going to have the option to configure it, we should document it. I would have been quite happy not to have the option myself.

I rather consider that a "developer's back door", which I would document in the Developer's Guide (if at all). ;-)

Changed 9 years ago by leif

Apply to Sage library. Based on Sage 4.6.rc0pre1. (Updated version s.t. more people can read it.)

comment:21 in reply to: ↑ 20 Changed 9 years ago by leif

Replying to leif:

Of course I can change that.

Reluctantly did that.

comment:22 Changed 9 years ago by leif

ping (before it rottens) ;-)

I'm working on a lot of further changes to (not only) sage-spkg...

comment:23 follow-up: Changed 9 years ago by mpatel

  • Milestone set to sage-4.6.1
  • Reviewers set to Mitesh Patel
  • Status changed from needs_review to positive_review

Suppressing the copying... messages sounds good to me. Should we have an option to enable them?

Should we use suppress "tarbosity" in sage-bdist, too?

comment:24 in reply to: ↑ 23 ; follow-up: Changed 9 years ago by leif

Replying to mpatel:

Suppressing the copying... messages sounds good to me. Should we have an option to enable them?

I have a patched Python package here that currently only adds the if verbose:.

Unfortunately, setting distutils.log's verbosity level (before calling setup()) seems to not work for some reason. It's not clear what the verbose parameter is supposed to change, and apparently it isn't [always] passed to copy_file().

There's always DISTUTILS_DEBUG btw. ;-)

We could make use of Sage environment variables (e.g. SAGE_DEBUG_BUILD, or SAGE_DISTUTILS_VERBOSITY_LEVEL) directly there, enabling more output. But I think keeping the other messages of the same verbosity level (like "creating ..." etc.) is ok, I'm not sure about "moving ..." of which we also have a lot, but by far not that many.

Did I already tell the install.log size drops to less than the half with non-verbose untarring and "copying" messages suppressed? (Also quite significantly depends on the length of $SAGE_ROOT...)

Should we use suppress "tarbosity" in sage-bdist, too?

Less important, at least to me.

comment:25 in reply to: ↑ 24 Changed 9 years ago by leif

Replying to leif:

Did I already tell the install.log size drops to less than the half with non-verbose untarring and "copying" messages suppressed? (Also quite significantly depends on the length of $SAGE_ROOT...)

$ wc -lc sage-4.6.rc0/install.log-rc0-orig sage-4.6.rc0-short-logs/install.log-rc0-short-logs 
  299773 31880226 sage-4.6.rc0/install.log-rc0-orig
  122924 15222503 sage-4.6.rc0-short-logs/install.log-rc0-short-logs
  422697 47102729 total
$ expr 15222503 - 11 \* `grep -c -- -short-logs sage-4.6.rc0-short-logs/install.log-rc0-short-logs`
14771536
$ echo "Total bytes saved: `expr 31880226 - 14771536`"
Total bytes saved: 17108690

(The above computation does not even take into account multiple occurrences of $SAGE_ROOT on a single line, which is also frequently the case, so we save more than 53.7%. :) )

comment:26 follow-ups: Changed 9 years ago by jdemeyer

Have you considered simply remove the v option to tar without environment variables? I don't really like adding another (pointless) environment variable.

comment:27 in reply to: ↑ 26 Changed 9 years ago by leif

Replying to jdemeyer:

Have you considered simply remove the v option to tar without environment variables? I don't really like adding another (pointless) environment variable.

See comments above. It's always good to have a "back door", the others then wanted me to officially document it. (And Mitesh recently asked if I could provide some way to reenable the useless "copying ..." messages from distutils if I suppress them.)

I don't mind having dozens of environment variables that nobody uses, at least as far as their names do not pollute the environment. (And they're much easier to implement than command line options.) There are enough scripts that export(!) variables like OPT etc., often despite being only locally used. The package name variables set in spkg/install, used in deps, are bad enough.

But IMHO the opposite is the case: We have too many useful variables (some undocumented), many with odd names like SAGE64 (which always reminds me of F77, Window95 etc.).

comment:28 in reply to: ↑ 26 ; follow-up: Changed 9 years ago by drkirkby

Replying to jdemeyer:

Have you considered simply remove the v option to tar without environment variables? I don't really like adding another (pointless) environment variable.

As you will see above, my suggestion was to just remove the 'v' and leave it there.

But I admit being able to change this does have some small benefit, and since it's now working, I think it's best left as it is. It can do no harm, and its documented properly.

Dave

comment:29 follow-ups: Changed 9 years ago by jdemeyer

I get the following error which might be caused by this patch:

[...]
sage_scripts-4.6.1.alpha1/spkg-install
sage_scripts-4.6.1.alpha1/sage-rebase_sage.sh
sage_scripts-4.6.1.alpha1/sage-sbuildhack
sage_scripts-4.6.1.alpha1/sage-grep
sage_scripts-4.6.1.alpha1/ipy_profile_sage.py
sage_scripts-4.6.1.alpha1/sage-ipython
Finished extraction
****************************************************
Host system
uname -a:
Linux boxen 2.6.24-24-server #1 SMP Fri Sep 18 16:47:05 UTC 2009 x86_64 GNU/Linux
****************************************************
****************************************************
CC Version
gcc -v
Using built-in specs.
Target: x86_64-linux-gnu
Configured with: ../src/configure -v --enable-languages=c,c++,fortran,objc,obj-c++,treelang --prefix=/usr --enable-shared --with-system-zlib --libexecdir=/usr/lib --without-included-gettext --enable-threads=posix --enable-nls --with-gxx-include-dir=/usr/include/c++/4.2 --program-suffix=-4.2 --enable-clocale=gnu --enable-libstdcxx-debug --enable-objc-gc --enable-mpfr --enable-checking=release --build=x86_64-linux-gnu --host=x86_64-linux-gnu --target=x86_64-linux-gnu
Thread model: posix
gcc version 4.2.4 (Ubuntu 4.2.4-1ubuntu4)
****************************************************
cp: cannot stat `/scratch/jdemeyer/merger/sage-4.6.1.alpha1/sage-python': No such file or directory
cp: cannot stat `/scratch/jdemeyer/merger/sage-4.6.1.alpha1/ipython': No such file or directory

real	0m0.075s
user	0m0.000s
sys	0m0.060s
/scratch/jdemeyer/merger/sage-4.6.1.alpha1/local/bin/sage-spkg: line 426: syntax error near unexpected token `('
/scratch/jdemeyer/merger/sage-4.6.1.alpha1/local/bin/sage-spkg: line 426: `    echo "(cd '`pwd`' && '$SAGE_ROOT/sage' -sh)"'
make[1]: *** [installed/sage_scripts-4.6.1.alpha1] Error 2
make[1]: Leaving directory `/padic/scratch/jdemeyer/merger/sage-4.6.1.alpha1/spkg'

comment:30 in reply to: ↑ 29 Changed 9 years ago by leif

Replying to jdemeyer:

I get the following error which might be caused by this patch:

How that? I see no relation to my patch, looks rather like the spkg-install does something weird, possibly corrupting (the running) sage-spkg?

comment:31 in reply to: ↑ 28 ; follow-ups: Changed 9 years ago by leif

Replying to drkirkby:

I think it's best left as it is. It can do no harm, and its documented properly.

We need a special section for useless (or rarely used) variables, I think in the Developer's rather than the Installation Guide.

comment:32 in reply to: ↑ 31 Changed 9 years ago by leif

Replying to leif:

Replying to drkirkby:

I think it's best left as it is. It can do no harm, and its documented properly.

We need a special section for useless (or rarely used) variables, I think in the Developer's rather than the Installation Guide.

Like PIL_NOTK (I always read "Pill not K", like the famous nchoosek.)

comment:33 in reply to: ↑ 31 Changed 9 years ago by drkirkby

Replying to leif:

We need a special section for useless (or rarely used) variables, I think in the Developer's rather than the Installation Guide.

Yes, perhaps some of these rarely used once should be in a section of their own. But that can be the subject of another ticket, and would not doubt need a lot of discussion about what is rarely used, what should be used more often.

IMHO, this ticket has positive review and should be merged unchanged.

comment:34 in reply to: ↑ 29 ; follow-ups: Changed 9 years ago by jhpalmieri

Replying to jdemeyer:

I get the following error which might be caused by this patch:

Yes and no. I think it was caused by the patch, but because you made a small mistake in applying the patch: when patching the script sage-spkg for testing purposes, you need to apply the patch, but then also copy the new version of sage-spkg to SAGE_ROOT/spkg/base. (Or apply the patch and then run "sage -sdist" and build the new version from scratch.) Otherwise, if the files SAGE_ROOT/spkg/base/sage-spkg and sage-spkg in the sage_scripts spkg don't match, at some point one of them overwrites the other while it is being executed, and the shell gets confused.

At least, that's my guess about what happened.

comment:35 in reply to: ↑ 34 Changed 9 years ago by jdemeyer

Replying to jhpalmieri:

Yes and no. I think it was caused by the patch, but because you made a small mistake in applying the patch: when patching the script sage-spkg for testing purposes, you need to apply the patch, but then also copy the new version of sage-spkg to SAGE_ROOT/spkg/base. (Or apply the patch and then run "sage -sdist" and build the new version from scratch.) Otherwise, if the files SAGE_ROOT/spkg/base/sage-spkg and sage-spkg in the sage_scripts spkg don't match, at some point one of them overwrites the other while it is being executed, and the shell gets confused.

That seems to be a likely explanation, I will test later. I suppose the same holds for sage-env and sage-make_relative, which are also in spkg/base?

comment:36 in reply to: ↑ 34 ; follow-up: Changed 9 years ago by jdemeyer

Replying to jhpalmieri:

Yes and no. I think it was caused by the patch, but because you made a small mistake in applying the patch: when patching the script sage-spkg for testing purposes, you need to apply the patch, but then also copy the new version of sage-spkg to SAGE_ROOT/spkg/base.

Thanks a lot for the tip, that's precisely what happened.

comment:37 in reply to: ↑ 36 Changed 9 years ago by jhpalmieri

Replying to jdemeyer:

Thanks a lot for the tip, that's precisely what happened.

Well, the same thing happened to me a few days ago, so it was an educated guess.

comment:38 Changed 9 years ago by jdemeyer

  • Merged in set to sage-4.6.1.alpha1
  • Resolution set to fixed
  • Status changed from positive_review to closed
Note: See TracTickets for help on using tickets.