redirect time command output to file (cygwin bash)

I have set up a bash script to run a long list of things that I need to time. I would like to redirect the output of time to a file. I have set it up like,

echo "Runtimes for servlet 4, 100K structures" > test_times.txt
echo "" >> test_times.txt

echo "runs where N=10" >> test_times.txt
echo "" >> test_times.txt

echo "run1 test_intput.txt -n 4 -t 1000 -l 100 -d t -N 10" >> test_times.txt
   time -a test_times.txt \
   ./myProgram.exe -a arguments -i inputFile -o outputFile
echo "" >> test_times.txt

I get a bash error for -a: command not found.

Am I doing something wrong here??? I thought that time -a filename would append to the file.

LMHmedchem

First off, don't give a filename after -a, since one isn't expected there. -a tells it to append, but you still need -o to tell it which file.

Second, you don't need to open the same file 300 times to put 300 things in it. Try this:

# The round brackets put it in a subshell.  You can redirect the output of the subshell instead
# of each individual command inside it.
(
        # You can feed one here-document into cat instead of running echo 9 times.
        # Note that the ending EOF is at the beginning of the line, not indented.  This is
        # important!  Even indenting that will prevent the here-document from ending properly.
        # Also note that variables will work inside a here-document, just like they would inside
        # double-quotes.
        cat <<EOF
Runtimes for servlet 4, 100K structures

Runs where N=10

run1 test_intput.txt -n 4 -t 1000 -l 100 -d t -N 10
EOF

        time ./myProgram.exe -a arguments -i inputFile -o outputFile

        echo

) > test_times.txt
1 Like

Thanks for the help, I always learn something new here.

I added a few things to the code you posted,

SIZE=100K
CPDS=10

(
   cat <<EOF
Runtimes for servlet 4, $SIZE structures

Runs where N=$CPDS

run1 test_ActiMol_$SIZE.sdf -n 4 -t 1000 -l 100 -d t -N $CPDS
EOF

   time ./servert.exe -n 4 -t 1000 -l 100 -d t -N $CPDS -i  'test_ActiMol_'$SIZE'.sdf' -o  'test_ActiMol_100K_'$CPDS'N_2.s'

   echo

) > test_times.txt

and this runs without error, but the the time data is still to cout and does not end up in the file. Everything else ends up in test_times.txt as expected.

I will probably end up with a double loop on SIZE and CPDS, but I need to get the single instance working first. I tried adding the same -o filename after the time command, but I still get the -o: command not found error.

LMHmedchem

time output is printed on the standard error, which hasn't been redirected.

Regards,
Alister

3 Likes

This is the ugly triple loop that I set up to run this long batch,

#!/usr/bin/bash

echo "testing output" > test_times.txt
echo "" >> test_times.txt

# list directory names here
SIZE=( 100K 500K 1M )

for SIZE in ${SIZE[@]}
do

   echo "Runtimes for servlet 4," $SIZE "structures" >> test_times.txt
   echo "" >> test_times.txt

   CPDS=( 10 100 500 1000 2500 5000 10000 25000 50000 )

   for CPDS in ${CPDS[@]}
   do

      echo "Runs where N="$CPDS >> test_times.txt 

      REP=( 1 2 3 4 5 )

      for REP in ${REP[@]}
      do

         echo 'run' $REP 'test_ActiMol_'$SIZE'.sdf -n 4 -t 1000 -l 100 -d t -N' $CPDS >> test_times.txt 
         time ./servert.exe -n 4 -t 1000 -l 100 -d t -N $CPDS \
         -i  'test_ActiMol_'$SIZE'.sdf' \
         -o  'test_ActiMol_100K_'$CPDS'N_'$REP'.s'  >> test_times.txt
         
         echo "   TIMEOUTS=" $(grep -c "TIMEOUT" 'test_ActiMol_100K_'$CPDS'N_'$REP'.s') >> test_times.txt
         echo "   SEGFAULTS=" $(grep -c "SEGFAULT" 'test_ActiMol_100K_'$CPDS'N_'$REP'.s') >> test_times.txt
         echo "   NUMBER PROCESSED=" $(wc -l 'test_ActiMol_100K_'$CPDS'N_'$REP'.s') >> test_times.txt

      done

      echo " " >> test_times.txt 

   done

      echo " " >> test_times.txt
      echo " " >> test_times.txt 

done

