ommitted time on resume

ommitted time on resume

[Wayne Davison]

[-- Attachment #1: Type: text/plain, Size: 271 bytes --]

I noticed this bug recently:

If I have a job running under "time", e.g. "time sleep 3" and the program
gets suspended (via Ctrl-Z), the resumed program (via %) does not output its
time.  I tested the official ubuntu 4.3.11 version and the latest dev
version.

..wayne..

Re: ommitted time on resume

[Bart Schaefer]

On Aug 5,  4:21pm, Wayne Davison wrote:
}
} If I have a job running under "time", e.g. "time sleep 3" and the
} program gets suspended (via Ctrl-Z), the resumed program (via %) does
} not output its time. I tested the official ubuntu 4.3.11 version and
} the latest dev version.

Hm.  I wouldn't have expected it to print the time after the job was
foregrounded again.  Cf. bash:

bash-3.2$ time sleep 4
^Z
[1]+  Stopped                 sleep 4

real    0m0.672s
user    0m0.000s
sys     0m0.001s
bash-3.2$ fg
sleep 4
bash-3.2$ 

In order for the builtin time to behave like e.g. /usr/bin/time does,
it would have to run *itself* in an external process rather than run
the subcommand in an external process.

I'm undecided on whether zsh's behavior on TSTP (skip reporting the
time entirely) is preferable.  The only ksh to which I have access
behaves the same as bash.

Re: ommitted time on resume

[Wayne Davison]

[-- Attachment #1.1: Type: text/plain, Size: 1895 bytes --]

On Fri, Aug 5, 2011 at 8:17 PM, Bart Schaefer <schaefer@brasslantern.com>wrote:

> Hm.  I wouldn't have expected it to print the time after the job
> was foregrounded again.
>

I sure expect that.  After all, the jobs output of the suspended command
still mentions the "time" prefix.

This seems to be caused by the handling of the first job suspension when it
creates a new process to replace the shell's role in the process handling --
it sets STAT_NOPRINT on the original job (or jobs -- the one(s) that have
STAT_TIMED set).  The STAT_NOPRINT causes a job to not show up in the output
of "jobs" (which just shows the newly-created super job for the whole
command), but it also causes the section of the code that would have gotten
around to printing out the time info to never get reached.

The attached patch seems to be the right fix for this.  It puts a check for
STAT_DONE && should_report_time() into the skip_print short-circuit in
printjob().  I've tested this with a time-wasting program and some pipelines
to see that the output seems correct.  For instance, assume that a.out just
takes 5 seconds in a cpu-wasting loop:

prompt$  time ./a.out | cat ~/foo/*(^/) | wc
 108376  459723 5888382
^Z
[2]  + 30000 suspended  ./a.out |
       30001 done       cat ~/foo/*(^/) |
       30002 done       wc
[1]  + 30003 suspended  time ./a.out | cat ~/foo/*(^/) | wc
prompt$ %
[1]  + 30003 continued  time ./a.out | cat ~/foo/*(^/) | wc
./a.out  5.55s user 0.02s system 54% cpu 10.258 total
cat ~/foo/*(^/)  0.00s user 0.01s system 3% cpu 0.239 total
wc  0.21s user 0.00s system 89% cpu 0.241 total

Without the patch, no times would be output at all.

For even more coolness, it would be nice for the shell to keep track of how
much elapsed time was spent suspended and either subtract it from the
process's wall-clock time output, or output the suspended time in an extra
field.

..wayne..

[-- Attachment #1.2: Type: text/html, Size: 2506 bytes --]

[-- Attachment #2: time-suspend.patch --]
[-- Type: text/x-patch, Size: 305 bytes --]

index 9c9b12f..f64c183 100644
--- a/Src/jobs.c
+++ b/Src/jobs.c
@@ -952,6 +952,8 @@ printjob(Job jn, int lng, int synch)
     }
 
     if (skip_print) {
+	if (jn->stat & STAT_DONE && should_report_time(jn))
+	    dumptime(jn);
 	if (jn->stat & STAT_DONE) {
 	    deletejob(jn);
 	    if (job == curjob) {

Re: ommitted time on resume

[Wayne Davison]

[-- Attachment #1.1: Type: text/plain, Size: 875 bytes --]

Another potential fix would be to change the hiding choices of the jobs so
that the "jobs" output would show the pieces of the pipeline, more like when
a non-time-using pipeline is used.  For example, if I suspend "sleep 5 | cat
~/foo/*(^/) | wc", jobs shows me the various pieces of the pipeline (as
would continue):

[1]  + suspended  sleep 5 |
       done       cat ~/foo/*(^/) | wc

I created the attached simple patch to test this, but it doesn't really work
right -- it doesn't hide the super job (which might be a good thing), and it
prints superfluous "done" messages at the end of the run.  I'm not going to
fiddle with this anymore, since my prior patch seems like a reasonable fix,
and the changing of the jobs output when suspending a newly-created
super-job seems like a separate issue (but one that could also fix the time
issue in a different way).

..wayne..

[-- Attachment #1.2: Type: text/html, Size: 1032 bytes --]

[-- Attachment #2: time-suspend2.patch --]
[-- Type: text/x-patch, Size: 553 bytes --]

index 6320f6a..7170652 100644
--- a/Src/exec.c
+++ b/Src/exec.c
@@ -1549,8 +1549,8 @@ execpline(Estate state, wordcode slcode, int how, int last1)
 			 * normal (non-super-) job. */
 			if (!(jn->stat & STAT_DONE)) {
 			    jobtab[list_pipe_job].other = newjob;
-			    jobtab[list_pipe_job].stat |= STAT_SUPERJOB;
-			    jn->stat |= STAT_SUBJOB | STAT_NOPRINT;
+			    jobtab[list_pipe_job].stat |= STAT_SUPERJOB | STAT_NOPRINT;
+			    jn->stat |= STAT_SUBJOB;
 			    jn->other = pid;
 			}
 			if ((list_pipe || last1) && hasprocs(list_pipe_job))