* Something fishy in process timing @ 1996-07-28 21:52 Carl Edman 1996-07-31 11:45 ` Peter Stephenson 0 siblings, 1 reply; 4+ messages in thread From: Carl Edman @ 1996-07-28 21:52 UTC (permalink / raw) To: Zsh hacking and development Have a look at this paste from my xterm: /tmp% xjig -file /tmp/a.gif -ts 50 &| 7:03pm /tmp% 7:04pm xjig V2.4, by Helmut Hoenig, July-24-96 Imported from TIFF image: 09320028.tif X connection to :0.0 broken (explicit kill or server shutdown). /tmp% ~/ftp 8:11pm ~/ftp% ls 8:12pm [ ... ] ls 133.68s user 37.81s system 100% cpu 0.312 total I probably included somewhat more context than necessary, but this seems to be an interaction between several processes. The bug is obviously the last line. The ls really only took the indicated total time, so the user and system times are obviously bogus (no, this is not a 500 processor parallel machine with a really, really slow ls). What it looks like is that the user and system timings for the disowned xjig process got added to the reported timings for the ls. That doesn't seem the right thing to do. FWIW, this is a machine running Linux 2.0.9 and zsh 3.0 pre3. Carl Edman PS: If this really were a parallel machine in which user+system time legitimately exceeds wall clock time, wouldn't the right thing be to report more than 100% CPU usage ? ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: Something fishy in process timing 1996-07-28 21:52 Something fishy in process timing Carl Edman @ 1996-07-31 11:45 ` Peter Stephenson 1996-07-31 17:50 ` Zoltan Hidvegi 0 siblings, 1 reply; 4+ messages in thread From: Peter Stephenson @ 1996-07-31 11:45 UTC (permalink / raw) To: Zsh hackers list, Carl Edman cedman@lynx.ps.uci.edu wrote: > Have a look at this paste from my xterm: I'm looking. (I presume that's a fish paste :-):-).) > /tmp% xjig -file /tmp/a.gif -ts 50 &| 7:03pm > /tmp% 7:04pm > xjig V2.4, by Helmut Hoenig, July-24-96 > > Imported from TIFF image: 09320028.tif > X connection to :0.0 broken (explicit kill or server shutdown). > > /tmp% ~/ftp 8:11pm > ~/ftp% ls 8:12pm > [ ... ] > ls 133.68s user 37.81s system 100% cpu 0.312 total > > What it looks like is that the user and system timings for the disowned > xjig process got added to the reported timings for the ls. That doesn't > seem the right thing to do. That is what happened and it isn't right. This patch seems to fix it. The bug is that zsh handles SIGCHLD for disowned processes (unavoidably), but doesn't bother calculating the usage, so it doesn't get updated into the total shell times in shtms until the next non-disowned process is reaped. The patch simply updates shtms even if the process wasn't found in the table. This is the last hunk. The second hunk below simply does the same thing when a process substitution process is finished. Otherwise, it's impossible to tell what process the times for that will tack themselves onto. > PS: If this really were a parallel machine in which user+system time > legitimately exceeds wall clock time, wouldn't the right thing be to > report more than 100% CPU usage ? I agree: nowadays there's less excuse than there used to be to massage the CPU percentage --- and in fact I've relied on the accuracy of this myself when running programmes on parallel machines. The first hunk below removes the limitation. (Testing for a real parallel machine would probably be taking things a bit far.) I wrapped a nearby line round as well. By the way, my time reports look like this: ./usetime 2 1000000: 1.37s(r) 1.35s(u) 0.02s(s) (99%): %K kb, max %M kb, %F pf I still haven't worked out what happened to %K, %M and %F. *** Src/jobs.c.time Mon Jul 22 22:32:14 1996 --- Src/jobs.c Wed Jul 31 13:03:39 1996 *************** *** 725,733 **** elapsed_time = real->tv_sec + real->tv_usec / 1000000.0; user_time = ti->ut / (double) clktck; system_time = ti->st / (double) clktck; ! percent = 100.0 * (ti->ut + ti->st) / (clktck * real->tv_sec + clktck * real->tv_usec / 1000000.0); ! if (percent > 100) ! percent = 100; /* just to make it look right */ if (!(s = getsparam("TIMEFMT"))) s = DEFAULT_TIMEFMT; --- 725,732 ---- elapsed_time = real->tv_sec + real->tv_usec / 1000000.0; user_time = ti->ut / (double) clktck; system_time = ti->st / (double) clktck; ! percent = 100.0 * (ti->ut + ti->st) ! / (clktck * real->tv_sec + clktck * real->tv_usec / 1000000.0); if (!(s = getsparam("TIMEFMT"))) s = DEFAULT_TIMEFMT; *** Src/signals.c.time Wed Jul 31 13:10:59 1996 --- Src/signals.c Wed Jul 31 13:31:13 1996 *************** *** 479,484 **** --- 479,485 ---- dotrap(WTERMSIG(status)); } else *procsubval = WEXITSTATUS(status); + times(&shtms); goto cont; } if (!es) *************** *** 500,505 **** --- 501,512 ---- if (findproc(pid, &jn, &pn)) { update_process(pn, status); update_job(jn); + } else { + /* If not found, update the shell record of time spent by + * children in sub processes anyway: otherwise, this + * will get added on to the next found process that terminates. + */ + times(&shtms); } } break; -- Peter Stephenson <pws@ifh.de> Tel: +49 33762 77366 WWW: http://www.ifh.de/~pws/ Fax: +49 33762 77330 Deutches Electronen-Synchrotron --- Institut fuer Hochenergiephysik Zeuthen DESY-IfH, 15735 Zeuthen, Germany. ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: Something fishy in process timing 1996-07-31 11:45 ` Peter Stephenson @ 1996-07-31 17:50 ` Zoltan Hidvegi 1996-07-31 19:26 ` Richard Coleman 0 siblings, 1 reply; 4+ messages in thread From: Zoltan Hidvegi @ 1996-07-31 17:50 UTC (permalink / raw) To: Zsh workers list > By the way, my time reports look like this: > > ./usetime 2 1000000: 1.37s(r) 1.35s(u) 0.02s(s) (99%): %K kb, max %M kb, %F pf > > I still haven't worked out what happened to %K, %M and %F. They've got removed on 30 March 1995 by Richard. If you have the RCS sources it happened in revision 1.18 of jobs.c. I think the corresponting ChangeLog entry is: * most of signals.{c,h} rewritten. Perhaps it was not portable? Zoltan ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: Something fishy in process timing 1996-07-31 17:50 ` Zoltan Hidvegi @ 1996-07-31 19:26 ` Richard Coleman 0 siblings, 0 replies; 4+ messages in thread From: Richard Coleman @ 1996-07-31 19:26 UTC (permalink / raw) To: zsh-workers > > By the way, my time reports look like this: > > > > ./usetime 2 1000000: 1.37s(r) 1.35s(u) 0.02s(s) (99%): %K kb, max %M kb, %F pf > > > > I still haven't worked out what happened to %K, %M and %F. > > They've got removed on 30 March 1995 by Richard. If you have the RCS > sources it happened in revision 1.18 of jobs.c. > > I think the corresponting ChangeLog entry is: > > * most of signals.{c,h} rewritten. > > Perhaps it was not portable? I can answer this one, since I removed them. When I rewrote the signals code, I converted zsh from using the BSD signals functions by default to using the POSIX signal functions. The flags such as %K return information that is specific to the way resource usage is reported on BSD. I looked for portable alternatives, but didn't find anything. I also rewrote the way resource usage information was reported. It sucks that we lost those flags, but almost no one complained at the time, and it greatly cleaned up the code, I consider it a small loss. rc ^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~1996-07-31 19:38 UTC | newest] Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 1996-07-28 21:52 Something fishy in process timing Carl Edman 1996-07-31 11:45 ` Peter Stephenson 1996-07-31 17:50 ` Zoltan Hidvegi 1996-07-31 19:26 ` Richard Coleman
Code repositories for project(s) associated with this public inbox https://git.vuxu.org/mirror/zsh/ This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).