This works in every respect other than printing the output of time to the file. I am very unclear as to how to utilize the here-document in this context.

This is giving me the output I need,

Runtimes for servlet 4, 100K structures

Runs where N=10
run 1 test_ActiMol_100K.sdf -n 4 -t 1000 -l 100 -d t -N 10
   TIMEOUTS= 0
   SEGFAULTS= 0
   NUMBER PROCESSED= 100002 test_ActiMol_100K_10N_1.s
run 2 test_ActiMol_100K.sdf -n 4 -t 1000 -l 100 -d t -N 10
   TIMEOUTS= 0
   SEGFAULTS= 0
   NUMBER PROCESSED= 100002 test_ActiMol_100K_10N_2.s
run 3 test_ActiMol_100K.sdf -n 4 -t 1000 -l 100 -d t -N 10
   TIMEOUTS= 0
   SEGFAULTS= 0
   NUMBER PROCESSED= 100002 test_ActiMol_100K_10N_3.s
run 4 test_ActiMol_100K.sdf -n 4 -t 1000 -l 100 -d t -N 10
   TIMEOUTS= 0
   SEGFAULTS= 0
   NUMBER PROCESSED= 100002 test_ActiMol_100K_10N_4.s
run 5 test_ActiMol_100K.sdf -n 4 -t 1000 -l 100 -d t -N 10
   TIMEOUTS= 0
   SEGFAULTS= 0
   NUMBER PROCESSED= 100002 test_ActiMol_100K_10N_5.s

minus the times.

LMHmedchem

---------- Post updated at 08:44 PM ---------- Previous update was at 08:27 PM ----------

I have tried the following to get stderr appended to my output file,

   time ./servert.exe -n 4 -t 1000 -l 100 -d t -N $CPDS \
   -i  'test_ActiMol_'$SIZE'.sdf' \
   -o  'test_ActiMol_100K_'$CPDS'N_'$REP'.s' >>test_times.txt 2>&1
   time ./servert.exe -n 4 -t 1000 -l 100 -d t -N $CPDS \
   -i  'test_ActiMol_'$SIZE'.sdf' \
   -o  'test_ActiMol_100K_'$CPDS'N_'$REP'.s' 2>>test_times.txt
   time ./servert.exe -n 4 -t 1000 -l 100 -d t -N $CPDS \
   -i  'test_ActiMol_'$SIZE'.sdf' \
   -o  'test_ActiMol_100K_'$CPDS'N_'$REP'.s' &>>test_times.txt

the third one being a shot in the dark. None of these make any difference and I am still getting the time data printed to the terminal.

There always seems to be a hangup somewhere.

LMHmedchem

---------- Post updated at 09:13 PM ---------- Previous update was at 08:44 PM ----------

Apparently, but using the following command,

   time ./servert.exe -n 4 -t 1000 -l 100 -d t -N $CPDS \
   -i  'test_ActiMol_'$SIZE'.sdf' \
   -o  'test_ActiMol_100K_'$CPDS'N_'$REP'.s' >> test_times.txt 2>&1

I am redirecting the stderr and stdout of servert.exe to test_times.txt and not the stderr/stdout of time. This was fixed by grouping the time and servert.exe commands,

   ( time ./servert.exe -n 4 -t 1000 -l 100 -d t -N $CPDS \
     -i  'test_ActiMol_'$SIZE'.sdf' \
     -o  'test_ActiMol_100K_'$CPDS'N_'$REP'.s' ) >> test_times.txt 2>&1

with this revision, the output is as expected,

Runtimes for servlet 4, 100K structures

Runs where N=10
run 1 test_ActiMol_100K.sdf -n 4 -t 1000 -l 100 -d t -N 10

real	0m43.656s
user	0m0.015s
sys	0m0.015s
TIMEOUTS= 0
SEGFAULTS= 0
NUMBER PROCESSED= 100002 test_ActiMol_100K_10N_1.s

run 2 test_ActiMol_100K.sdf -n 4 -t 1000 -l 100 -d t -N 10

real	0m43.203s
user	0m0.031s
sys	0m0.015s
TIMEOUTS= 0
SEGFAULTS= 0
NUMBER PROCESSED= 100002 test_ActiMol_100K_10N_2.s

run 3 test_ActiMol_100K.sdf -n 4 -t 1000 -l 100 -d t -N 10

