Is there a unix command to output time elapsed during a command?

I love using time to find out how long a command took to execute but when dealing with commands that execute sub-commands internally (and provide output that allows you to tell when each of those sub-commands start running) it would be really great to be able to tell after what number of seconds (or milliseconds) a specific sub-command started running.

When I say sub-command, really the only way to distinguish these from the outside is anything printed to standard out.

Really this seems like it should be an option to time.


it would be really great to be able to tell after what number of seconds (or milliseconds) a specific sub-command started running

One possibility is to use this bash variable:

SECONDS

This variable expands to the number of seconds since the shell was started. Assignment to this variable resets the count to the value assigned, and the expanded value becomes the value assigned plus the number of seconds since the assignment.

To combine that with an output stream, consider this dedicated script which adds a timestamp to each input line:

$ cat timestamp-output
#!/bin/bash
while read line
do
  printf "%05d %s\n" $SECONDS "$line"
done

And pipe your script's output into that script.

$ your-script | timestamp-output

Example:

$ cat your-script
#!/bin/bash
for i in 1 2 3 4
do
  echo "step $i started";
  sleep $(($RANDOM%10));
done

$ your-script | timestamp-output

Output:

00000 step 1 started
00002 step 2 started
00010 step 3 started
00015 step 4 started


This could be refined to timestamp only the output lines that signal the start of a sub-command, assuming they can be grep'ed:

#!/bin/bash
regex="^start of command"
while read line
do
 if [[ "$line" =~ $regex ]]; then
   printf "%05d %s\n" $SECONDS "$line"
 else
   echo "$line"
 fi
done

Sample script:

#!/bin/bash
for i in 1 2 3 4
do
  echo "start of command: $i";
  echo some output
  echo other output
  sleep $(($RANDOM%10));
done

Sample output:

00000 start of command: 1
some output
other output
00002 start of command: 2
some output
other output
00006 start of command: 3
some output
other output
00008 start of command: 4
some output
other output

If you need to find out when child processes start running, you can use strace -f -tt and analyze the output, or potentially roll your own script to do that for you.