Opened 4 years ago

Closed 4 years ago

Last modified 4 years ago

#20884 closed defect (fixed)

line buffering in sage-logger causes "hang" due to invisible prompt when installing experimental packages

Reported by: mkoeppe Owned by:
Priority: blocker Milestone: sage-7.3
Component: build Keywords:
Cc: jdemeyer, embray, vbraun, kcrisman, dimpase, vdelecroix, novoselt Merged in:
Authors: Matthias Koeppe Reviewers: Leif Leonhardy, Volker Braun
Report Upstream: N/A Work issues:
Branch: 6888a67 (Commits) Commit:
Dependencies: Stopgaps:

Description

(Observed on Mac OS X.)

As I reported in http://trac.sagemath.org/ticket/20708#comment:8:

When installing an "experimental" package, Sage warns a lot and then prompts the user. Because of line buffering, one does not see the prompt, but Sage just waits indefinitely.

sage -f latte_int
...
[latte_int-1.7.3] =========================== WARNING ===========================
[latte_int-1.7.3] You are about to download and install an experimental package.
[latte_int-1.7.3] This probably won't work at all for you! There is no guarantee
[latte_int-1.7.3] that it will build correctly, or behave as expected.
[latte_int-1.7.3] Use at your own risk!
[latte_int-1.7.3] ===============================================================

<--- This is where it asks "[latte_int-1.7.3] Are you sure you want to continue [Y/n]?" but this is line-buffered and not visible to the user.

Change History (103)

comment:1 Changed 4 years ago by vbraun

IMHO we just shouldn't ask questions here, a (potentially) parallel make session is just not an interactive process. Either do it or bail out and require a command line switch --experimental to opt-in.

comment:2 Changed 4 years ago by mkoeppe

I think so too.

comment:3 Changed 4 years ago by embray

+1, just keep the message.

comment:4 Changed 4 years ago by kcrisman

I also think it's fine for experimental packages to just run and fail. As long as there isn't any potential to mess up the rest of Sage (like with messed up runs of make).

comment:5 Changed 4 years ago by embray

  • Authors set to Erik Bray
  • Branch set to u/embray/disable-exp-pkg-prompt
  • Commit set to ccff00540641c9a7b19166c550433b6d4495a5ba
  • Status changed from new to needs_review

Here's a patch to remove the prompt entirely.

Might be good to find a fix to the underlying problem, since in principle there could be some other prompt somewhere that would be hidden in the same way. I'm not sure how best to fix this though--would have to disable line-buffering on such prompts somehow.


New commits:

ccff005Disable the y/n prompt when installing experimental packages.

comment:6 Changed 4 years ago by mkoeppe

This would be fine with me. But it could be argued that this warning is too easy to overlook (and comes too late) and so the point of distinguishing between optional and experimental packages is lost.

comment:7 Changed 4 years ago by mkoeppe

  • Cc kcrisman added

comment:8 Changed 4 years ago by mkoeppe

  • Cc dimpase vdelecroix added

comment:9 Changed 4 years ago by novoselt

  • Cc novoselt added

comment:10 Changed 4 years ago by dimpase

I don't think simply removing this dialog is the right thing to do.

comment:11 Changed 4 years ago by dimpase

  • Status changed from needs_review to needs_work

comment:12 Changed 4 years ago by embray

This would be fine with me. But it could be argued that this warning is too easy to overlook (and comes too late) and so the point of distinguishing between optional and experimental packages is lost.

I'm not sure what you suggest differently, other than moving the warning a little earlier?

But if someone doesn't read their build output it will be lost on them anyways. That's okay, because it's "merely" a warning.

comment:13 follow-up: Changed 4 years ago by embray

Dima has a point that removing the prompt outright is potentially disruptive.

What if we moved the warning so that there's no prompt if running make <packagename> directly, as a package developer might do. But running ./sage -i for an experimental package both displays the warning and the prompt (before ever even running make, much less sage-logger).

comment:14 in reply to: ↑ 13 Changed 4 years ago by mkoeppe

Replying to embray:

Dima has a point that removing the prompt outright is potentially disruptive.

What if we moved the warning so that there's no prompt if running make <packagename> directly, as a package developer might do. But running ./sage -i for an experimental package both displays the warning and the prompt (before ever even running make, much less sage-logger).

I think ./sage -i PACKAGENAMES... should display the warning and the prompt before at the very beginning, before installing any package.

As per Volker's initial suggestion, a command-line switch --experimental should override the prompt. This would be useful in a script. I didn't know that make PACKAGENAME works; but in any case it would be better to be able to use "sage -i" also from a script.

comment:15 Changed 4 years ago by embray

make <packagename> is how all packages are built. sage -i is just a thin front-end over that.