now I think I need to try to incorporate the here-document suggested by Corona688 to minimize the number of echo commands.

LMHmedchem

There were a few things regarding your redirection woes that piqued my curiosity. I believe I now understand why you've had so much trouble with it.

The syntax for a bash pipeline is as follows (from the bash manual):

The format for a pipeline is

     [time [-p]] [!] command1 [ [| or |&] command2 ...]

The reserved word time causes timing statistics to be printed for the pipeline once it finishes. 

The key here is that time is a shell keyword, not a built-in and not an external command.

Note that the error message says that -a is a command that cannot be found. It does not say that it's a bad option. Your script is using bash's time keyword, which does not support a -a or -o option, so that as far as bash is concerned, -a is the name of the command whose execution should be timed.

Indeed. With a command, the first two redirection attempts would have worked. However, since time is a keyword, there is nothing to redirect. The time keyword simply instructs bash to output timing info to its own standard error. If you want to redirect the timing information, you have to modify the current shell environment with exec prior to invoking the timed pipeline...

... or you can run it in a subshell as you did there.

If you want to run the time command that supports the options you were initially attempting to use, you'll need to bypass the keyword using command time ./servert.exe ... or tell bash where to find the time binary, e.g., /usr/bin/time ./servert.exe ... .

Regards,
Alister

1 Like

You are right that I mistakenly thought I was running the gnu time program when I was really using the bash time argument. Am I right in guessing that this reports the time it takes the bash command to execute and not the time it takes the program to run, or is there a difference?

GNU time gives more detailed output, such a page faults, etc. I thought I tried /usr/bin/time at some point, but that didn't work. I will have to give that a try and see if I can get it working. Which says that it's there. One of the issues I as thinking of is that the log file already exists, so I would want -a, but I didn't know if I could do -a without first having used -o to create the file.

This is the current version of the script,

#!/usr/bin/bash

# t value
TIMEOUT=1000
# n value
NCLIENTS=4

echo "testing output" > test_times.txt
echo "" >> test_times.txt

# list input file sizes here (number of compounds)
SIZE=( 1K 10K 100K 500K 1M )

for SIZE in ${SIZE[@]}
do
   echo "Runtimes for servlet 4," $SIZE "structures" >> test_times.txt
   echo "" >> test_times.txt

#  list values for N here
   CPDS=( 10 100 500 1000 2500 5000 10000 25000 50000 75000 100000 )

   for CPDS in ${CPDS[@]}
   do
      echo "Runs where N="$CPDS >> test_times.txt 

#     list number of repetitions for each run
      REP=( 1 2 3 4 5 )

      for REP in ${REP[@]}
      do
         echo 'run' $REP 'test_ActiMol_'$SIZE'.sdf -n 4 -t 1000 -l 100 -d t -N' $CPDS >> test_times.txt 
         ( time ./servert.exe -n $NCLIENTS -t $TIMEOUT -l 100 -d t -N $CPDS \
           -i  'test_ActiMol_'$SIZE'.sdf' \
           -o  'test_ActiMol_'$SIZE'_'$CPDS'N_'$REP'.s' ) >> test_times.txt 2>&1

         echo "TIMEOUTS=" $(grep -c "TIMEOUT" 'test_ActiMol_'$SIZE'_'$CPDS'N_'$REP'.s') >> test_times.txt
         echo "SEGFAULTS=" $(grep -c "SEGFAULT" 'test_ActiMol_'$SIZE'_'$CPDS'N_'$REP'.s') >> test_times.txt
         echo "NUMBER PROCESSED=" $(wc -l 'test_ActiMol_'$SIZE'_'$CPDS'N_'$REP'.s') >> test_times.txt
         echo "" >> test_times.txt

#        print something to the terminal to monitor progress
         echo 'completed run' $REP 'test_ActiMol_'$SIZE'.sdf -n' $NCLIENTS '-t' $TIMEOUT '-l 100 -d t -N' $CPDS

      done
      echo "" >> test_times.txt 

   done
      echo "" >> test_times.txt
      echo "" >> test_times.txt 

done

unix2dos test_times.txt 

It seems as if some of the multiple echo statements could be reduced using the here-document that Corona688 suggested. I will look into that. It also seems that I could echo a couple of newlines at once instead of doing it several times to insert several blank lines.

LMHmedchem

You could also use printf to do it. It never prints newlines unless instructed.

printf "\n\n\n\n"