Take the 2-minute tour ×
Unix & Linux Stack Exchange is a question and answer site for users of Linux, FreeBSD and other Un*x-like operating systems.. It's 100% free, no registration required.

I'm trying to get the time that my program takes to finish (aka elapsed time) so I'm using the common time.

What I get by doing this is 3 measurements: user, system and total. This is fine but I found that the user time that I'm interested in has only two decimal places and I would need more. Is there any way I can get more decimal places out of my time command?

Example: time ./myCProgram
Output: 0.17s user 1.21s system 130% cpu 0.187 total

Wished output wanted: 0.17000s user 1.21s system 130% cpu 0.187 total (or more decimal places)

share|improve this question
    
Are you using bash's builtin time? GNU coreutils time? What version of time? –  jordanm Nov 9 '12 at 19:52
add comment

2 Answers

up vote 2 down vote accepted

If all you want is elapsed time, then with zsh or ksh93:

$ typeset -F SECONDS=0; sleep 1; print "$SECONDS"
1.0012850761

Now, whether that kind of precision makes sense is another matter.

share|improve this answer
    
+1 for questioning whether having finer than ms measurement is really sensible. –  peterph Nov 9 '12 at 23:42
    
Yes this helped me determine where I wanted to get to! Thanks you! –  Ini Nov 15 '12 at 16:00
add comment

Computing time in nanoseconds under GNU/Linux, using .

Ways to retrieve reliable values

There are some way to ask for time in a finer granularity than one second.

First, but not best: 1/100th of second

For 1/100th of second, you could simply refer to /proc/uptime:

sed 's/ .*$//' /proc/uptime 
276440.58

The time offset to add for calculating real UTC time could be obtain by one of:

ps ho lstart 1 | date -f - +%s
1357193821

or

date +%s.%N-$(sed 's/ .*$//' /proc/uptime ) | bc -l
1357193821.088187101

As offset are static, this value could be computed only 1 time, at begin of script.

1/1000000000th of seconds, using proc entries only:

For computing with nanoseconds, there is a proc entry, named /proc/timer_list which contain both uptime and offset:

sed < /proc/timer_list -ne '/now at/p;/offset/{p;q}'
now at 276350507668586 nsecs
  .offset:     1357193821075753443 nsecs

So this