It appears the warning/prompt comes from the sage-spkg (which is the program responsible for unpacking the package, running spkg-install, etc) which is in turn called by make.

I tried reworking this yesterday in a way that didn't change sage-spkg, but to make that prompt happen right away it would have to moved either into the makefile itself, or into the sage command, though I think it's good to have the warning when running sage-spkg too. So I'd hate to have duplicate copies of the warning.

In other words it's not exactly clear where the best place would be for it. Jeroen might have some ideas but he's on holiday right now so we won't bug him about it.

comment:16 Changed 4 years ago by git

  • Commit changed from ccff00540641c9a7b19166c550433b6d4495a5ba to 632fea7e3912f4769fa65413c62dbbaec098b613

Branch pushed to git repo; I updated commit sha1. New commits:

611480dNo matter what I do, even with sed --unbuffered, sed will read either up to the EOF or the EOL, but otherwise buffers until EOL.
632fea7Add a new -y argument to sage-spkg to make it automatically answer 'y' to all prompts.

comment:17 Changed 4 years ago by embray

Welp, this is definitely more complicated than it was before, but I think it's pretty good.

comment:18 Changed 4 years ago by embray

  • Status changed from needs_work to needs_review

comment:19 Changed 4 years ago by git

  • Commit changed from 632fea7e3912f4769fa65413c62dbbaec098b613 to 4f7b63f16b156891638b546427f4d9c7e66c7137

Branch pushed to git repo; I updated commit sha1. New commits:

4f7b63fDisplay an additional message when continuing automatically

comment:20 Changed 4 years ago by dimpase

  • Reviewers set to Dima Pasechnik, Matthias Koeppe
  • Status changed from needs_review to positive_review

looks good to me

comment:21 Changed 4 years ago by vbraun

  • Status changed from positive_review to needs_work

On OSX:

config.status: creating directory /Users/buildslave-sage/slave/sage_git/build/local/lib
config.status: creating directory /Users/buildslave-sage/slave/sage_git/build/local/share
config.status: creating directory /Users/buildslave-sage/slave/sage_git/build/local/var/lib/sage/installed
build/bin/sage-logger \
		"cd build/make && ./install 'start'" logs/install.log
build/bin/sage-logger: line 48: read: -N: invalid option
read: usage: read [-ers] [-u fd] [-t timeout] [-p prompt] [-a array] [-n nchars] [-d delim] [name ...]
make: *** [start] Error 141
program finished with exit code 2

comment:22 Changed 4 years ago by dimpase

oops... perhaps one can just replace -N with -n ?

comment:23 Changed 4 years ago by dimpase

With IFS unset, at least, -n appears to be equivalent to -N.

comment:24 Changed 4 years ago by embray

And here I thought by relying entirely on bash features this would be portable. Leave it to OSX to "think different"!

Mysteriously, on my bash -n is not quite the same as -N even with IFS unset. I think the key is that for -N it reads "Delimiter characters encountered in the input are not treated specially and do not cause read to return until nchars are read". So in other words, hitting "Enter" with -N 1 will cause read to return a newline literal. Whereas for -n the delimiter is still treated specially and is *not* returned. Hitting Enter causes read to return with no characters read. It should be made clear that here "delimiter" is referring to the delimiter that read should read up to, not the delimiter(s) used to split a line, which is what IFS is.

The solution is to use -n, but treat an empty string has having received a newline.

comment:25 Changed 4 years ago by git

  • Commit changed from 4f7b63f16b156891638b546427f4d9c7e66c7137 to bdcfff486256625b42541e505905e3a7d2e083e7

Branch pushed to git repo; I updated commit sha1. New commits:

bdcfff4Two fixes:

comment:26 Changed 4 years ago by embray

  • Status changed from needs_work to needs_review

comment:27 Changed 4 years ago by dimpase

the last commit did not make it into the branch! Never seen such a strange thing before...

comment:28 Changed 4 years ago by dimpase

  • Status changed from needs_review to needs_work

sorry, in fact there is still -N left in sage-logger, and I get on OSX

build/bin/sage-logger: line 48: read: -N: invalid option

comment:29 Changed 4 years ago by embray

Ah, right.

comment:30 Changed 4 years ago by git

  • Commit changed from bdcfff486256625b42541e505905e3a7d2e083e7 to 0fc8fde498193be273b22ec69e5e97a67caa0dc0

Branch pushed to git repo; I updated commit sha1. New commits:

0fc8fdeChange -N 1 to -n 1 in sage-logger, since the former does not work on

comment:31 Changed 4 years ago by embray

  • Status changed from needs_work to needs_review

Fixed sage-logger to not use read -N 1 as well.


New commits:

0fc8fdeChange -N 1 to -n 1 in sage-logger, since the former does not work on

