# HG changeset patch
# User jbe
# Date 1427051186 -3600
# Node ID 04b648660f9aa13163e0ea4c3eb8157830bbdcdb
# Parent  216cd6ca6bc86dabf1ab18f610eec9666c89ce7f
Time triple (cpu/db/total) for trace system

diff -r 216cd6ca6bc8 -r 04b648660f9a framework/env/trace/_new_entry.lua
--- a/framework/env/trace/_new_entry.lua	Sun Mar 22 19:28:07 2015 +0100
+++ b/framework/env/trace/_new_entry.lua	Sun Mar 22 20:06:26 2015 +0100
@@ -1,5 +1,7 @@
 function trace._new_entry(node)
   local node = node or {}
-  table.insert(trace._stack[#trace._stack], node)
+  local stack = trace._stack
+  local parent = stack[#stack]
+  parent[#parent+1] = node
   return node
 end
diff -r 216cd6ca6bc8 -r 04b648660f9a framework/env/trace/_open_section.lua
--- a/framework/env/trace/_open_section.lua	Sun Mar 22 19:28:07 2015 +0100
+++ b/framework/env/trace/_open_section.lua	Sun Mar 22 20:06:26 2015 +0100
@@ -1,8 +1,10 @@
 function trace._open_section(node)
   local node = trace._new_entry(node)
   node.section = true
+  node.db_time = 0
   node.start_real_time = extos.monotonic_hires_time()
   node.start_proc_time = os.clock()
-  table.insert(trace._stack, node)
+  local stack = trace._stack
+  stack[#stack+1] = node
   return node
 end
diff -r 216cd6ca6bc8 -r 04b648660f9a framework/env/trace/_render_sub_tree.lua
--- a/framework/env/trace/_render_sub_tree.lua	Sun Mar 22 19:28:07 2015 +0100
+++ b/framework/env/trace/_render_sub_tree.lua	Sun Mar 22 20:06:26 2015 +0100
@@ -1,8 +1,16 @@
-local function format_time(real_time, proc_time)
-  if proc_time then
-    return string.format("%.1f ms (%.1f ms)", real_time * 1000, proc_time * 1000)
+local function format_time(db_time)
+  return string.format("%.1f ms", real_time * 1000)
+end
+
+local function format_triple(real_time, proc_time, db_time)
+  if proc_time and db_time then
+    return string.format(
+      "u=%.1f d=%.1f t=%.1f",
+      1000 * db_time,
+      1000 * proc_time,
+      1000 * real_time
+    )
   else
-    return string.format("%.1f ms", real_time * 1000)
   end
 end
 
@@ -14,29 +22,33 @@
   if node.start_real_time and node.stop_real_time then
     local total_real_time = node.stop_real_time - node.start_real_time
     local total_proc_time = node.stop_proc_time - node.start_proc_time
+    local total_db_time   = node.db_time
     local child_real_time = 0
     local child_proc_time = 0
+    local child_db_time   = 0
     for i, child in ipairs(node) do
       if child.start_real_time then
         child_real_time = child_real_time + child.stop_real_time - child.start_real_time
         child_proc_time = child_proc_time + child.stop_proc_time - child.start_proc_time
+        child_db_time   = child_db_time   + child.db_time
       end
     end
     local real_time = total_real_time - child_real_time
     local proc_time = total_proc_time - child_proc_time
+    local db_time   = total_db_time   - child_db_time
     slot.put(
       '<div class="time">',
       '<span class="duration_label">this:</span>',
       ' ',
-      '<span class="duration">', format_time(real_time, proc_time), '</span>',
+      '<span class="duration">', format_triple(real_time, proc_time, db_time), '</span>',
       ' | ',
       '<span class="child_duration_label">children:</span>',
       ' ',
-      '<span class="child_duration">', format_time(child_real_time, child_proc_time), '</span>',
+      '<span class="child_duration">', format_triple(child_real_time, child_proc_time, db_time), '</span>',
       ' | ',
       '<span class="total_duration_label">total:</span>',
       ' ',
-      '<span class="total_duration">', format_time(total_real_time, total_proc_time), '</span>',
+      '<span class="total_duration">', format_triple(total_real_time, total_proc_time, db_time), '</span>',
       '</div>'
     )
   end
diff -r 216cd6ca6bc8 -r 04b648660f9a framework/env/trace/sql.lua
--- a/framework/env/trace/sql.lua	Sun Mar 22 19:28:07 2015 +0100
+++ b/framework/env/trace/sql.lua	Sun Mar 22 20:06:26 2015 +0100
@@ -31,5 +31,8 @@
       execution_time = execution_time,
       error_position = error_position
     }
+    for i, entry in ipairs(trace._stack) do
+      entry.db_time = entry.db_time + execution_time
+    end
   end
 end