From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 9095 invoked by alias); 6 Aug 2011 19:21:17 -0000 Mailing-List: contact zsh-workers-help@zsh.org; run by ezmlm Precedence: bulk X-No-Archive: yes List-Id: Zsh Workers List List-Post: List-Help: X-Seq: 29650 Received: (qmail 3197 invoked from network); 6 Aug 2011 19:21:02 -0000 X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on f.primenet.com.au X-Spam-Level: X-Spam-Status: No, score=-2.6 required=5.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID,HTML_MESSAGE,RCVD_IN_DNSWL_LOW autolearn=ham version=3.3.1 Received-SPF: pass (ns1.primenet.com.au: SPF record at _spf.google.com designates 209.85.160.171 as permitted sender) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=mime-version:sender:in-reply-to:references:date :x-google-sender-auth:message-id:subject:from:to:cc:content-type; bh=Ck2oCDNbi14PVsVbUWg1oD48iRrdCTjdNy8vUEBxm0A=; b=ItT5fz+8AYILkIIUzUqor3eyRDMw7RhjZZOBIbze3tdLhLfFXb7Y3enX8RSOdMYf7g fJYJ9VfpNjjcY+8WXkB1aKnWf1I4MalJGTAcitvY+c1mTQXv8x8z308P5qz7CBp9WvKm GXfgd9vSH6sifo93AyhSgWnXjhYMvpy03DNus= MIME-Version: 1.0 Sender: 4wayned@gmail.com In-Reply-To: <110805201755.ZM32464@torch.brasslantern.com> References: <110805201755.ZM32464@torch.brasslantern.com> Date: Sat, 6 Aug 2011 12:20:53 -0700 X-Google-Sender-Auth: ZUsy99rGv_W3xmaGIoT4UVkXAys Message-ID: Subject: Re: ommitted time on resume From: Wayne Davison To: Bart Schaefer Cc: zsh-workers@zsh.org Content-Type: multipart/mixed; boundary=20cf30363913dd512204a9db1cd0 --20cf30363913dd512204a9db1cd0 Content-Type: multipart/alternative; boundary=20cf30363913dd511e04a9db1cce --20cf30363913dd511e04a9db1cce Content-Type: text/plain; charset=UTF-8 On Fri, Aug 5, 2011 at 8:17 PM, Bart Schaefer 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.. --20cf30363913dd511e04a9db1cce Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: quoted-printable
On Fri, Aug 5, 2011 at 8:17 PM, Bart Schaefer <schaefer@b= rasslantern.com> wrote:
Hm. =C2=A0I wouldn't have expected it to print the ti= me after the job was=C2=A0foregrounded again.

I sure expect that. =C2=A0After all, the jobs output of the suspen= ded command still mentions the "time" prefix.

This seems to be caused by the handling of the first jo= b 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 job= s -- the one(s) that have STAT_TIMED set). =C2=A0The 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 sect= ion 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. = =C2=A0It puts a check for STAT_DONE && should_report_time() into th= e skip_print short-circuit in printjob(). =C2=A0I've tested this with a= time-wasting program and some pipelines to see that the output seems corre= ct. =C2=A0For instance, assume that a.out just takes 5 seconds in a cpu-was= ting loop:

prompt$ =C2=A0time ./a.out | cat ~/foo/*(^/) | wc
=
=C2=A0108376 =C2=A0459723 5888382
^Z
[2] =C2=A0+ 3= 0000 suspended =C2=A0./a.out |=C2=A0
=C2=A0 =C2=A0 =C2=A0 =C2=A03= 0001 done =C2=A0 =C2=A0 =C2=A0 cat ~/foo/*(^/) |=C2=A0
=C2=A0 =C2= =A0 =C2=A0 =C2=A030002 done =C2=A0 =C2=A0 =C2=A0 wc
[1] =C2=A0+ 30003 suspended =C2=A0time ./a.out | cat ~/foo/*(^/) | wc<= /div>
prompt$ %
[1] =C2=A0+ 30003 continued =C2=A0time ./a.ou= t | cat ~/foo/*(^/) | wc
./a.out =C2=A05.55s user 0.02s system 54= % cpu 10.258 total
cat ~/foo/*(^/) =C2=A00.00s user 0.01s system 3% cpu 0.239 total
=
wc =C2=A00.21s user 0.00s system 89% cpu 0.241 total

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

<= /div>
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 proc= ess's wall-clock time output, or output the suspended time in an extra = field.

..wayne..
--20cf30363913dd511e04a9db1cce-- --20cf30363913dd512204a9db1cd0 Content-Type: text/x-patch; charset=US-ASCII; name="time-suspend.patch" Content-Disposition: attachment; filename="time-suspend.patch" Content-Transfer-Encoding: base64 X-Attachment-Id: f_gr0yddex0 aW5kZXggOWM5YjEyZi4uZjY0YzE4MyAxMDA2NDQKLS0tIGEvU3JjL2pvYnMuYworKysgYi9TcmMv am9icy5jCkBAIC05NTIsNiArOTUyLDggQEAgcHJpbnRqb2IoSm9iIGpuLCBpbnQgbG5nLCBpbnQg c3luY2gpCiAgICAgfQogCiAgICAgaWYgKHNraXBfcHJpbnQpIHsKKwlpZiAoam4tPnN0YXQgJiBT VEFUX0RPTkUgJiYgc2hvdWxkX3JlcG9ydF90aW1lKGpuKSkKKwkgICAgZHVtcHRpbWUoam4pOwog CWlmIChqbi0+c3RhdCAmIFNUQVRfRE9ORSkgewogCSAgICBkZWxldGVqb2Ioam4pOwogCSAgICBp ZiAoam9iID09IGN1cmpvYikgewo= --20cf30363913dd512204a9db1cd0--