comment:32 Changed 4 years ago by dimpase

  • Status changed from needs_review to positive_review

OK, this works on OSX.

comment:33 Changed 4 years ago by mkoeppe

Follow up: #20937

comment:34 Changed 4 years ago by vbraun

  • Status changed from positive_review to needs_work

I'm getting this failure

sage -t --long src/sage/tests/cmdline.py
**********************************************************************
File "src/sage/tests/cmdline.py", line 219, in sage.tests.cmdline.test_executable
Failed example:
    print(out)
Expected:
    Found local metadata for sqlite-...
    = SQLite =
    ...
    SQLite is a software library that implements a self-contained,
    serverless, zero-configuration, transactional SQL database engine.
    ...
Got:
    Found local metadata for sqliteautoconf3130000
    = SQLite =
    <BLANKLINE>
    == Description ==
    <BLANKLINE>
    SQLite is a software library that implements a selfcontained,
    serverless, zeroconfiguration, transactional SQL database engine.
    <BLANKLINE>
    == License ==
    <BLANKLINE>
    Public Domain
    <BLANKLINE>
    == Upstream contact ==
    <BLANKLINE>
     * http://www.sqlite.org
    <BLANKLINE>
    == Dependencies ==
    <BLANKLINE>
    * readline
    <BLANKLINE>
    == Special Update/Build Instructions ==
    <BLANKLINE>
    * Use the autoconf version of sqlite.
    <BLANKLINE>
**********************************************************************
1 item had failures:
   1 of 239 in sage.tests.cmdline.test_executable
    [238 tests, 1 failure, 142.30 s]

comment:35 Changed 4 years ago by dimpase

looks like a monster is eating up all - in there: in sqlite-autoconf3130000, in self-contained, in zero-configuration. So there is something wrong in the update of build/bin/sage-logger. (The problem is reproducible on Linux as well as on OSX).

Last edited 4 years ago by dimpase (previous) (diff)

comment:36 Changed 4 years ago by mkoeppe

Perhaps it's best to use a simple solution that doesn't try to be interactive...

comment:37 Changed 4 years ago by dimpase

indeed, - does not get echoed:

$ cat blah
oh-oh

$ while IFS= read -d'' -s -n 1 char; do echo -n "$char"; done <blah
ohoh

comment:38 Changed 4 years ago by embray

Fantastic. I'm this close to just rewriting this script in Python....

comment:39 Changed 4 years ago by embray

Incidentally, read -N 1 (as it was before) does not inexplicably eat -.

comment:40 follow-up: Changed 4 years ago by embray

This is so effing bizarre I had to ask about it on Stack Overflow: http://stackoverflow.com/questions/38199974/bash-read-mystery-read-d-s-n-1-eats-hyphens

I think it's a bug in bash, personally, or at least very ill-documented behavior. In the meantime I do have a work-around.

comment:41 Changed 4 years ago by git

  • Commit changed from 0fc8fde498193be273b22ec69e5e97a67caa0dc0 to 4ce1311c5eb580adc85ab95f596e85d13145847c

Branch pushed to git repo; I updated commit sha1. New commits:

4ce1311Don't use -d'' to read, since it mysteriously treats - as a delimiter.

comment:42 Changed 4 years ago by embray

  • Status changed from needs_work to needs_review

Fixed the issue with sage-logger eating hyphens.

comment:43 in reply to: ↑ 40 Changed 4 years ago by dimpase

  • Status changed from needs_review to needs_work

Replying to embray:

This is so effing bizarre I had to ask about it on Stack Overflow: http://stackoverflow.com/questions/38199974/bash-read-mystery-read-d-s-n-1-eats-hyphens

I think it's a bug in bash, personally, or at least very ill-documented behavior. In the meantime I do have a work-around.

The internet has solved your problem - you must have a space between -d and '' ! (so this must also be fixed in the other place where you use -d'' instead of -d '')

comment:44 follow-up: Changed 4 years ago by embray

Wow, I feel silly. But not too silly either--bash's behavior here is really quite silly IMO. But very nice.

I actually didn't use -d'' anywhere else--at least in the current version of this patch the -d flag is not used at all. But I'll still update the patch once more time to use this, since it will simplify things slightly.

comment:45 Changed 4 years ago by git

  • Commit changed from 4ce1311c5eb580adc85ab95f596e85d13145847c to 7a6f70c6cb3f7106109d61093fc07240e4a5bfe1

Branch pushed to git repo; I updated commit sha1. New commits:

7a6f70cNow that we know what the correct syntax is, went back to using `-d ''`

comment:46 Changed 4 years ago by embray

  • Status changed from needs_work to needs_review

