David Waugh

LUA Parser to Extract Query Execute Time

Blog Post created by David Waugh Employee on Nov 25, 2016

Building on the excellent work in Security Analytics Log Parser 2.1.63.zip I had a minor irritation in that the query time was not particulary useful if you had a lot of concentrators.

 

A typical log message would look like:

 

Nov 20 07:08:46 mybroker NwBroker[3306]: [SDK-Query] [audit] User admin (session 3421280, 192.168.15.95:41462) has finished query (channel 3424049, queued 00:00:00, execute 00:20:01, 192.168.16.188:56003=00:08:04 192.168.20.184:56003=00:20:01 192.168.20.76:56003=00:00:59 192.168.21.78:56003=00:20:01 192.168.22.53:56003=00:12:50 192.168.23.173:56003=00:02:58 192.168.23.55:56003=00:00:05 192.168.24.184:56003=00:08:44 192.168.24.49:56003=00:04:18 192.168.25.177:56003=00:00:11 192.168.25.58:56003=00:00:24 192.168.26.53:56003=00:12:11 192.168.27.177:56003=00:11:48 192.168.27.52:56003=00:00:22 192.168.28.177:56003=00:09:28 192.168.28.49:56003=00:10:28 192.168.29.139:56003=00:00:14 192.168.29.49:56003=00:00:21 192.168.31.19:56003=00:00:07 192.168.8.235:56005=00:05:29 192.168.8.236:56005=00:00:43 192.168.26.182:56003=00:01:36 192.168.19.57:56003=00:00:03 192.168.21.182:56003=00:11:55): id1=5729990302 id2=19760696376362 threshold=0 query="select time, ip.src, ip.dst, tcp.srcport, tcp.dstport, service, alias.host, directory, filename, query, referer, sessionid where (time='2016-Sep-01 00:00:00'-'2016-Nov-19 06:47:11') && (((alias.host contains 'bbc.com' || alias.host contains 'guardian.com' )))"

 

Unfortunately the part in red got put into the query.time meta key so it was not particularly useful.

 

I wrote a LUA parser to extract the data from Query.time so that the time the query took was put into an Integer metakey called execute.time.

 

Here is the LUA parser. Perhaps it will be useful for someone...

 

With this parser you can create reports that show your longest running queries, and who ran them.

 

 

 

I've updated the parser so that it has the following features:

  • Able to parse all concentrator times even if the length of querytime exceeds 256 characters, so no statistics are lost
  • Added a key to store the slowest concentrator for each query so you can identify if one particular concentrator is always the slowest. We only consider query times greater than 5 seconds for this feature.

Outcomes