Take the 2-minute tour ×
Super User is a question and answer site for computer enthusiasts and power users. It's 100% free, no registration required.

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.

share|improve this question
    
There are commands that don't print anything. Also, a command might exist that outputs something, waits a bit, and outputs something more (watch, tail -f). –  choroba Jun 7 at 16:06
1  
time is a command for measuring any executable, not only shell scripts. Output lines don't mean anything per se (as @choroba already noted). So time won't ever have such an option. It would be useless. This is a very specific case which makes sense for you, and for that specific script. –  drk.com.ar Jun 7 at 17:14

2 Answers 2

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.

share|improve this answer

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
share|improve this answer

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.