comment:47 Changed 4 years ago by git

  • Commit changed from 7a6f70c6cb3f7106109d61093fc07240e4a5bfe1 to 705573623266f1017aa4a433e816c0e878960836

Branch pushed to git repo; I updated commit sha1. New commits:

7055736Replace one more example of echo -n with printf

comment:48 Changed 4 years ago by dimpase

  • Status changed from needs_review to positive_review

OK, good.

comment:49 in reply to: ↑ 44 Changed 4 years ago by leif

Replying to embray:

Wow, I feel silly. But not too silly either--bash's behavior here is really quite silly IMO. But very nice.

It's not silly, it's as documented. read -d'' -s ... is equivalent to read -d '-s' ... (where only the first character of the string argument '-s' is taken as the delimiter, as documented).

comment:50 Changed 4 years ago by leif

  • Status changed from positive_review to needs_work

That's clearly the wrong solution to the problem.

Did anyone even think of performance when replacing sed by a character-by-character shell loop (in addition with two conditionals in it)?

One should probably try this on a single-, maybe dual-core machine.


How about simply changing the scripts to output a newline when prompting the user for something, at least when the sage-logger is used?

comment:51 Changed 4 years ago by leif

I didn't want to wait for the latter to finish, but now it did:

$ time ./sage-logger-7.3.beta6 -p "cat logs/install.log" test-current.log >/dev/null

real    0m0.311s
user    0m0.170s
sys     0m0.160s
$ time ./sage-logger-20884 -p "cat logs/install.log" test-new.log >/dev/null

real    25m12.620s
user    24m20.680s
sys     0m51.900s

