zsh-users
 help / color / mirror / code / Atom feed
* Timing function execution
@ 2021-11-06 12:11 Zach Riggle
  2021-11-06 16:15 ` Bart Schaefer
  0 siblings, 1 reply; 9+ messages in thread
From: Zach Riggle @ 2021-11-06 12:11 UTC (permalink / raw)
  To: Zsh Users

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

Hello again, all!

It looks like "time" is a reserved keyword, but it is not possible to use
"time" on shell functions (and /usr/bin/time cannot be used for obvious
reasons).

What is the appropriate way to benchmark / log the execution time of a
function?

    $ which -a time
    time: shell reserved word
    /usr/bin/time

    $ foo() { sleep 1; echo hello }

    $ foo
    hello

    $ time foo
    hello

*Zach Riggle*

[-- Attachment #2: Type: text/html, Size: 771 bytes --]

^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: Timing function execution
  2021-11-06 12:11 Timing function execution Zach Riggle
@ 2021-11-06 16:15 ` Bart Schaefer
  2021-11-06 16:21   ` Roman Perepelitsa
  0 siblings, 1 reply; 9+ messages in thread
From: Bart Schaefer @ 2021-11-06 16:15 UTC (permalink / raw)
  To: Zach Riggle; +Cc: Zsh Users

On Sat, Nov 6, 2021 at 5:11 AM Zach Riggle <zachriggle@gmail.com> wrote:
>
> What is the appropriate way to benchmark / log the execution time of a function?

"time" relies upon being able to use the OS-level profiling operations
on an external process.  Shell functions run in the current shell, so
there's no process to profile.  Consequently, in order to use "time"
you have to force the function to run in a subshell:

% time (foo)
hello
( foo; )  0.00s user 0.00s system 0% cpu 1.005 total

If all you need is the elapsed time, you can use $SECONDS.

% float SECONDS
% SECONDS=0; foo; print $SECONDS
hello
1.004018000e+00

(Saved almost 0.001 by not forking, I guess.)


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: Timing function execution
  2021-11-06 16:15 ` Bart Schaefer
@ 2021-11-06 16:21   ` Roman Perepelitsa
  2021-11-06 18:17     ` Bart Schaefer
  0 siblings, 1 reply; 9+ messages in thread
From: Roman Perepelitsa @ 2021-11-06 16:21 UTC (permalink / raw)
  To: Bart Schaefer; +Cc: Zach Riggle, Zsh Users

On Sat, Nov 6, 2021 at 5:16 PM Bart Schaefer <schaefer@brasslantern.com> wrote:
>
> On Sat, Nov 6, 2021 at 5:11 AM Zach Riggle <zachriggle@gmail.com> wrote:
> >
> > What is the appropriate way to benchmark / log the execution time of a function?
>
> "time" relies upon being able to use the OS-level profiling operations
> on an external process.  Shell functions run in the current shell, so
> there's no process to profile.

Could "time" invoke getrusage(RUSAGE_THREAD) before and after and
print the difference?

Roman.


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: Timing function execution
  2021-11-06 16:21   ` Roman Perepelitsa
@ 2021-11-06 18:17     ` Bart Schaefer
  2021-11-06 18:35       ` Bart Schaefer
  0 siblings, 1 reply; 9+ messages in thread
From: Bart Schaefer @ 2021-11-06 18:17 UTC (permalink / raw)
  To: Roman Perepelitsa; +Cc: Zach Riggle, Zsh Users

On Sat, Nov 6, 2021 at 9:21 AM Roman Perepelitsa
<roman.perepelitsa@gmail.com> wrote:
>
> Could "time" invoke getrusage(RUSAGE_THREAD) before and after and
> print the difference?

That's a possibility.  It'd only work on a subset of OSs, I think.


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: Timing function execution
  2021-11-06 18:17     ` Bart Schaefer
@ 2021-11-06 18:35       ` Bart Schaefer
  2021-11-06 18:40         ` Bart Schaefer
  0 siblings, 1 reply; 9+ messages in thread
From: Bart Schaefer @ 2021-11-06 18:35 UTC (permalink / raw)
  To: Roman Perepelitsa; +Cc: Zach Riggle, Zsh Users

On Sat, Nov 6, 2021 at 11:17 AM Bart Schaefer <schaefer@brasslantern.com> wrote:
>
> On Sat, Nov 6, 2021 at 9:21 AM Roman Perepelitsa
> <roman.perepelitsa@gmail.com> wrote:
> >
> > Could "time" invoke getrusage(RUSAGE_THREAD) before and after and
> > print the difference?
>
> That's a possibility.  It'd only work on a subset of OSs, I think.

Glancing through builtin.c, "times" (based on library times(3)) may be
the answer?

% times ; foo; times
0m0.00s 0m0.00s
0m0.00s 0m0.00s
hello
0m0.01s 0m0.00s
0m0.00s 0m0.00s

