Proposed/still running

[maximuska]

Due to a somewhat popular demand..

There is currently no infrastructure to test this with gtest, but to avoid "great" being an enemy of "good" publishing this anyway. I did tested it manually using the following manifest: git show 22aa5f3:tst4.ninja, for what it worth (building different targets in separate and together)..

This pull request provides the following features:

• If ninja is running one or more commands lasting longer than 3 sec w/o status being updated (e.g., nothing starts/finishes) ninja starts printing "xxx (still running ) with '' spinning moderately (test with: './ninja -f tst.ninja e5').
• If only one command is currently running, and no new commands can be started and the command emits output while running (e.g., a long-running generator), then ninja starts dumping the output immediately, in real-time, w/o waiting for the command to finish (test with: './ninja -f tst.ninja e6').

[buildhive]

Evan Martin » ninja #561 SUCCESS
This pull request looks good
(what's this?)

[nico]

Bleh, left this comment on the wrong pull request (#608), it belongs here:

ninja used to have code to print a "still going" line every 5 seconds, but that code was dead due to a bug, and so I removed it ( 555431a ). That implementation looks simpler, maybe it's good enough?

On the other hand, updating the status line every N seconds regardless of progress might be nice for some NINJA_STATUS settings anyhow.

[maximuska]

555431a 555431a doesn't address
quite the same use-case, I think.

I was trying to solve the following problems:

• Sometimes people are coming to me with the "ninja gets stuck" complaints.
  Then I am asking to "ps auxf", which shows that ninja is actually working
  fine. This often happens with large external projects built with their own
  build systems and being a single target from ninja perspective (e.g., Linux
  kernel).
• Some long-running commands (e.g., our generator) are printing their own
  progress, which is swallowed when these run from inside ninja, which is
  pity.

On Mon, Jul 29, 2013 at 8:21 AM, Nico Weber notifications@git.luolix.topwrote:

Bleh, left this comment on the wrong pull request (#608#608),
it belongs here:

ninja used to have code to print a "still going" line every 5 seconds, but
that code was dead due to a bug, and so I removed it ( 555431ahttps://github.com/martine/ninja/commit/555431a). That implementation looks simpler, maybe it's good enough?

On the other hand, updating the status line every N seconds regardless of
progress might be nice for some NINJA_STATUS settings anyhow.

—
Reply to this email directly or view it on GitHubhttps://github.com//pull/629#issuecomment-21699973
.

Maxim

[sorbits]

I have the same problem, i.e. show me the job that is actually stalling the build, rather than “ninja is not dead”, so this pull request looks good to me — I made my own patch for this (7831cb8) before I became aware of @maximuska’s. His patch is definitely better, but I suggest removing the spinner when the output device is not a smart terminal, otherwise the receiver will be spammed with a lot of duplicate output.

[maximuska]

@sorbits: re "smart terminal", the code already does that you've proposed (or you mean something else?)
E.g., with my test file, only one line is printed when output is piped:

host204: ninja> ./ninja -f tst4.ninja e5 | cat
[1/1] [SLEEP-20] e5
host204: ninja>

[sorbits]

@maximuska Yes, that is what I meant, I didn’t see that BuildEdgeStillRunning is a no-op for !printer_.is_smart_terminal().

But this means for the case where you don’t output to a tty, your patch has effectively no changed behavior, right?

I think in the non-tty case, it should print the active job’s line once (if it is wasn’t the last job printed).

[maximuska]

@sorbits - right, almost. To be precise, after the change as it is now ninja re-checks each 50ms if it can run anything new, which may result in spawning new tasks if load-based jobs limit (-j xx) is in effect. Highly unlikely, though.

Your proposal to fix non-tty mode as well is all-right, but frankly sepaking I am reluctant to invest in it before it gets more traction.

[mgaunard]

I personally pipe all my ninja output to less. Since I really need this feature, I've simply removed the test for is_smart_terminal in BuildEdgeRunningSolo.
Once I do that, it prints the status twice. The test to call PrintStatus might not be correct then.

[maximuska]

I've took a look at that you have described so briefly, if I comment out the
tests following your instructions AND pipe the output, the output looks
like that indeed:

host204: ninja> ./ninja -f tst.ninja e1 | cat
[1/1] [ECHOS-20] e1
[1/1] [ECHOS-20] e1

1
2
3
4
5
6
..

But if I edit 'LinePrinter::LinePrinter()' to unconditionally set
'smart_terminal_= true' instead (e.g., one could add a command line option
to force that), the output looks fine:

host204: ninja> ./ninja -f tst4.ninja e1 | cat
[1/1] [ECHOS-20] e1
1
2
3
4
5
6

On Sat, Sep 7, 2013 at 2:32 PM, Mathias Gaunard notifications@git.luolix.topwrote:

I personally pipe all my ninja output to less. Since I really need this
feature, I've simply removed the test for is_smart_terminal in
BuildEdgeRunningSolo.
Once I do that, it prints the status twice. The test to call PrintStatus
might not be correct then.

—
Reply to this email directly or view it on GitHubhttps://github.com//pull/629#issuecomment-23992713
.

Maxim

[nicolasdespres]

@maximuska This is a great job. I just tried it and I like it very much.
@sorbits I double your request. Showing the stalling job would be good.

About the issue reported by @mgaunard I found this easy fix. It seems to work with my simple tests. I did not investigate more your code so maybe I have broken something else:

diff --git a/src/build.cc b/src/build.cc
index 7a3cf7e..2c7c15d 100644
--- a/src/build.cc
+++ b/src/build.cc
@@ -183,11 +183,11 @@ void BuildStatus::RestartStillRunningDelay()

 void BuildStatus::BuildEdgeRunningSolo(Edge* edge, const string& output)
 {
-  if (config_.verbosity == BuildConfig::QUIET || !printer_.is_smart_terminal())
+  if (config_.verbosity == BuildConfig::QUIET)
     return;

   if (output.size() > solo_bytes_printed_) {
-    if (solo_bytes_printed_ == 0) {
+    if (solo_bytes_printed_ == 0 && printer_.is_smart_terminal()) {
       // Print edge description before starting to print its output
       PrintStatus(edge, "\n");
     }

$ cat ~/tmp/ninja/tst.ninja
rule SLEEP
command = for i in 1 2 3 4 5 6; do echo $$i; sleep 1; done
description = Sleeping

build o1: SLEEP s1
build o2: SLEEP s2
build o3: SLEEP s3
$ ./ninja -C ~/tmp/ninja -f tst.ninja o1
ninja: Entering directory /home/despres/tmp/ninja' [100%|0.000][0|1|0][?|?] Sleeping 1 2 3 4 5 6 $ ./ninja -C ~/tmp/ninja -f tst.ninja o1 | cat ninja: Entering directory/home/despres/tmp/ninja'
[100%|0.000][0|1|0][?|?] Sleeping
1
2
3
4
5
6

[Boddlnagg]

This PR seems to be dead (?), but it's a feature that I would very much like to see being integrated (and I think #111 requests the same thing). It's quite confusing when the status message is "Doing B" because B was the last thing that was started (and finished), but the task that's blocking further progress is actually a long-running A that was started before B. So in that case I'd like to somehow see that ninja is waiting for A to finish (automatically switching to live output as if pool = console is specified might be a good idea as well).

[nico]

I really like the approach in #1320 for that particular problem (which came in while I was on leave, and the author got impatient and deleted their clone so I can't easily merge it, but I'll recreate it myself when I have time).

[jhasse]

Let's continue any discussions in #111.

[mgaunard]

#111 doesn't seem to be the same thing at all.
This PR removes buffering if a single command is being run, so that its output is displayed as it is being generated, instead of buffered until the command finishes.
#111 is about displaying "still running" if waiting for a long-running command without output.

[jhasse]

You're right, I've missed immediate output part. But one commit is still about the same as #111, isn't it?

[maximuska]

I can do that if there is an intention to merge that.

…

On Sun, Aug 4, 2019 at 10:46 AM Michael Jones ***@***.***> wrote: @maximuska <https://github.com/maximuska> Would you be able to rebase this pull request against the latest master branch code? — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#629?email_source=notifications&email_token=AAAWV6S2YTVPPM72OZQZ653QC2CMXA5CNFSM4AG2NKU2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD3P4MXI#issuecomment-517981789>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAAWV6XEFIKHTSBFIHGHHS3QC2CMXANCNFSM4AG2NKUQ> .

-- Maxim

[jhasse]

While this is a nice feature (I'm talking about the second commit), I would prefer to have this implemented in an external frontend (see #1600). Ninja simply doesn't have enough manpower to maintain this long term, sorry.

@jonesmz That goes with mostly all "frontend" PRs. Please don't ask them to rebase before #1600 is merged in some form or another, because that would result in merge conflicts again.

[sorbits]

I would prefer to have this implemented in an external frontend

Maybe I do not understand you as you refer to second commit, but closed the PR which title is about the “still running” issue.

The problem being solved here is when you have Task 1, 2, and 3, where 1 is the slow one. But ninja is likely showing: [3/3] Task 3 when we are actually waiting for Task 1 (both Task 2 and 3 have completed).

This is problematic because the user may wonder why Task 3 is taking so long, and also not realize that there is an issue with Task 1 (this could e.g. be a test runner that has gone into an infinite loop).

I don’t think ninja should start a “spinner” but I do think ninja should update the status text, so that if a solo task has been running for e.g. 1 second and the status currently shows another task as running, it should reprint the status line as [3/3] Task 1 (i.e. actual task running).

I have run into this countless of times, where ninja was stalling, but the current output did not offer a way for me to figure out what was actually holding up the build.

[jhasse]

I was only referring to the second commit, because the still-running-problem has multiple ways to fix it, one of them was #1320, which we merged but had to revert due to a regression. As the problem seems to be more complicated than first thought, I think a possible solution should be discussed in #111 first (and again: Maybe just be implemented in an external frontend).

[sorbits]

I think a possible solution should be discussed in #111 first

OK, I added the patch I have been using to that PR.

I thought I had previously submitted a PR for it, but it doesn’t appear so. Probably because it was sort of a duplicate, but I have had no problems with that patch for the last 6 years.