# HG changeset patch
# User jbe
# Date 1427046007 -3600
# Node ID 1fbdccf4f8e9ac6c1ac61937ea711f6f79bfda7c
# Parent  0a6378afc6daa11c716c9777149599ff777ff97f
Always enable SQL tracer (within framework/env/__init.lua); Record execution time of SQL statements

diff -r 0a6378afc6da -r 1fbdccf4f8e9 doc/autodoc-header.htmlpart
--- a/doc/autodoc-header.htmlpart	Sun Mar 22 17:33:37 2015 +0100
+++ b/doc/autodoc-header.htmlpart	Sun Mar 22 18:40:07 2015 +0100
@@ -153,18 +153,9 @@
     </p>
     <pre>
 _G.db = assert(mondelefant.connect(config.db))
-function mondelefant.class_prototype:get_db_conn() return db end
-
-if config.db_trace then
-  function db:sql_tracer(command)
-    return function(error_info)
-      local error_info = error_info or {}
-      trace.sql{ command = command, error_position = error_info.position }
-    end
-  end
-end</pre>
+function mondelefant.class_prototype:get_db_conn() return db end</pre>
     <p>
-      Overwriting the <tt>sql_tracer</tt> method of the database handle is optional, but helpful for debugging. The parameters for <tt>mondelefant.connect</tt> are directly passed to PostgreSQL's client library libpq. See <a href="http://www.postgresql.org/docs/9.4/static/libpq-connect.html">PostgreSQL's documentation on PQconnect</a> for information about supported parameters.
+      The parameters for <tt>mondelefant.connect</tt> are directly passed to PostgreSQL's client library libpq. See <a href="http://www.postgresql.org/docs/9.4/static/libpq-connect.html">PostgreSQL's documentation on PQconnect</a> for information about supported parameters.
     </p>
     <p>
       To define a model to be used within a WebMCP application, create a file named with the name of the model and <tt>.lua</tt> as extension in the <tt>model/</tt> directory of your application. The most basic definition of a model (named &ldquo;movie&rdquo; in this example) is:
diff -r 0a6378afc6da -r 1fbdccf4f8e9 framework/env/__init.lua
--- a/framework/env/__init.lua	Sun Mar 22 17:33:37 2015 +0100
+++ b/framework/env/__init.lua	Sun Mar 22 18:40:07 2015 +0100
@@ -41,12 +41,27 @@
 extos       = require 'extos'
 nihil       = require 'nihil'
 mondelefant = require 'mondelefant'
-mondelefant.connection_prototype.error_objects = true
 atom        = require 'atom'
 json        = require 'json'
 require 'mondelefant_atom_connector'
 -- NOTE: "multirand" library is loaded in mcp.lua after forking
 
+-- setup mondelefant
+mondelefant.connection_prototype.error_objects = true
+function mondelefant.connection_prototype:sql_tracer(command)
+  if trace.is_disabled() then
+    return
+  end
+  local start_time = extos.monotonic_hires_time()
+  return function(error_info)
+    trace.sql{
+      command        = command,
+      execution_time = extos.monotonic_hires_time() - start_time,
+      error_position = error_info and error_info.position or nil
+    }
+  end
+end
+
 --[[--
 config  -- table to store application configuration
 
diff -r 0a6378afc6da -r 1fbdccf4f8e9 framework/env/trace/_render_sub_tree.lua
--- a/framework/env/trace/_render_sub_tree.lua	Sun Mar 22 17:33:37 2015 +0100
+++ b/framework/env/trace/_render_sub_tree.lua	Sun Mar 22 18:40:07 2015 +0100
@@ -1,3 +1,7 @@
+local function format_time(seconds)
+  return string.format("%.2f&nbsp;ms", seconds)
+end
+
 local function open(class)
   slot.put('<li class="trace_' .. class .. '">')
 end
@@ -184,13 +188,11 @@
     if node.error_position then
       -- error position starts counting with 1
       local part1 = string.sub(node.command, 1, node.error_position - 1)
-      --local part2 = string.sub(node.command, node.error_position - 1, node.error_position + 1)
       local part2 = string.sub(node.command, node.error_position)
       slot.put(encode.html(part1))
       slot.put('<span class="trace_error_position">&rArr;</span>')
       slot.put(encode.html(part2))
-      --slot.put('</span>')
-      --slot.put(encode.html(part3))
+      slot.put(" (execution time: ", format_time(node.execution_time), ")")
     else
       slot.put(encode.html(node.command))
     end
diff -r 0a6378afc6da -r 1fbdccf4f8e9 framework/env/trace/sql.lua
--- a/framework/env/trace/sql.lua	Sun Mar 22 17:33:37 2015 +0100
+++ b/framework/env/trace/sql.lua	Sun Mar 22 18:40:07 2015 +0100
@@ -1,7 +1,8 @@
 --[[--
 trace.sql{
-  command        = command,        -- executed SQL command as string
-  error_position = error_position  -- optional position in bytes where an error occurred
+  command        = command,         -- executed SQL command as string
+  execution_time = execution_time,  -- execution time of the statement in seconds
+  error_position = error_position   -- optional position in bytes where an error occurred
 }
 
 This command can be used to log SQL command execution. It is currently not invoked automatically.
@@ -13,10 +14,14 @@
 function trace.sql(args)
   if not trace._disabled then
     local command = args.command
+    local execution_time = args.execution_time
     local error_position = args.error_position
     if type(command) ~= "string" then
       error("No command string passed to trace.sql{...}.")
     end
+    if type(execution_time) ~= "number" then
+      error("No execution time number passed to trace.sql{...}.")
+    end
     if error_position and type(error_position) ~= "number" then
       error("error_position must be a number.")
     end