echo $(($(sed < /proc/timer_list -ne '
    /^now at/{s/now at \([0-9]*\) ns.*$/\1/;H};
    /offset/{s/^.*: *\([0-9]*\) ns.*$/\1/;G;s/\n\+/+/;p;q}'))) 
1357470173543424035

is the integer number of nanoseconds elapsed from 1970-1-1 00:00:00 UTC.

For computing integer under , there is no need to use bc and for parsing proc files, we could use mapfile which is a bash builtin:

# first, some static variables (with fork, but only 1 time, at begin;):
nowAtLine=$(($(sed -ne < /proc/timer_list '/now at/{=;q}')-1))
offset=$(sed -ne < /proc/timer_list '
    /offset/{s/^.*: *\([0-9]*\) n.*$/\1/p;q}')

# than this will be a lot quicker than a fork:
mapfile -n 1 -s $nowAtLine timerList </proc/timer_list &&
    timerList=($timerList) &&
    echo $((${timerList[2]}+offset))
1357470173543424035

1/1000000000th of seconds, using date binary tool:

And finaly if they not exist, we could call date keeping in mind that it's a fork wich take a lot more time than reading proc files, staying in only one bash session.

date +%s%N
1357470074808968375

My elap.bash function

based on this, I wrote a elap bash function, with two counters: 1 for each call and the other for a kind of overall duration.

Usage:

First, this is a function, not a script. You have to source them in your current bash session in order for using it.

. elap.bash
Syntaxe:
elap [ [ -r | -R ] | [ -n ] [ -t | -T ] [<simple text report>] ]
    -r reset first counter only, don't output anything, like -R...
    -R reset both counters, (both -r and -R must by unique argument)
    -n don't reset any counter (just print)
    -t print both counters (reset first counter)
    -T print and reset

Than reset both counters before using it:

elap -R
find /usr/bin >/dev/null
elap browsing /usr/bin

     0.025389543 browsing /usr/bin

So you could add some markers in a script:

#!/bin/bash
. elap.bash
  elap -R
tar -cf /tmp/test.tar -C / bin
  elap making a tarball of $(stat -c %s /tmp/test.tar) bytes
gzip /tmp/test.tar
  elap compressing them to $(stat -c %s /tmp/test.tar.gz) bytes
scp /tmp/test.tar.gz backup@elswhere.net:backups/
  elap sending file to backup server
rm /tmp/test.tar.gz
  elap removing compressed tarball
elap -t total duration

     0.043223957 making a tarball of 5877760 bytes
     0.667249628 compressing them to 2742537 bytes
test.tar.gz                                  100% 2678KB 2.6MB/s 00:00
     0.380779818 sending file to backup server
     0.010262259 removing compressed tarball
     0.003566335      1.105081997 total duration

Using trap debug for following step-by-step

With or without the -t switch, using trap debug for step by step, wit less script alteration (added four lines at top of script and one at bottom):

As trapping for debug will occure before $BASH_COMMAND execution, we need to store variable content to a $BASH_LAST variable for correct printing, and add a dummy command at bottom of script.

#!/bin/bash

. elap.bash
elap -R
export BASH_LAST=Starting
trap 'elap -t $BASH_LAST;BASH_LAST=$BASH_COMMAND' debug 

tar -cf /tmp/test.tar -C / bin
gzip /tmp/test.tar
scp /tmp/test.tar.gz backup@elswhere.net:backups/
rm /tmp/test.tar.gz

exit $?

The exit $? command is needed to dump statistiques after the last rm command.

     0.001011086      0.001011086 Starting
     0.045175969      0.046187055 tar -cf /tmp/test.tar -C / bin
     0.651394209      0.697581264 gzip /tmp/test.tar
test.tar.gz                                  100% 2678KB 2.6MB/s 00:00
     0.374499354      1.072080618 scp /tmp/test.tar.gz backup@elswhere.net:backups/
     0.007160101      1.079240719 rm /tmp/test.tar.gz

The function source

Where you could cut (or reorder) uptime part, if you prefer using fork to date +%s%N instead of using 1/100th of seconds granularity.

#
# Bash source file for fine elapsed time reporting
# based on /proc/timer_list, display elapsed time in nanosecs
# or /proc/uptime if timer_list not present, for 100th of secs.
# if none of them if present, fall back to *fork* `date +%s%N`.
#
# (C) 2011-2012 Felix Hauri - felix@f-hauri.ch
# Licensed under terms of LGPL v3. www.gnu.org

# Usage:
#   load script into bash using ``source elap.bash''
#
# Syntaxe: elap [ [ -r | -R ] | [ -n ] [ -t | -T ] [<simple text report>] ]
#   -r reset first counter only, don't output anything, like -R...
#   -R reset both counters, (both -r and -R must by unique argument)
#   -n don't reset any counter (just print)
#   -t print both counters (reset first counter)
#   -T print and reset
#
# nota: using ``-n'' in combinaison with any of ``-r'' or ``-R'' is buggy.

export _elaP_now _elaP_last _elaP_elap _elaP_last2 _elaP_dec

if [ -r /proc/timer_list ] ;then
    _elaP_file=/proc/timer_list
    _elaP_dec=9
    _elaP_field=2
    mapfile < $_elaP_file _elaP_now
    _elaP_line=0
    while [ "${_elaP_now[_elaP_line]}" == \
    "${_elaP_now[_elaP_line]#*now at}" ] ;do
    ((_elaP_line++))
    done
    eval 'function elap_getNow() {
     mapfile -n 1 -s '$_elaP_line' <'$_elaP_file' _elaP_now
         _elaP_now=($_elaP_now)
         _elaP_now=${_elaP_now[_elaP_field]}
         }'
else
    #      --- To be removed for nanoseconds only
    if [ -r /proc/uptime ] ;then
    _elaP_dec=2
    function elap_getNow() {
        read -a _elaP_now </proc/uptime _elaP_now
            _elaP_now=${_elaP_now//./}
    }
    else # --- End of part to be removed for ns only.
    _elaP_dec=9
    function elap_getNow() { _elaP_now=$(date +%s%N) ;}
    fi   # --- Remove this line too for ns only.
fi

export -f elap_getNow

elap() {
    local _Z9=000000000
    local _elaP_setLast=true
    [ "$1" == "-n" ] && shift && _elaP_setLast=false
    [ "$2" == "-n" ] && set -- $1 ${@:3} && _elaP_setLast=false

    elap_getNow

    _elaP_elap=$((_elaP_now - _elaP_last))
    [ ${#_elaP_elap} -lt $_elaP_dec ] && \
    _elaP_elap=${_Z9:0:_elaP_dec-${#_elaP_elap}}$_elaP_elap
    [ "${*}" == "-R" ] &&  _elaP_last2=$_elaP_now || \
    [ "${*}" == "-r" ] || if [ "$1" == "-t" ] || [ "$1" == "-T" ] ;then
    local _elaP_setLast2=false
    [ "$1" == "-T" ] && _elaP_setLast2=true
    shift
            _elaP_elap2=$((_elaP_now - _elaP_last2))
    [ ${#_elaP_elap2} -lt $_elaP_dec ] && \
        _elaP_elap2="${_Z9:0:_elaP_dec-${#_elaP_elap2}}$_elaP_elap2"
        printf "%6d.%s %6d.%s %s\n" \
        "${_elaP_elap:0:${#_elaP_elap}-$_elaP_dec}" \
        "${_elaP_elap:${#_elaP_elap}-_elaP_dec}" \
        "${_elaP_elap2:0:${#_elaP_elap2}-$_elaP_dec}" \
        "${_elaP_elap2:${#_elaP_elap2}-_elaP_dec}"      "${*}"
    $_elaP_setLast2 && _elaP_last2=$_elaP_now
    else
        printf "%6d.%s %s\n" \
        "${_elaP_elap:0:${#_elaP_elap}-$_elaP_dec}" \
        "${_elaP_elap:${#_elaP_elap}-_elaP_dec}"        "${*}"
    fi
    $_elaP_setLast && _elaP_last=$_elaP_now
}

export -f elap
share|improve this answer
add comment

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.