I had entirely forgotten the existence of that builtin.  Also quite
useful for a function because it separates in-shell user/system time
(first line) from sub-process (second line).


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: Timing function execution
  2021-11-06 18:35       ` Bart Schaefer
@ 2021-11-06 18:40         ` Bart Schaefer
  2021-11-06 18:43           ` Roman Perepelitsa
  0 siblings, 1 reply; 9+ messages in thread
From: Bart Schaefer @ 2021-11-06 18:40 UTC (permalink / raw)
  To: Roman Perepelitsa; +Cc: Zach Riggle, Zsh Users

On Sat, Nov 6, 2021 at 11:35 AM Bart Schaefer <schaefer@brasslantern.com> wrote:
>
> Glancing through builtin.c, "times" (based on library times(3)) may be
> the answer?
>
> I had entirely forgotten the existence of that builtin.

And (with apologies for the multiple follow-ups) I had also forgotten
that you can run "time" with no arguments:

% time; foo; time
shell  0.03s user 0.01s system 0% cpu 11:05.07 total
children  1.30s user 0.17s system 0% cpu 11:05.07 total
hello
shell  0.03s user 0.01s system 0% cpu 11:06.07 total
children  1.30s user 0.17s system 0% cpu 11:06.07 total


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: Timing function execution
  2021-11-06 18:40         ` Bart Schaefer
@ 2021-11-06 18:43           ` Roman Perepelitsa
  2021-11-06 19:01             ` Bart Schaefer
  0 siblings, 1 reply; 9+ messages in thread
From: Roman Perepelitsa @ 2021-11-06 18:43 UTC (permalink / raw)
  To: Bart Schaefer; +Cc: Zach Riggle, Zsh Users

On Sat, Nov 6, 2021 at 7:40 PM Bart Schaefer <schaefer@brasslantern.com> wrote:
>
> On Sat, Nov 6, 2021 at 11:35 AM Bart Schaefer <schaefer@brasslantern.com> wrote:
> >
> > Glancing through builtin.c, "times" (based on library times(3)) may be
> > the answer?
> >
> > I had entirely forgotten the existence of that builtin.
>
> And (with apologies for the multiple follow-ups) I had also forgotten
> that you can run "time" with no arguments:

Does this mean that `time foo` could work for functions (or rather any
"list")? That would be nice.

Roman.


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: Timing function execution
  2021-11-06 18:43           ` Roman Perepelitsa
@ 2021-11-06 19:01             ` Bart Schaefer
  2021-11-06 20:37               ` Zach Riggle
  0 siblings, 1 reply; 9+ messages in thread
From: Bart Schaefer @ 2021-11-06 19:01 UTC (permalink / raw)
  To: Roman Perepelitsa; +Cc: Zach Riggle, Zsh Users

On Sat, Nov 6, 2021 at 11:44 AM Roman Perepelitsa
<roman.perepelitsa@gmail.com> wrote:
>
> Does this mean that `time foo` could work for functions (or rather any
> "list")? That would be nice.

It's a bit more complicated than that; "time" with is handed fairly
deep in the exec.c call stack, with a special case for an empty list,
and actually requesting/printing the data when there is a list is
passed off to the SIGCHLD handler, so it would take a bit more
untangling than I'm going to dive into.


^ permalink raw reply	[flat|nested] 9+ messages in thread

* Re: Timing function execution
  2021-11-06 19:01             ` Bart Schaefer
@ 2021-11-06 20:37               ` Zach Riggle
  0 siblings, 0 replies; 9+ messages in thread
From: Zach Riggle @ 2021-11-06 20:37 UTC (permalink / raw)
  To: Bart Schaefer; +Cc: Roman Perepelitsa, Zsh Users

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

Thanks for the ideas everybody!

I may write up my own "timer" wrapper that uses $EPOCHREALTIME for the
benchmarking.

*Zach Riggle*


On Sat, Nov 6, 2021 at 2:02 PM Bart Schaefer <schaefer@brasslantern.com>
wrote:

> On Sat, Nov 6, 2021 at 11:44 AM Roman Perepelitsa
> <roman.perepelitsa@gmail.com> wrote:
> >
> > Does this mean that `time foo` could work for functions (or rather any
> > "list")? That would be nice.
>
> It's a bit more complicated than that; "time" with is handed fairly
> deep in the exec.c call stack, with a special case for an empty list,
> and actually requesting/printing the data when there is a list is
> passed off to the SIGCHLD handler, so it would take a bit more
> untangling than I'm going to dive into.
>

[-- Attachment #2: Type: text/html, Size: 1388 bytes --]

^ permalink raw reply	[flat|nested] 9+ messages in thread

end of thread, other threads:[~2021-11-06 20:38 UTC | newest]

Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-11-06 12:11 Timing function execution Zach Riggle
2021-11-06 16:15 ` Bart Schaefer
2021-11-06 16:21   ` Roman Perepelitsa
2021-11-06 18:17     ` Bart Schaefer
2021-11-06 18:35       ` Bart Schaefer
2021-11-06 18:40         ` Bart Schaefer
2021-11-06 18:43           ` Roman Perepelitsa
2021-11-06 19:01             ` Bart Schaefer
2021-11-06 20:37               ` Zach Riggle

Code repositories for project(s) associated with this 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).