(Note that the comparison isn't even exactly fair, since sed had to output a longer prefix, and the second time, install.log was already in the filesystem cache. ;-) )

comment:52 follow-up: Changed 4 years ago by vbraun

  • Branch changed from u/embray/disable-exp-pkg-prompt to 705573623266f1017aa4a433e816c0e878960836
  • Resolution set to fixed
  • Status changed from needs_work to closed

comment:53 follow-up: Changed 4 years ago by embray

  • Commit 705573623266f1017aa4a433e816c0e878960836 deleted

How about simply changing the scripts to output a newline when prompting the user for something, at least when the sage-logger is used?

Those scripts don't necessarily have any way to know that sage-logger is being used, nor should they.

I think the test of just catting is not quite fair either. In a real build the overhead of the commands being run far outweighs the overhead of the logger. For example running make patch on current develop I got:

real    2m14.225s
user    0m29.614s
sys     1m2.397s

while on my branch:

real    2m18.844s
user    0m38.751s
sys     1m4.341s

So maybe possibly a little slower but hard to say from a single data point.

There's no need to emphasize shell loop since it's using only shell built-ins, or should be, so that shouldn't be a significant source of overhead. Ultimately sed is looping over one character at a time too. One thing that might speed this up a bit is to not printf for every character, but at least buffer that.

Still, point partly taken. I might prefer to go with my earlier instinct and just rewrite it in Python. I think using sed just to prepend to a line also feels like a blunt instrument.

Last edited 4 years ago by embray (previous) (diff)

comment:54 follow-up: Changed 4 years ago by embray

It's not silly, it's as documented. read -d -s ... is equivalent to read -d '-s' ... (where only the first character of the string argument '-s' is taken as the delimiter, as documented).

Just because it's as documented (which I see now, on very careful read, that the syntax must be -d<space><delimiter>). That's not *unreasonable*, just different from how other commands (specifically cut, which is why I was mentally comparing to) take their arguments. You can't well argue that the syntax of shell commands is always logical or consistent.

comment:55 Changed 4 years ago by embray

FWIW, I also tried running make patch with a version that doesn't add the prefix at all and the result from time was roughly the same there too. The point is that the overhead of adding the prefix, regardless how it's done, pales in comparison to the time to run most commands that produce output during the build.

comment:56 in reply to: ↑ 52 Changed 4 years ago by jhpalmieri

Volker, I don't understand why you merged this when it was labeled as "needs_work". At one point, yes, it was marked as "positive_review", but when you merged it, it had gone back to "needs_work" and had been that way for 12 hours.

comment:57 Changed 4 years ago by jhpalmieri

I can confirm Leif's timings. On an OS X machine:

  • make build from a fresh tarball: 73 minutes. Within that build, it took 19m53s to build gcc.
  • make build from a fresh tarball + this branch: 93 minutes. Within that build, it took 29m57s to build gcc.

Following that:

  • ./sage -f gcc took 20m39s without this branch.
  • ./sage -f gcc took 29m15s with this branch.

So the timing difference can be significant. It will be more significant for larger log files, which is why it doesn't make that much difference when building patch.

comment:58 Changed 4 years ago by dimpase

Perhaps Erik can explain the need to patch build/bin/sage-logger - this is the part that causes the slowdown.

comment:59 Changed 4 years ago by vbraun

  • Resolution fixed deleted
  • Status changed from closed to new

comment:60 Changed 4 years ago by embray

Okay, thanks for the full make build comparison. That's definitely more convincing. I'll see what I can do to tinker.

Perhaps Erik can explain the need to patch build/bin/sage-logger - this is the part that causes the slowdown.

I could--there are good reasons. But regardless as this stands now it's adding more overhead than any explanation I have justifies, so back to the drawing board.

comment:61 in reply to: ↑ 53 Changed 4 years ago by leif

Replying to embray:

How about simply changing the scripts to output a newline when prompting the user for something, at least when the sage-logger is used?

Those scripts don't necessarily have any way to know that sage-logger is being used, nor should they.

While you could set some env var in "non-interactive" mode (or when the sage-logger is used), what's the problem with having a newline after "... [Y/n]?"?


I think the test of just catting is not quite fair either. In a real build the overhead of the commands being run far outweighs the overhead of the logger.

The timings I listed are (the lower bound of) consumed CPU time you get in addition with every build from scratch (not taking into account a GCC build btw.); on a single-core that's what adds to the wall time (plus presumably the overhead of more context switches), and regardless of whether you build any experimental package (or any other question is asked).


There's no need to emphasize shell loop since it's using only shell built-ins, or should be,

You were not using bash's built-in test ([[ ... ]]), but the speed-up with the latter isn't huge either:

$ time ./sage-logger-20884-bt -p "cat logs/install.log" test-nw2.log >/dev/null

real    21m51.249s
user    21m15.210s
sys     0m36.170s

(i.e., ~22 minutes vs. previously ~25 minutes, saving about 3.5 minutes, and all tests were performed on the same, a relatively fast machine; note that sys though dropped by nearly one third.)


so that shouldn't be a significant source of overhead. Ultimately sed is looping over one character at a time too.

But it's not an interpreter, it compiles the regular expressions instead of rereading and interpreting them over and over, and btw. operates on lines of input -- you've seen the difference (orders of magnitude).


[...] I might prefer to go with my earlier instinct and just rewrite it in Python. I think using sed just to prepend to a line also feels like a blunt instrument.

Please don't, sed is IMHO pretty adequate in lack of other portable tools for this trivial task (prepending something to each line); regarding that we meanwhile have separate log files for each package it's a bit superfluous though, even for parallel builds. But as is (with sed), it doesn't hurt much.

(If at all, I'd personally rewrite the whole sage-logger in C.)

comment:62 in reply to: ↑ 54 Changed 4 years ago by leif

Replying to embray:

It's not silly, it's as documented. read -d -s ... is equivalent to read -d '-s' ... (where only the first character of the string argument '-s' is taken as the delimiter, as documented).

Just because it's as documented (which I see now, on very careful read, that the syntax must be -d<space><delimiter>). That's not *unreasonable*, just different from how other commands (specifically cut, which is why I was mentally comparing to) take their arguments. You can't well argue that the syntax of shell commands is always logical or consistent.

You were also passing an empty string, which there gets removed altogether in shell preparsing (-d'' => -d). (You could likely have written re''ad ... for example... 8-) )

Last edited 4 years ago by leif (previous) (diff)

comment:63 Changed 4 years ago by dimpase

Anyhow, perhaps we should keep sage-logger as it is, and proceed with the rest of the patch.

comment:64 Changed 4 years ago by embray

I have rewritten sage-logger in Python. I'm still doing some performance tests (i.e. on a full build) but all indication so far is that performance is the same or slightly better than the current version.

comment:65 follow-up: Changed 4 years ago by embray

You were not using bash's built-in test [[ ]]

No, I was using bash's built-in test [ ]. This is still a bash built-in--it does not run as a separate process. The only difference between [ ] and [[ ]] is that the latter is bash-specific and less portable. But when run explicitly in bash, as opposed to an arbitrary shell, test is still a shell built-in.

comment:66 follow-up: Changed 4 years ago by embray

(If at all, I'd personally rewrite the whole sage-logger in C.)

I considered that too. In fact it might be good to take the Python version I wrote as a prototype for a faster C version. That said, having a Python version is easier for bootstrapping purposes, and the Python version I wrote is just as fast as the current version, by all indications.

comment:67 in reply to: ↑ 66 Changed 4 years ago by embray

Replying to leif:

(If at all, I'd personally rewrite the whole sage-logger in C.)

I considered that too. In fact it might be good to take the Python version I wrote as a prototype for a faster C version. That said, having a Python version is easier for bootstrapping purposes, and the Python version I wrote is just as fast as the current version, by all indications (and can certainly be sped up more than the current naive version).

Last edited 4 years ago by embray (previous) (diff)

comment:68 in reply to: ↑ 65 Changed 4 years ago by leif

Replying to embray:

You were not using bash's built-in test [[ ]]

No, I was using bash's built-in test [ ]. This is still a bash built-in--it does not run as a separate process. The only difference between [ ] and [[ ]] is that the latter is bash-specific and less portable. But when run explicitly in bash, as opposed to an arbitrary shell, test is still a shell built-in.

Oh, that's new (to me m) and presumably to bash versions that aren't ages old)...

Still, [[ is reproducibly faster for me (bash 4.1.5) -- just retested ten times each (with just 0.5 MB input).

comment:69 Changed 4 years ago by chapoton

  • Branch changed from 705573623266f1017aa4a433e816c0e878960836 to u/embray/disable-exp-pkg-prompt
  • Commit set to 705573623266f1017aa4a433e816c0e878960836

re-introduced branch name


New commits:

ccff005Disable the y/n prompt when installing experimental packages.
611480dNo matter what I do, even with sed --unbuffered, sed will read either up to the EOF or the EOL, but otherwise buffers until EOL.
632fea7Add a new -y argument to sage-spkg to make it automatically answer 'y' to all prompts.
4f7b63fDisplay an additional message when continuing automatically
bdcfff4Two fixes:
0fc8fdeChange -N 1 to -n 1 in sage-logger, since the former does not work on
4ce1311Don't use -d'' to read, since it mysteriously treats - as a delimiter.
7a6f70cNow that we know what the correct syntax is, went back to using `-d ''`
7055736Replace one more example of echo -n with printf

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

IMHO we cannot solve this other than by either

  • disabling prompting the user, or
  • simply printing a newline after the prompt.

(I think the latter solution to users is the less surprising, as it doesn't change the behaviour.)


If the sage-logger did print incomplete lines (such as a prompt from read), this would just mess up other output where echo -n is used, especially from configure. We'd (again) end up with (now wrongly prefixed!) lines like for example

...
[ foo ] checking whether make supports nested variables... /bin/grep
[ bar ] checking build system type... yes
[ baz ] checking for C/C++ restrict keyword... x86_64-unknown-linux-gnu
...

where a prefix usually correctly refers to the package from which the first part of a line originated, but the result (at the end of the line) comes from another, so doesn't belong to the first part. (When building in parallel that is, on the terminal, and in install.log.)

In fact, even the left part of a line wouldn't necessarily belong to the package the prefix tells.

comment:71 follow-up: Changed 4 years ago by vbraun

IMHO we should never have y/n prompts in parallel output. Its pretty much by definition not interactive. The way to pass options to non-interactive processes is via command line options.

comment:72 Changed 4 years ago by mkoeppe

+1

comment:73 Changed 4 years ago by leif

@vbraun, @mkoeppe: It's still not clear to me what you propose.

Disable/remove any prompting? Disable it depending on how sage-spkg got invoked?

(Shouldn't sage -f ... -- as given in the example -- proceed anyway, since -f means force? ;-)

comment:74 in reply to: ↑ 71 Changed 4 years ago by embray

Replying to vbraun:

IMHO we should never have y/n prompts in parallel output. Its pretty much by definition not interactive. The way to pass options to non-interactive processes is via command line options.

I had this discussion with Dima and we agreed that there should be no prompts when running make directly, and that there should only be such a prompt when using the high level interface of ./sage -i. So that's a large part of what this patch does, before getting mired in all the issues with the prompt itself.

Maybe I should just refactor things further so that sage-spkg itself never prompts (and hence the prompt is never raised during make, which calls sage-spkg), and instead the prompt is only issued by the sage script itself before any calls to make.

comment:75 in reply to: ↑ 70 Changed 4 years ago by embray

Replying to leif:

If the sage-logger did print incomplete lines (such as a prompt from read), this would just mess up other output where echo -n is used, especially from configure. We'd (again) end up with (now wrongly prefixed!) lines like for example

Point taken on this--I didn't believe this would happen as I did't think make would interleave the output of individual commands but it definitely can if it's waiting for output for some command, as is wont to happen with configure. Though if you make is new enough (>=4.0) you can enable this behavior with -Oline.

That said, this isn't just an issue with sage-logger. This can happen even without it, and also happened with the previous version of the logger before I added the prefixing (and the line-buffering that came with it).

I do agree with Volker and others though that there's no reason for user input prompts in make. So I'll go with my proposed solution above and move the prompt entirely to the top-level user interface, and that will simplify this whole matter greatly.

I would still propose keeping my Python implementation of sage-logger because why not? I can change it to be line-based instead of character-based and that should actually make it faster than the current version by a bit, I think.

comment:76 follow-up: Changed 4 years ago by vbraun

+1 for python implementation instead of some untestable bash noise.

comment:77 in reply to: ↑ 76 Changed 4 years ago by leif

Replying to vbraun:

+1 for python implementation instead of some untestable bash noise.

The only change I'd perhaps make to the sage-logger (which works and is sufficiently short and simple enough) is to replace $SED "s/^/$prefix/" by cat if the prefix is empty (i.e., no -p given), in order to win a useless use of cat award. (More precisely, also move the argument to sed into SED, and let SED=cat if the prefix is empty. Otherwise we'd have to nearly duplicate a line in case the prefix is empty.)

Also, it's fast enough with sed (see figures above), so reimplementing it in Python would IMHO be just yet another case of needless use of Python -- in a script that would be executed by both the system's Python and (later) Sage's.


I'd be happy with the current branch if Erik just removed the changes to sage-logger from it.

comment:78 follow-up: Changed 4 years ago by mkoeppe

  • Priority changed from critical to blocker

comment:79 in reply to: ↑ 78 Changed 4 years ago by leif

Replying to mkoeppe:

* Priority changed from critical to blocker

Could we then postpone beautifying the sage-logger to another ticket?

Or do we want to wait with the next release until Erik had a "quiet, rainy day"? ;-)

comment:80 Changed 4 years ago by mkoeppe

I have not followed the details of this implementation. But in any case breaking the installation of all experimental packages is a blocker, IMO.

comment:81 Changed 4 years ago by leif

It isn't really broken, you just have to hit return when installation stops with the warning, or do e.g.

  echo yes | ./sage -i latte_int

comment:82 Changed 4 years ago by mkoeppe

Instead of fixing this, could as well revert #20640, #20708, which caused this problem.

comment:83 Changed 4 years ago by embray

I'm leaving tomorrow on vacation (originally today but my travel plans were diverted from the events in Turkey).

If someone else wants to fix this a very easy workaround (in fact, I would say a solution) without even touching sage-logger is to move the code that prompts the user out of build/bin/sage-spkg and into the sage script itself which is the "user interface" and the only script that should be prompting anything.

comment:84 Changed 4 years ago by embray

so reimplementing it in Python would IMHO be just yet another case of needless use of Python -- in a script that would be executed by both the system's Python and (later) Sage's.

It's already been done. And this is a moot point because Python is a requirement now for bootstrapping the build system, so while it may be "needless" the more we get rid of piles of bash noise the better. I agree with Volker here.

comment:85 Changed 4 years ago by embray

Even easier is to modify sage-spkg so it still handles the prompting (otherwise a lot of package parsing stuff needs to be duplicated), but for ./sage -i first have it run sage-spkg -d (download-only) which is the only context in which those prompts are displayed, then run make (which in turn calls sage-spkg) but with the package already downloaded, it won't prompt. I might add some options to sage-spkg to make extra sure it doesn't prompt.

comment:86 Changed 4 years ago by embray

  • Branch changed from u/embray/disable-exp-pkg-prompt to u/embray/ticket-20884-squashed
  • Commit changed from 705573623266f1017aa4a433e816c0e878960836 to a6aefa3c8c41d726a7e677a11ef521d484f1fa98
  • Status changed from new to needs_review

Okay, give this a look. I've pushed a new branch with a different approach.

The one downside I see to this approach is that if you run ./sage -i <pkg> for an experimental package, while it will display the warning prompt for that package, if <pkg> has any dependencies that are also experimental packages it will not display the prompt for those packages as well (it will still display a warning message).

I think this is acceptable--if the user is accepting to install one experimental package that can include everything that comes along with it.

(Sorry for the noise below--I made a few mistakes in rebasing that I had to fix)


New commits:

9da3ad5Disable the y/n prompt when installing experimental packages.
a6aefa3A simplified approach to #20884
Last edited 4 years ago by embray (previous) (diff)

comment:87 Changed 4 years ago by embray

I still want to add my Python implementation of sage-logger but that can be kept back for later.

comment:88 Changed 4 years ago by git

  • Commit changed from a6aefa3c8c41d726a7e677a11ef521d484f1fa98 to e2cf8fbe05c83a0827bcdbd7feba9e510524232e

Branch pushed to git repo; I updated commit sha1. This was a forced push. New commits:

e2cf8fbA simplified approach to #20884

comment:89 Changed 4 years ago by git

  • Commit changed from e2cf8fbe05c83a0827bcdbd7feba9e510524232e to 035e1d8e972d15f50229869da42fe669e9abc35e

Branch pushed to git repo; I updated commit sha1. This was a forced push. New commits:

035e1d8A simplified approach to #20884

comment:90 Changed 4 years ago by mkoeppe

I just tried sage -f latte_int and I observe the following three things (this is with MAKE='make -j12' in case that matters:

  • Sage banner in color, interleaved with environment variables in color due to competing output
  • a visible prompt "Are you sure you want to continue [Y/n]? "
  • building the dependency 4ti2
  • another warning about experimental packages, but no visible prompt.
  • "hang" as before
Last edited 4 years ago by mkoeppe (previous) (diff)

comment:91 Changed 4 years ago by mkoeppe

  • Status changed from needs_review to needs_work

comment:92 Changed 4 years ago by leif

You can avoid SED=cat if you put the pipe into the/a variable (POSTPROCESS, say), leaving it empty if no prefix was given, i.e.

    POSTPROCESS="| $SED 's/^/$prefix/'"
    ...
    ( trap '' SIGINT; eval tee -a "$logfile" $POSTPROCESS )
    ...

(I think.)

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

You don't have to install packages in a loop; you can download them one-by-one, and afterwards run make on all of them.

In any case, the following is wrong:

        sage-logger "sage-spkg $INSTALL_OPTIONS -d '$PKG'" logs/install.log

        # Then make / install the package with no prompts
        $MAKE SAGE_SPKG="sage-spkg $INSTALL_OPTIONS -y" "$OPT"

("$OPT" should be "$PKG".)


Unrelated to this ticket:

# First of all, make sure that the toolchain is up-to-date
# (which is a dependency of every package)
./sage --location
$MAKE all-toolchain

is pretty stupid before we know the package(s) at all exist(s), can be downloaded if needed, whatever. (And IIRC one gets *** ALL ENVIRONMENT VARIABLES BEFORE BUILD: *** etc. twice for no reason, the first time before any relevant processing happens.)

comment:94 in reply to: ↑ 93 Changed 4 years ago by jdemeyer

Replying to leif:

You don't have to install packages in a loop; you can download them one-by-one, and afterwards run make on all of them.

+1

comment:95 Changed 4 years ago by mkoeppe

  • Branch changed from u/embray/ticket-20884-squashed to u/mkoeppe/ticket-20884-squashed

comment:96 follow-up: Changed 4 years ago by mkoeppe

  • Authors changed from Erik Bray to Matthias Koeppe
  • Commit changed from 035e1d8e972d15f50229869da42fe669e9abc35e to 0b1acc2e58162075755f52e941bcb537d8f33d30
  • Reviewers Dima Pasechnik, Matthias Koeppe deleted
  • Status changed from needs_work to needs_review

I've implemented a "good enough for next release" solution. Making it prettier can be on a follow-up ticket. Needs review.


New commits:

0b1acc2Simple (not pretty) solution for #20884

comment:97 in reply to: ↑ 96 Changed 4 years ago by leif

Replying to mkoeppe:

I've implemented a "good enough for next release" solution. Making it prettier can be on a follow-up ticket. Needs review.


New commits:

0b1acc2Simple (not pretty) solution for #20884

Ok for me, modulo indentation... (tabs instead of spaces perhaps?)

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

(At least in theory, we'd have to make sure the prompting message doesn't vanish due to other output when building in parallel though. But I think in practice this is very unlikely.)

comment:99 in reply to: ↑ 98 Changed 4 years ago by mkoeppe

Replying to leif:

(At least in theory, we'd have to make sure the prompting message doesn't vanish due to other output when building in parallel though. But I think in practice this is very unlikely.)

Yes, I hope that a follow-up ticket will do a proper solution, which prompts early (or just bails out and requires an extra flag), rather than prompting in the middle of a parallel build.

My simple solution just restores (except for cosmetics) the status quo before #20640, #20708 broke the prompting.

comment:100 Changed 4 years ago by git

  • Commit changed from 0b1acc2e58162075755f52e941bcb537d8f33d30 to 6888a6788eb25bcc293a465091c68850346f0e85

Branch pushed to git repo; I updated commit sha1. New commits:

6888a67untabify changes

comment:101 Changed 4 years ago by vbraun

  • Reviewers set to Leif Leonhardy, Volker Braun
  • Status changed from needs_review to positive_review

comment:102 Changed 4 years ago by vbraun

  • Branch changed from u/mkoeppe/ticket-20884-squashed to 6888a6788eb25bcc293a465091c68850346f0e85
  • Resolution set to fixed
  • Status changed from positive_review to closed

comment:103 Changed 4 years ago by mkoeppe

  • Commit 6888a6788eb25bcc293a465091c68850346f0e85 deleted

Follow-up ticket - #21082. This is where work on the patch by Erik Bray can continue.

Note: See TracTickets for help on using tickets.