* bug with for and time @ 2004-10-04 15:31 Nathan Sidwell 2004-10-04 16:10 ` Peter Stephenson 0 siblings, 1 reply; 12+ messages in thread From: Nathan Sidwell @ 2004-10-04 15:31 UTC (permalink / raw) To: zsh-workers Zsh 4.0.4 appears to lose the time command in the following, nathan@garibaldi:363>for i in 1 2 ; time echo but, place the command in a subshell, and it works. nathan@garibaldi:364>for i in 1 2 ; time (echo) ( echo ) 0.00s user 0.00s system 0% cpu 0.000 total ( echo ) 0.00s user 0.00s system 0% cpu 0.000 total nathan -- Nathan Sidwell :: http://www.codesourcery.com :: CodeSourcery LLC nathan@codesourcery.com :: http://www.planetfall.pwp.blueyonder.co.uk ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: bug with for and time 2004-10-04 15:31 bug with for and time Nathan Sidwell @ 2004-10-04 16:10 ` Peter Stephenson 2004-10-05 9:38 ` Matthias B. 0 siblings, 1 reply; 12+ messages in thread From: Peter Stephenson @ 2004-10-04 16:10 UTC (permalink / raw) To: zsh-workers Nathan Sidwell wrote: > Zsh 4.0.4 appears to lose the time command in the following, > > nathan@garibaldi:363>for i in 1 2 ; time echo > > > but, place the command in a subshell, and it works. Yes, that's always been an annoying limitation: "time" works by gettings system information about subprocesses, and there isn't one in this case. -- Peter Stephenson <pws@csr.com> Software Engineer CSR Ltd., Science Park, Milton Road, Cambridge, CB4 0WH, UK Tel: +44 (0)1223 692070 ********************************************************************** This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This footnote also confirms that this email message has been swept by MIMEsweeper for the presence of computer viruses. www.mimesweeper.com ********************************************************************** ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: bug with for and time 2004-10-04 16:10 ` Peter Stephenson @ 2004-10-05 9:38 ` Matthias B. 2004-10-05 18:18 ` Dan Nelson 0 siblings, 1 reply; 12+ messages in thread From: Matthias B. @ 2004-10-05 9:38 UTC (permalink / raw) Cc: zsh-workers On Mon, 04 Oct 2004 17:10:47 +0100 Peter Stephenson <pws@csr.com> wrote: > Nathan Sidwell wrote: > > Zsh 4.0.4 appears to lose the time command in the following, > > > > nathan@garibaldi:363>for i in 1 2 ; time echo > > > > > > but, place the command in a subshell, and it works. > > Yes, that's always been an annoying limitation: "time" works by gettings > system information about subprocesses, and there isn't one in this case. Then how does bash do it? bash can time builtins just fine. MSB -- I will continue to be an impossible person as long as those who are now possible remain possible. ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: bug with for and time 2004-10-05 9:38 ` Matthias B. @ 2004-10-05 18:18 ` Dan Nelson 2004-10-06 11:48 ` Matthias B. 0 siblings, 1 reply; 12+ messages in thread From: Dan Nelson @ 2004-10-05 18:18 UTC (permalink / raw) To: Matthias B.; +Cc: zsh-workers In the last episode (Oct 05), Matthias B. said: > On Mon, 04 Oct 2004 17:10:47 +0100 Peter Stephenson <pws@csr.com> wrote: > > Nathan Sidwell wrote: > > > Zsh 4.0.4 appears to lose the time command in the following, > > > > > > nathan@garibaldi:363>for i in 1 2 ; time echo > > > > > > but, place the command in a subshell, and it works. > > > > Yes, that's always been an annoying limitation: "time" works by > > gettings system information about subprocesses, and there isn't one > > in this case. > > Then how does bash do it? bash can time builtins just fine. It probably calls getrusage(RUSAGE_SELF) before and after whatever you're timing, then prints the deltas. -- Dan Nelson dnelson@allantgroup.com ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: bug with for and time 2004-10-05 18:18 ` Dan Nelson @ 2004-10-06 11:48 ` Matthias B. 2004-10-06 12:52 ` Nikolai Weibull 2004-10-06 17:06 ` Peter Stephenson 0 siblings, 2 replies; 12+ messages in thread From: Matthias B. @ 2004-10-06 11:48 UTC (permalink / raw) Cc: zsh-workers On Tue, 5 Oct 2004 13:18:20 -0500 Dan Nelson <dnelson@allantgroup.com> wrote: > In the last episode (Oct 05), Matthias B. said: > > On Mon, 04 Oct 2004 17:10:47 +0100 Peter Stephenson <pws@csr.com> > > wrote: > > > Nathan Sidwell wrote: > > > > Zsh 4.0.4 appears to lose the time command in the following, > > > > > > > > nathan@garibaldi:363>for i in 1 2 ; time echo > > > > > > > > but, place the command in a subshell, and it works. > > > > > > Yes, that's always been an annoying limitation: "time" works by > > > gettings system information about subprocesses, and there isn't one > > > in this case. > > > > Then how does bash do it? bash can time builtins just fine. > > It probably calls getrusage(RUSAGE_SELF) before and after whatever > you're timing, then prints the deltas. Then maybe zsh should do that, too. Right now, zsh's time function doesn't work very well. Look at this: /home/msb> TIMEFMT=$'real\t%*Es\nuser\t%*Us\nsys \t%*Ss\ncpu \t%P' /home/msb> time /bin/echo foo foo real 0.000s user 0.000s sys 0.010s cpu 8695% /home/msb> time /bin/echo foo foo real 0.006s user 0.000s sys 0.000s cpu 0% /home/msb> time /bin/echo foo foo real 0.000s user 0.010s sys 0.000s cpu 8928% The numbers don't add up properly. I've never seen something like this with bash. MSB -- Happiness through ignorance! ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: bug with for and time 2004-10-06 11:48 ` Matthias B. @ 2004-10-06 12:52 ` Nikolai Weibull 2004-10-06 17:06 ` Peter Stephenson 1 sibling, 0 replies; 12+ messages in thread From: Nikolai Weibull @ 2004-10-06 12:52 UTC (permalink / raw) To: zsh-workers * Matthias B. <msbREMOVE-THIS@winterdrache.de> [Oct 06, 2004 13:50]: > /home/msb> time /bin/echo foo > foo > real 0.000s > user 0.010s > sys 0.000s > cpu 8928% I can beat that: regex '(a|aa)*' aaa: real: 0.000 user: 0.020 system: 0.000 (50000%) is what I got when executing a test program for my regular expression engine, nikolai -- ::: name: Nikolai Weibull :: aliases: pcp / lone-star / aka ::: ::: born: Chicago, IL USA :: loc atm: Gothenburg, Sweden ::: ::: page: www.pcppopper.org :: fun atm: gf,lps,ruby,lisp,war3 ::: main(){printf(&linux["\021%six\012\0"],(linux)["have"]+"fun"-97);} ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: bug with for and time 2004-10-06 11:48 ` Matthias B. 2004-10-06 12:52 ` Nikolai Weibull @ 2004-10-06 17:06 ` Peter Stephenson 2004-10-06 17:53 ` Dan Nelson 1 sibling, 1 reply; 12+ messages in thread From: Peter Stephenson @ 2004-10-06 17:06 UTC (permalink / raw) To: zsh-workers > Then maybe zsh should do that, too. Right now, zsh's time function doesn't > work very well. Look at this: > > /home/msb> TIMEFMT=$'real\t%*Es\nuser\t%*Us\nsys \t%*Ss\ncpu \t%P' > /home/msb> time /bin/echo foo > foo > real 0.000s > user 0.000s > sys 0.010s > cpu 8695% This has never been great. There appear to be two problems. First, zsh is using times() instead of getrusage(). The former has much worse resolution, typically only 100th of second (probably the case here). Second, zsh's "real" time is taken by measuring the time till the process is harvested, but starting *after* the fork in the parent process. This can make a big difference, given that the fork can include arbitrary amounts of real time starting off the child process. The following tries to address both problems. It's basically working, but there could easily be glitches. There are a couple of places where the shell calls fork() instead of zfork() (which I've commented). It would make the code simpler to use zfork() owing to the gettimeofday() call I've embedded in that. I suspect that's OK to do (apart from fixing up redundant error messages), but I haven't looked closely enough yet. This doesn't do anything for builtins. Last I looked the code structure didn't make that too easy. Index: configure.ac =================================================================== RCS file: /cvsroot/zsh/zsh/configure.ac,v retrieving revision 1.19 diff -u -r1.19 configure.ac --- configure.ac 30 Jul 2004 11:09:17 -0000 1.19 +++ configure.ac 6 Oct 2004 16:57:27 -0000 @@ -1043,7 +1043,7 @@ initgroups nis_list \ setuid seteuid setreuid setresuid setsid \ memcpy memmove strstr strerror \ - getrlimit \ + getrlimit getrusage \ setlocale \ uname \ signgam \ Index: Src/exec.c =================================================================== RCS file: /cvsroot/zsh/zsh/Src/exec.c,v retrieving revision 1.72 diff -u -r1.72 exec.c --- Src/exec.c 5 Oct 2004 10:39:43 -0000 1.72 +++ Src/exec.c 6 Oct 2004 16:57:30 -0000 @@ -212,9 +212,10 @@ /**/ static pid_t -zfork(void) +zfork(struct timeval *tv) { pid_t pid; + struct timezone dummy_tz; /* * Is anybody willing to explain this test? @@ -223,6 +224,8 @@ zerr("job table full", NULL, 0); return -1; } + if (tv) + gettimeofday(tv, &dummy_tz); pid = fork(); if (pid == -1) { zerr("fork failed: %e", NULL, errno); @@ -313,6 +316,7 @@ int list_pipe = 0, simple_pline = 0; static pid_t list_pipe_pid; +static struct timeval list_pipe_start; static int nowait, pline_level = 0; static int list_pipe_child = 0, list_pipe_job; static char list_pipe_text[JOBTEXTSIZE]; @@ -1101,7 +1105,8 @@ curjob = newjob; DPUTS(!list_pipe_pid, "invalid list_pipe_pid"); - addproc(list_pipe_pid, list_pipe_text, 0); + addproc(list_pipe_pid, list_pipe_text, 0, + &list_pipe_start); /* If the super-job contains only the sub-shell, the sub-shell is the group leader. */ @@ -1157,9 +1162,13 @@ (jobtab[list_pipe_job].stat & STAT_STOPPED)))) { pid_t pid; int synch[2]; + struct timezone dummy_tz; + struct timeval bgtime; pipe(synch); + gettimeofday(&bgtime, &dummy_tz); + /* Any reason this isn't zfork? */ if ((pid = fork()) == -1) { trashzle(); close(synch[0]); @@ -1177,6 +1186,7 @@ lpforked = (killpg(jobtab[list_pipe_job].gleader, 0) == -1 ? 2 : 1); list_pipe_pid = pid; + list_pipe_start = bgtime; nowait = errflag = 1; breaks = loops; close(synch[1]); @@ -1289,8 +1299,12 @@ * rest of the pipeline in the current shell. */ if (wc_code(code) >= WC_CURSH && (how & Z_SYNC)) { int synch[2]; + struct timeval bgtime; + struct timezone dummy_tz; pipe(synch); + gettimeofday(&bgtime, &dummy_tz); + /* any reason this isn't zfork? */ if ((pid = fork()) == -1) { close(synch[0]); close(synch[1]); @@ -1299,7 +1313,7 @@ char dummy, *text; text = getjobtext(state->prog, state->pc); - addproc(pid, text, 0); + addproc(pid, text, 0, &bgtime); close(synch[1]); read(synch[0], &dummy, 1); close(synch[0]); @@ -1437,8 +1451,9 @@ char buf[TCBUFSIZE]; int len, i; pid_t pid; + struct timeval bgtime; - if ((pid = zfork())) { + if ((pid = zfork(&bgtime))) { for (i = 0; i < mn->ct; i++) zclose(mn->fds[i]); zclose(mn->pipe); @@ -1448,7 +1463,7 @@ } mn->ct = 1; mn->fds[0] = fd; - addproc(pid, NULL, 1); + addproc(pid, NULL, 1, &bgtime); return; } /* pid == 0 */ @@ -2108,11 +2123,12 @@ pid_t pid; int synch[2]; char dummy; + struct timeval bgtime; child_block(); pipe(synch); - if ((pid = zfork()) == -1) { + if ((pid = zfork(&bgtime)) == -1) { close(synch[0]); close(synch[1]); opts[AUTOCONTINUE] = oautocont; @@ -2140,7 +2156,7 @@ 3 : WC_ASSIGN_NUM(ac) + 2); } } - addproc(pid, text, 0); + addproc(pid, text, 0, &bgtime); opts[AUTOCONTINUE] = oautocont; return; } @@ -2697,7 +2713,7 @@ zleactive = 0; if (cl) clearjobtab(monitor); - times(&shtms); + get_usage(); forklevel = locallevel; } @@ -2843,7 +2859,7 @@ mpipe(pipes); child_block(); cmdoutval = 0; - if ((cmdoutpid = pid = zfork()) == -1) { + if ((cmdoutpid = pid = zfork(NULL)) == -1) { /* fork error */ zclose(pipes[0]); zclose(pipes[1]); @@ -2979,7 +2995,7 @@ child_block(); fd = open(nam, O_WRONLY | O_CREAT | O_EXCL | O_NOCTTY, 0600); - if (fd < 0 || (cmdoutpid = pid = zfork()) == -1) { + if (fd < 0 || (cmdoutpid = pid = zfork(NULL)) == -1) { /* fork or open error */ child_unblock(); return nam; @@ -3040,6 +3056,7 @@ int out = *cmd == Inang; char *pnam; pid_t pid; + struct timeval bgtime; #ifndef PATH_DEV_FD int fd; @@ -3054,11 +3071,11 @@ jobtab[thisjob].filelist = znewlinklist(); zaddlinknode(jobtab[thisjob].filelist, ztrdup(pnam)); - if ((pid = zfork())) { + if ((pid = zfork(&bgtime))) { if (pid == -1) return NULL; if (!out) - addproc(pid, NULL, 1); + addproc(pid, NULL, 1, &bgtime); return pnam; } closem(0); @@ -3078,7 +3095,7 @@ if (!(prog = parsecmd(cmd))) return NULL; mpipe(pipes); - if ((pid = zfork())) { + if ((pid = zfork(&bgtime))) { sprintf(pnam, "%s/%d", PATH_DEV_FD, pipes[!out]); zclose(pipes[out]); if (pid == -1) @@ -3089,7 +3106,7 @@ fdtable[pipes[!out]] = 2; if (!out) { - addproc(pid, NULL, 1); + addproc(pid, NULL, 1, &bgtime); } return pnam; } @@ -3116,17 +3133,18 @@ Eprog prog; int pipes[2], out = *cmd == Inang; pid_t pid; + struct timeval bgtime; if (!(prog = parsecmd(cmd))) return -1; mpipe(pipes); - if ((pid = zfork())) { + if ((pid = zfork(&bgtime))) { zclose(pipes[out]); if (pid == -1) { zclose(pipes[!out]); return -1; } - addproc(pid, NULL, 1); + addproc(pid, NULL, 1, &bgtime); return pipes[!out]; } entersubsh(Z_ASYNC, 1, 0, 0); Index: Src/init.c =================================================================== RCS file: /cvsroot/zsh/zsh/Src/init.c,v retrieving revision 1.44 diff -u -r1.44 init.c --- Src/init.c 20 Sep 2004 13:37:41 -0000 1.44 +++ Src/init.c 6 Oct 2004 16:57:30 -0000 @@ -856,7 +856,7 @@ #endif } - times(&shtms); + get_usage(); /* Close the file descriptors we opened to block off 0 to 9 */ for (i = 0; i < 10; i++) Index: Src/jobs.c =================================================================== RCS file: /cvsroot/zsh/zsh/Src/jobs.c,v retrieving revision 1.31 diff -u -r1.31 jobs.c --- Src/jobs.c 2 Jun 2004 22:14:26 -0000 1.31 +++ Src/jobs.c 6 Oct 2004 16:57:31 -0000 @@ -80,7 +80,15 @@ /* shell timings */ /**/ -struct tms shtms; +#ifdef HAVE_GETRUSAGE +/**/ +static struct rusage child_usage; +/**/ +#else +/**/ +static struct tms shtms; +/**/ +#endif /* 1 if ttyctl -f has been executed */ @@ -93,8 +101,6 @@ /**/ int prev_errflag, prev_breaks, errbrk_saved; -static struct timeval dtimeval, now; - /**/ int numpipestats, pipestats[MAX_PIPESTATS]; @@ -250,6 +256,21 @@ return 0; } + +/* Get the latest usage information */ + +/**/ +void +get_usage(void) +{ +#ifdef HAVE_GETRUSAGE + getrusage(RUSAGE_CHILDREN, &child_usage); +#else + times(shtms); +#endif +} + + /* Update status of process that we have just WAIT'ed for */ /**/ @@ -257,17 +278,31 @@ update_process(Process pn, int status) { struct timezone dummy_tz; +#ifdef HAVE_GETRUSAGE + struct timeval childs, childu; +#else long childs, childu; +#endif +#ifdef HAVE_GETRUSAGE + childs = child_usage.ru_stime; + childu = child_usage.ru_utime; +#else childs = shtms.tms_cstime; childu = shtms.tms_cutime; - times(&shtms); /* get time-accounting info */ +#endif + /* get time-accounting info */ + get_usage(); + gettimeofday(&pn->endtime, &dummy_tz); /* record time process exited */ pn->status = status; /* save the status returned by WAIT */ +#ifdef HAVE_GETRUSAGE + dtime(&pn->ti.sys, &childs, &child_usage.ru_stime); + dtime(&pn->ti.usr, &childu, &child_usage.ru_utime); +#else pn->ti.st = shtms.tms_cstime - childs; /* compute process system space time */ pn->ti.ut = shtms.tms_cutime - childu; /* compute process user space time */ - - gettimeofday(&pn->endtime, &dummy_tz); /* record time process exited */ +#endif } /* Update status of job, possibly printing it */ @@ -473,6 +508,8 @@ prevjob = -1; } +/**/ +#ifndef HAVE_GETRUSAGE static long clktck = 0; /**/ @@ -501,6 +538,8 @@ # endif #endif } +/**/ +#endif /**/ static void @@ -519,9 +558,8 @@ fprintf(stderr, "%.3f", secs); } -/**/ static void -printtime(struct timeval *real, struct timeinfo *ti, char *desc) +printtime(struct timeval *real, child_times_t *ti, char *desc) { char *s; double elapsed_time, user_time, system_time; @@ -530,13 +568,21 @@ if (!desc) desc = ""; - set_clktck(); /* go ahead and compute these, since almost every TIMEFMT will have them */ elapsed_time = real->tv_sec + real->tv_usec / 1000000.0; + +#ifdef HAVE_GETRUSAGE + user_time = ti->usr.tv_sec + ti->usr.tv_usec / 1000000.0; + system_time = ti->sys.tv_sec + ti->sys.tv_usec / 1000000.0; + percent = 100.0 * (user_time + system_time) + / (real->tv_sec + real->tv_usec / 1000000.0); +#else + set_clktck(); 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); +#endif queue_signals(); if (!(s = getsparam("TIMEFMT"))) @@ -598,11 +644,13 @@ dumptime(Job jn) { Process pn; + struct timeval dtimeval; if (!jn->procs) return; for (pn = jn->procs; pn; pn = pn->next) - printtime(dtime(&dtimeval, &pn->bgtime, &pn->endtime), &pn->ti, pn->text); + printtime(dtime(&dtimeval, &pn->bgtime, &pn->endtime), &pn->ti, + pn->text); } /* Check whether shell should report the amount of time consumed * @@ -617,7 +665,7 @@ struct value vbuf; Value v; char *s = "REPORTTIME"; - int reporttime; + zlong reporttime; /* if the time keyword was used */ if (j->stat & STAT_TIMED) @@ -634,8 +682,15 @@ if (!j->procs) return 0; +#ifdef HAVE_GETRUSAGE + reporttime -= j->procs->ti.usr.tv_sec + j->procs->ti.sys.tv_sec; + if (j->procs->ti.usr.tv_usec + j->procs->ti.sys.tv_usec >= 1000000) + reporttime--; + return reporttime <= 0; +#else set_clktck(); return ((j->procs->ti.ut + j->procs->ti.st) / clktck >= reporttime); +#endif } /* !(lng & 3) means jobs * @@ -899,10 +954,9 @@ /**/ void -addproc(pid_t pid, char *text, int aux) +addproc(pid_t pid, char *text, int aux, struct timeval *bgtime) { Process pn, *pnlist; - struct timezone dummy_tz; DPUTS(thisjob == -1, "No valid job in addproc."); pn = (Process) zshcalloc(sizeof *pn); @@ -916,7 +970,7 @@ if (!aux) { - gettimeofday(&pn->bgtime, &dummy_tz); + pn->bgtime = *bgtime; /* if this is the first process we are adding to * * the job, then it's the group leader. */ if (!jobtab[thisjob].gleader) @@ -1158,18 +1212,40 @@ void shelltime(void) { - struct timeinfo ti; struct timezone dummy_tz; + struct timeval dtimeval, now; +#ifdef HAVE_GETRUSAGE + struct rusage ru; + child_times_t ti; +#else + struct timeinfo ti; struct tms buf; +#endif + + gettimeofday(&now, &dummy_tz); +#ifdef HAVE_GETRUSAGE + getrusage(RUSAGE_SELF, &ru); + ti.sys = ru.ru_stime; + ti.usr = ru.ru_utime; +#else times(&buf); + ti.ut = buf.tms_utime; ti.st = buf.tms_stime; - gettimeofday(&now, &dummy_tz); +#endif printtime(dtime(&dtimeval, &shtimer, &now), &ti, "shell"); + +#ifdef HAVE_GETRUSAGE + getrusage(RUSAGE_CHILDREN, &ru); + ti.sys = ru.ru_stime; + ti.usr = ru.ru_utime; +#else ti.ut = buf.tms_cutime; ti.st = buf.tms_cstime; - printtime(dtime(&dtimeval, &shtimer, &now), &ti, "children"); +#endif + printtime(&dtimeval, &ti, "children"); + } /* see if jobs need printing */ Index: Src/signals.c =================================================================== RCS file: /cvsroot/zsh/zsh/Src/signals.c,v retrieving revision 1.30 diff -u -r1.30 signals.c --- Src/signals.c 29 Jul 2004 15:09:51 -0000 1.30 +++ Src/signals.c 6 Oct 2004 16:57:31 -0000 @@ -484,7 +484,7 @@ *procsubval = (0200 | WTERMSIG(status)); else *procsubval = WEXITSTATUS(status); - times(&shtms); + get_usage(); goto cont; } if (!es) @@ -514,7 +514,7 @@ * children in sub processes anyway: otherwise, this * will get added on to the next found process that terminates. */ - times(&shtms); + get_usage(); } } break; Index: Src/zsh.h =================================================================== RCS file: /cvsroot/zsh/zsh/Src/zsh.h,v retrieving revision 1.62 diff -u -r1.62 zsh.h --- Src/zsh.h 1 Oct 2004 19:10:59 -0000 1.62 +++ Src/zsh.h 6 Oct 2004 16:57:32 -0000 @@ -739,12 +739,21 @@ /* node in job process lists */ +#ifdef HAVE_GETRUSAGE +typedef struct { + struct timeval sys; + struct timeval usr; +} child_times_t; +#else +typedef struct timeinfo child_times_t; +#endif + struct process { struct process *next; pid_t pid; /* process id */ char text[JOBTEXTSIZE]; /* text to print when 'jobs' is run */ int status; /* return code from waitpid/wait3() */ - struct timeinfo ti; + child_times_t ti; struct timeval bgtime; /* time job was spawned */ struct timeval endtime; /* time job exited */ }; -- Peter Stephenson <pws@csr.com> Software Engineer CSR Ltd., Science Park, Milton Road, Cambridge, CB4 0WH, UK Tel: +44 (0)1223 692070 ********************************************************************** This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This footnote also confirms that this email message has been swept by MIMEsweeper for the presence of computer viruses. www.mimesweeper.com ********************************************************************** ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: bug with for and time 2004-10-06 17:06 ` Peter Stephenson @ 2004-10-06 17:53 ` Dan Nelson 2004-10-07 9:37 ` Peter Stephenson 0 siblings, 1 reply; 12+ messages in thread From: Dan Nelson @ 2004-10-06 17:53 UTC (permalink / raw) To: Peter Stephenson; +Cc: zsh-workers In the last episode (Oct 06), Peter Stephenson said: > This has never been great. There appear to be two problems. Actually it _was_ great back in zsh 2.5, which did use getrusage(). It was dropped in zsh 3.0 for some reason. My TIMEFMT is still set to "U:%U S:%S E:%E CPU:%P Faults:%F Swaps:%W" as a reminder to put it back in (not a very effective reminder I guess). > The following tries to address both problems. It's basically working, > but there could easily be glitches. Bonus points for anyone who adds back the extra TIMEFMT options too. -- Dan Nelson dnelson@allantgroup.com ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: bug with for and time 2004-10-06 17:53 ` Dan Nelson @ 2004-10-07 9:37 ` Peter Stephenson 2004-10-07 15:25 ` Dan Nelson 0 siblings, 1 reply; 12+ messages in thread From: Peter Stephenson @ 2004-10-07 9:37 UTC (permalink / raw) To: zsh-workers Dan Nelson wrote: > In the last episode (Oct 06), Peter Stephenson said: > > This has never been great. There appear to be two problems. > > Actually it _was_ great back in zsh 2.5, which did use getrusage(). It > was dropped in zsh 3.0 for some reason. My TIMEFMT is still set to > "U:%U S:%S E:%E CPU:%P Faults:%F Swaps:%W" as a reminder to put it back > in (not a very effective reminder I guess). I can vaguely remember that the getrusage() fields which didn't correspond to times were dropped when we switched to autoconf, simply because it became hard to test for all the fields. I didn't notice getrusage() disappearing entirely then, but it certainly must have at some point. I suppose this will give us a base for putting them back, with suitable configuration tests. Here's what we're aiming at (from 2.5.03): TIMEFMT The format of process time reports with the time keyword. The default is "%E real %U user %S system %P %J". Recognizes the following escape sequences: %U CPU seconds spent in user mode. %S CPU seconds spent in kernel mode. %E Elapsed time in seconds. %P The CPU percentage, computed as (%U+%S)/%E. %W Number of times the process was swapped. %X The average amount in (shared) text space used in Kbytes. %D The average amount in (unshared) data/stack space used in Kbytes. %K The total space used (%X+%D) in Kbytes. %M The maximum memory the process had in use at any time in Kbytes. %F The number of major page faults (page needed to be brought from disk). %R The number of minor page faults. %I The number of input operations. %O The number of output operations. %r The number of socket messages received. %s The number of socket messages sent. %k The number of signals received. %w Number of voluntary context switches (waits). %c Number of involuntary context switches. %J The name of this job. -- Peter Stephenson <pws@csr.com> Software Engineer CSR Ltd., Science Park, Milton Road, Cambridge, CB4 0WH, UK Tel: +44 (0)1223 692070 ********************************************************************** This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This footnote also confirms that this email message has been swept by MIMEsweeper for the presence of computer viruses. www.mimesweeper.com ********************************************************************** ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: bug with for and time 2004-10-07 9:37 ` Peter Stephenson @ 2004-10-07 15:25 ` Dan Nelson 2004-10-08 13:14 ` Peter Stephenson 0 siblings, 1 reply; 12+ messages in thread From: Dan Nelson @ 2004-10-07 15:25 UTC (permalink / raw) To: Peter Stephenson; +Cc: zsh-workers In the last episode (Oct 07), Peter Stephenson said: > I can vaguely remember that the getrusage() fields which didn't > correspond to times were dropped when we switched to autoconf, simply > because it became hard to test for all the fields. I didn't notice > getrusage() disappearing entirely then, but it certainly must have at > some point. I did some mailinglist searches, and back in 1999, workers-2526 says that getrusage was removed because it wasn't POSIX and the autoconf test was too complex. It is now, though, and was in SUS as far back as 1997. Unfortunately, only two struct members are defined: struct timeval ru_utime User time used. struct timeval ru_stime System time used. Fortunately, the remaining members defined by AIX, FreeBSD, Linux, Solaris, and Tru64 are identical. Solaris doesn't fill in ru_ixrss or ru_isrss (%X and %D), but they are in the struct. Testing for each member individually if you wanted to wouldn't be hard, anyway. One AC_CHECK_MEMBERS call with 14 arguments is all that's needed, plus the appropriate #if defined checks around each resource in the TIMEFMT expansion code. -- Dan Nelson dnelson@allantgroup.com ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: bug with for and time 2004-10-07 15:25 ` Dan Nelson @ 2004-10-08 13:14 ` Peter Stephenson 2004-10-08 14:18 ` Peter Stephenson 0 siblings, 1 reply; 12+ messages in thread From: Peter Stephenson @ 2004-10-08 13:14 UTC (permalink / raw) To: zsh-workers Dan Nelson wrote: > I did some mailinglist searches, and back in 1999, workers-2526 says > that getrusage was removed because it wasn't POSIX and the autoconf > test was too complex. There's another issue... we used to get the usage for a child by calling wait3(), which can set a struct rusage. (Modern systems have wait4, which allows you to wait for a particular PID, but it looks like we don't actually use that anyway.) However, this isn't part of the latest standards. So the only standardised way of doing it is to call getrusage and subtract all appropriate elements. With some (maximum value), you can't actually tell for sure whether it's applicable to the last child or not. Maybe we should prefer wait3(), which is widely available, and do the best we can elsewhere, but it's not ideal. Still, both wait3() and the additional rusage elements came from BSD; maybe I can rely on either both or neither being available and skip the case where we can't tie usage to individual processes. > One AC_CHECK_MEMBERS call with 14 arguments is all that's needed, plus the > appropriate #if defined checks around each resource in the TIMEFMT > expansion code. This bit I can easily get working. -- Peter Stephenson <pws@csr.com> Software Engineer CSR Ltd., Science Park, Milton Road, Cambridge, CB4 0WH, UK Tel: +44 (0)1223 692070 ********************************************************************** This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This footnote also confirms that this email message has been swept by MIMEsweeper for the presence of computer viruses. www.mimesweeper.com ********************************************************************** ^ permalink raw reply [flat|nested] 12+ messages in thread
* Re: bug with for and time 2004-10-08 13:14 ` Peter Stephenson @ 2004-10-08 14:18 ` Peter Stephenson 0 siblings, 0 replies; 12+ messages in thread From: Peter Stephenson @ 2004-10-08 14:18 UTC (permalink / raw) To: zsh-workers Peter Stephenson wrote: > Still, both wait3() and the > additional rusage elements came from BSD; maybe I can rely on either > both or neither being available and skip the case where we can't tie > usage to individual processes. This is what I've done. I'm not sure doing anything else is necessary or sensible. Enjoy. I replaced the fork()s with zfork()s as threatened. As far as I can see, the only issue is error messages, and they're not very common errors. They should still print something sensible. Index: configure.ac =================================================================== RCS file: /cvsroot/zsh/zsh/configure.ac,v retrieving revision 1.20 diff -u -r1.20 configure.ac --- configure.ac 7 Oct 2004 09:45:43 -0000 1.20 +++ configure.ac 8 Oct 2004 14:13:15 -0000 @@ -1448,6 +1448,32 @@ dnl -------------------------------------------- +dnl Check for members of struct rusage +dnl -------------------------------------------- +if test $ac_cv_func_getrusage = yes; then + AC_CHECK_MEMBERS([struct rusage.ru_maxrss, + struct rusage.ru_ixrss, + struct rusage.ru_idrss, + struct rusage.ru_isrss, + struct rusage.ru_minflt, + struct rusage.ru_majflt, + struct rusage.ru_nswap, + struct rusage.ru_inblock, + struct rusage.ru_oublock, + struct rusage.ru_msgsnd, + struct rusage.ru_msgrcv, + struct rusage.ru_nsignals, + struct rusage.ru_nvcsw, + struct rusage.ru_nivcsw],,, +[#include <sys/types.h> +#ifdef HAVE_SYS_TIME_H +#include <sys/time.h> +#endif +#include <sys/resource.h>]) +fi + + +dnl -------------------------------------------- dnl CHECK FOR DEFAULT PATH (used for command -p) dnl -------------------------------------------- AC_CACHE_VAL(zsh_cv_cs_path, Index: Doc/Zsh/params.yo =================================================================== RCS file: /cvsroot/zsh/zsh/Doc/Zsh/params.yo,v retrieving revision 1.22 diff -u -r1.22 params.yo --- Doc/Zsh/params.yo 22 Jun 2004 13:10:02 -0000 1.22 +++ Doc/Zsh/params.yo 8 Oct 2004 14:13:18 -0000 @@ -1047,7 +1047,9 @@ item(tt(TIMEFMT))( The format of process time reports with the tt(time) keyword. The default is `tt(%E real %U user %S system %P %J)'. -Recognizes the following escape sequences: +Recognizes the following escape sequences, although not all +may be available on all systems, and some that are available +may not be useful: startsitem() sitem(tt(%%))(A `tt(%)'.) @@ -1055,6 +1057,23 @@ sitem(tt(%S))(CPU seconds spent in kernel mode.) sitem(tt(%E))(Elapsed time in seconds.) sitem(tt(%P))(The CPU percentage, computed as (tt(%U)PLUS()tt(%S))/tt(%E).) +sitem(tt(%W))(Number of times the process was swapped.) +sitem(tt(%X))(The average amount in (shared) text space used in Kbytes.) +sitem(tt(%D))(The average amount in (unshared) data/stack space used in +Kbytes.) +sitem(tt(%K))(The total space used (%X+%D) in Kbytes.) +sitem(tt(%M))(The maximum memory the process had in use at any time in +Kbytes.) +sitem(tt(%F))(The number of major page faults (page needed to be brought +from disk).) +sitem(tt(%R))(The number of minor page faults.) +sitem(tt(%I))(The number of input operations.) +sitem(tt(%O))(The number of output operations.) +sitem(tt(%r))(The number of socket messages received.) +sitem(tt(%s))(The number of socket messages sent.) +sitem(tt(%k))(The number of signals received.) +sitem(tt(%w))(Number of voluntary context switches (waits).) +sitem(tt(%c))(Number of involuntary context switches.) sitem(tt(%J))(The name of this job.) endsitem() Index: Src/exec.c =================================================================== RCS file: /cvsroot/zsh/zsh/Src/exec.c,v retrieving revision 1.73 diff -u -r1.73 exec.c --- Src/exec.c 7 Oct 2004 09:45:46 -0000 1.73 +++ Src/exec.c 8 Oct 2004 14:13:25 -0000 @@ -1162,18 +1162,14 @@ (jobtab[list_pipe_job].stat & STAT_STOPPED)))) { pid_t pid; int synch[2]; - struct timezone dummy_tz; struct timeval bgtime; pipe(synch); - gettimeofday(&bgtime, &dummy_tz); - /* Any reason this isn't zfork? */ - if ((pid = fork()) == -1) { + if ((pid = zfork(&bgtime)) == -1) { trashzle(); close(synch[0]); close(synch[1]); - putc('\n', stderr); fprintf(stderr, "zsh: job can't be suspended\n"); fflush(stderr); makerunning(jn); @@ -1300,15 +1296,11 @@ if (wc_code(code) >= WC_CURSH && (how & Z_SYNC)) { int synch[2]; struct timeval bgtime; - struct timezone dummy_tz; pipe(synch); - gettimeofday(&bgtime, &dummy_tz); - /* any reason this isn't zfork? */ - if ((pid = fork()) == -1) { + if ((pid = zfork(&bgtime)) == -1) { close(synch[0]); close(synch[1]); - zerr("fork failed: %e", NULL, errno); } else if (pid) { char dummy, *text; Index: Src/jobs.c =================================================================== RCS file: /cvsroot/zsh/zsh/Src/jobs.c,v retrieving revision 1.32 diff -u -r1.32 jobs.c --- Src/jobs.c 7 Oct 2004 09:45:46 -0000 1.32 +++ Src/jobs.c 8 Oct 2004 14:13:28 -0000 @@ -271,6 +271,7 @@ } +#ifndef HAVE_GETRUSAGE /* Update status of process that we have just WAIT'ed for */ /**/ @@ -278,32 +279,19 @@ update_process(Process pn, int status) { struct timezone dummy_tz; -#ifdef HAVE_GETRUSAGE - struct timeval childs, childu; -#else long childs, childu; -#endif -#ifdef HAVE_GETRUSAGE - childs = child_usage.ru_stime; - childu = child_usage.ru_utime; -#else childs = shtms.tms_cstime; childu = shtms.tms_cutime; -#endif /* get time-accounting info */ get_usage(); gettimeofday(&pn->endtime, &dummy_tz); /* record time process exited */ pn->status = status; /* save the status returned by WAIT */ -#ifdef HAVE_GETRUSAGE - dtime(&pn->ti.sys, &childs, &child_usage.ru_stime); - dtime(&pn->ti.usr, &childu, &child_usage.ru_utime); -#else pn->ti.st = shtms.tms_cstime - childs; /* compute process system space time */ pn->ti.ut = shtms.tms_cutime - childu; /* compute process user space time */ -#endif } +#endif /* Update status of job, possibly printing it */ @@ -563,6 +551,9 @@ { char *s; double elapsed_time, user_time, system_time; +#ifdef HAVE_GETRUSAGE + double total_time; +#endif int percent; if (!desc) @@ -572,10 +563,11 @@ elapsed_time = real->tv_sec + real->tv_usec / 1000000.0; #ifdef HAVE_GETRUSAGE - user_time = ti->usr.tv_sec + ti->usr.tv_usec / 1000000.0; - system_time = ti->sys.tv_sec + ti->sys.tv_usec / 1000000.0; + user_time = ti->ru_utime.tv_sec + ti->ru_utime.tv_usec / 1000000.0; + system_time = ti->ru_stime.tv_sec + ti->ru_stime.tv_usec / 1000000.0; percent = 100.0 * (user_time + system_time) / (real->tv_sec + real->tv_usec / 1000000.0); + total_time = user_time + system_time; #else set_clktck(); user_time = ti->ut / (double) clktck; @@ -620,6 +612,97 @@ case 'P': fprintf(stderr, "%d%%", percent); break; +#ifdef HAVE_STRUCT_RUSAGE_RU_NSWAP + case 'W': + fprintf(stderr, "%ld", ti->ru_nswap); + break; +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_IXRSS + case 'X': + fprintf(stderr, "%ld", (long)(ti->ru_ixrss / total_time)); + break; +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_IDRSS + case 'D': + fprintf(stderr, "%ld", + (long) ((ti->ru_idrss +#ifdef HAVE_STRUCT_RUSAGE_RU_ISRSS + + ti->ru_isrss +#endif + ) / total_time)); + break; +#endif +#if defined(HAVE_STRUCT_RUSAGE_RU_IDRSS) || \ + defined(HAVE_STRUCT_RUSAGE_RU_ISRSS) || \ + defined(HAVE_STRUCT_RUSAGE_RU_IXRSS) + case 'K': + /* treat as D if X not available */ + fprintf(stderr, "%ld", + (long) (( +#ifdef HAVE_STRUCT_RUSAGE_RU_IXRSS + ti->ru_ixrss +#else + 0 +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_IDRSS + + ti->ru_idrss +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_ISRSS + + ti->ru_isrss +#endif + ) / total_time)); + break; +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_MAXRSS + case 'M': + fprintf(stderr, "%ld", ti->ru_maxrss / 1024); + break; +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_MAJFLT + case 'F': + fprintf(stderr, "%ld", ti->ru_majflt); + break; +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_MINFLT + case 'R': + fprintf(stderr, "%ld", ti->ru_minflt); + break; +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_INBLOCK + case 'I': + fprintf(stderr, "%ld", ti->ru_inblock); + break; +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_OUBLOCK + case 'O': + fprintf(stderr, "%ld", ti->ru_oublock); + break; +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_MSGRCV + case 'r': + fprintf(stderr, "%ld", ti->ru_msgrcv); + break; +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_MSGSND + case 's': + fprintf(stderr, "%ld", ti->ru_msgsnd); + break; +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_NSIGNALS + case 'k': + fprintf(stderr, "%ld", ti->ru_nsignals); + break; +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_NVCSW + case 'w': + fprintf(stderr, "%ld", ti->ru_nvcsw); + break; +#endif +#ifdef HAVE_STRUCT_RUSAGE_RU_NIVCSW + case 'c': + fprintf(stderr, "%ld", ti->ru_nivcsw); + break; +#endif case 'J': fprintf(stderr, "%s", desc); break; @@ -683,8 +766,9 @@ return 0; #ifdef HAVE_GETRUSAGE - reporttime -= j->procs->ti.usr.tv_sec + j->procs->ti.sys.tv_sec; - if (j->procs->ti.usr.tv_usec + j->procs->ti.sys.tv_usec >= 1000000) + reporttime -= j->procs->ti.ru_utime.tv_sec + j->procs->ti.ru_stime.tv_sec; + if (j->procs->ti.ru_utime.tv_usec + + j->procs->ti.ru_stime.tv_usec >= 1000000) reporttime--; return reporttime <= 0; #else @@ -1214,20 +1298,15 @@ { struct timezone dummy_tz; struct timeval dtimeval, now; -#ifdef HAVE_GETRUSAGE - struct rusage ru; child_times_t ti; -#else - struct timeinfo ti; +#ifndef HAVE_GETRUSAGE struct tms buf; #endif gettimeofday(&now, &dummy_tz); #ifdef HAVE_GETRUSAGE - getrusage(RUSAGE_SELF, &ru); - ti.sys = ru.ru_stime; - ti.usr = ru.ru_utime; + getrusage(RUSAGE_SELF, &ti); #else times(&buf); @@ -1237,9 +1316,7 @@ printtime(dtime(&dtimeval, &shtimer, &now), &ti, "shell"); #ifdef HAVE_GETRUSAGE - getrusage(RUSAGE_CHILDREN, &ru); - ti.sys = ru.ru_stime; - ti.usr = ru.ru_utime; + getrusage(RUSAGE_CHILDREN, &ti); #else ti.ut = buf.tms_cutime; ti.st = buf.tms_cstime; Index: Src/signals.c =================================================================== RCS file: /cvsroot/zsh/zsh/Src/signals.c,v retrieving revision 1.31 diff -u -r1.31 signals.c --- Src/signals.c 7 Oct 2004 09:45:46 -0000 1.31 +++ Src/signals.c 8 Oct 2004 14:13:31 -0000 @@ -400,18 +400,6 @@ return ret; } -/* What flavor of waitpid/wait3/wait shall we use? */ - -#ifdef HAVE_WAITPID -# define WAIT(pid, statusp, options) waitpid(pid, statusp, options) -#else -# ifdef HAVE_WAIT3 -# define WAIT(pid, statusp, options) wait3((void *) statusp, options, NULL) -# else -# define WAIT(pid, statusp, options) wait(statusp) -# endif -#endif - /* the signal handler */ /**/ @@ -471,7 +459,25 @@ int *procsubval = &cmdoutval; struct execstack *es = exstack; - pid = WAIT(-1, &status, WNOHANG|WUNTRACED); /* reap the child process */ + /* + * Reap the child process. + * If we want usage information, we need to use wait3. + */ +#ifdef HAVE_WAIT3 +# ifdef HAVE_GETRUSAGE + struct rusage ru; + + pid = wait3((void *)&status, WNOHANG|WUNTRACED, &ru); +# else + pid = wait3((void *)&status, WNOHANG|WUNTRACED, NULL); +# endif +#else +# ifdef HAVE_WAITPID + pid = waitpid(-1, &status, WNOHANG|WUNTRACED); +# else + pid = wait(&status); +# endif +#endif if (!pid) /* no more children to reap */ break; @@ -504,7 +510,14 @@ /* Find the process and job containing this pid and update it. */ if (findproc(pid, &jn, &pn, 0)) { +#if defined(HAVE_WAIT3) && defined(HAVE_GETRUSAGE) + struct timezone dummy_tz; + gettimeofday(&pn->endtime, &dummy_tz); + pn->status = status; + pn->ti = ru; +#else update_process(pn, status); +#endif update_job(jn); } else if (findproc(pid, &jn, &pn, 1)) { pn->status = status; Index: Src/zsh.h =================================================================== RCS file: /cvsroot/zsh/zsh/Src/zsh.h,v retrieving revision 1.63 diff -u -r1.63 zsh.h --- Src/zsh.h 7 Oct 2004 09:45:46 -0000 1.63 +++ Src/zsh.h 8 Oct 2004 14:13:35 -0000 @@ -740,10 +740,7 @@ /* node in job process lists */ #ifdef HAVE_GETRUSAGE -typedef struct { - struct timeval sys; - struct timeval usr; -} child_times_t; +typedef struct rusage child_times_t; #else typedef struct timeinfo child_times_t; #endif -- Peter Stephenson <pws@csr.com> Software Engineer CSR Ltd., Science Park, Milton Road, Cambridge, CB4 0WH, UK Tel: +44 (0)1223 692070 ********************************************************************** This email and any files transmitted with it are confidential and intended solely for the use of the individual or entity to whom they are addressed. If you have received this email in error please notify the system manager. This footnote also confirms that this email message has been swept by MIMEsweeper for the presence of computer viruses. www.mimesweeper.com ********************************************************************** ^ permalink raw reply [flat|nested] 12+ messages in thread
end of thread, other threads:[~2004-10-08 14:20 UTC | newest] Thread overview: 12+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2004-10-04 15:31 bug with for and time Nathan Sidwell 2004-10-04 16:10 ` Peter Stephenson 2004-10-05 9:38 ` Matthias B. 2004-10-05 18:18 ` Dan Nelson 2004-10-06 11:48 ` Matthias B. 2004-10-06 12:52 ` Nikolai Weibull 2004-10-06 17:06 ` Peter Stephenson 2004-10-06 17:53 ` Dan Nelson 2004-10-07 9:37 ` Peter Stephenson 2004-10-07 15:25 ` Dan Nelson 2004-10-08 13:14 ` Peter Stephenson 2004-10-08 14:18 ` Peter Stephenson
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).