UNIX Command Line

query.log is the log file of the query daemon of my application. It prints the query debug lines in the following format:

$ cat query.log
Tue Oct 25 11:36:35 2008 (debug) : query received: Select ...... ;
Tue Oct 25 11:36:49 2008 (debug) : response prepared:
Tue Oct 25 11:36:50 2008 (debug) : query response sent: total records sent = 50
Tue Oct 25 11:39:04 2008 (debug) : query received: Select ..... ;
Tue Oct 25 11:40:04 2008 (debug) : response prepared:
Tue Oct 25 11:40:06 2008 (debug) : query response sent: total records sent = 23
....
....

Output required: For each query, I need to find the total time taken for the whole execution of the query, i.e the diff of "query response sent" and "query received" time.

The bash script using sed:

$ cat querytime.sh
#!/bin/sh

QFILE=query.log

while read logline
do
event=$(echo $logline | sed 's/.*(debug).*: \(.*\):.*/\1/')
case $event in
       "query received") ST=$(date +%s -d "${logline%(debug)*}")
               echo "$logline";;
       "query response sent") ET=$(date +%s -d "${logline%(debug)*}")
               echo "$logline"
               echo "Total time taken=$(($ET - $ST)) sec";;
       *) echo "$logline" ;;
esac
done < $QFILE

Executing the above script:
$ ./querytime.sh
Tue Oct 25 11:36:35 2008 (debug) : query received: Select ...... ;
Tue Oct 25 11:36:49 2008 (debug) : response prepared:
Tue Oct 25 11:36:50 2008 (debug) : query response sent: total records sent = 50
Total time taken=15 sec
Tue Oct 25 11:39:04 2008 (debug) : query received: Select ..... ;
Tue Oct 25 11:40:04 2008 (debug) : response prepared:
Tue Oct 25 11:40:06 2008 (debug) : query response sent: total records sent = 23
Total time taken=62 sec
....
....