webmcp

changeset 299:47c5f33e4a6b

Trace real time and CPU time
author jbe
date Sun Mar 22 19:25:38 2015 +0100 (2015-03-22)
parents e0b6cb626ee6
children d1d21ae9acdb
files framework/env/trace/__init.lua framework/env/trace/_close_section.lua framework/env/trace/_open_section.lua framework/env/trace/_render_sub_tree.lua
line diff
     1.1 --- a/framework/env/trace/__init.lua	Sun Mar 22 18:58:50 2015 +0100
     1.2 +++ b/framework/env/trace/__init.lua	Sun Mar 22 19:25:38 2015 +0100
     1.3 @@ -5,7 +5,7 @@
     1.4    if seq == 0 then
     1.5      -- prepare for configuration/initialization phase
     1.6      trace._disabled = false
     1.7 -    trace._tree = { type = "root", start_hires_time = extos.monotonic_hires_time() }
     1.8 +    trace._tree = { type = "root" }
     1.9      trace._stack = { trace._tree }
    1.10      seq = 1
    1.11    elseif seq == 1 then
     2.1 --- a/framework/env/trace/_close_section.lua	Sun Mar 22 18:58:50 2015 +0100
     2.2 +++ b/framework/env/trace/_close_section.lua	Sun Mar 22 19:25:38 2015 +0100
     2.3 @@ -4,8 +4,8 @@
     2.4    if not closed_section then
     2.5      error("All trace sections have been closed already.")
     2.6    end
     2.7 -  closed_section.stop_hires_time = extos.monotonic_hires_time()
     2.8 -  --trace.debug("END " .. extos.monotonic_hires_time() .. " / " .. os.clock())
     2.9 +  closed_section.stop_real_time = extos.monotonic_hires_time()
    2.10 +  closed_section.stop_proc_time = os.clock()
    2.11    trace._stack[pos] = nil
    2.12    return closed_section
    2.13  end
     3.1 --- a/framework/env/trace/_open_section.lua	Sun Mar 22 18:58:50 2015 +0100
     3.2 +++ b/framework/env/trace/_open_section.lua	Sun Mar 22 19:25:38 2015 +0100
     3.3 @@ -1,8 +1,8 @@
     3.4  function trace._open_section(node)
     3.5    local node = trace._new_entry(node)
     3.6    node.section = true
     3.7 -  node.start_hires_time = extos.monotonic_hires_time()
     3.8 +  node.start_real_time = extos.monotonic_hires_time()
     3.9 +  node.start_proc_time = os.clock()
    3.10    table.insert(trace._stack, node)
    3.11 -  --trace.debug("START " .. extos.monotonic_hires_time() .. " / " .. os.clock())
    3.12    return node
    3.13  end
     4.1 --- a/framework/env/trace/_render_sub_tree.lua	Sun Mar 22 18:58:50 2015 +0100
     4.2 +++ b/framework/env/trace/_render_sub_tree.lua	Sun Mar 22 19:25:38 2015 +0100
     4.3 @@ -1,5 +1,9 @@
     4.4 -local function format_time(seconds)
     4.5 -  return string.format("%.1f ms", seconds * 1000)
     4.6 +local function format_time(real_time, proc_time)
     4.7 +  if proc_time then
     4.8 +    return string.format("%.1f ms (%.1%f ms CPU)", real_time * 1000, proc_time * 1000)
     4.9 +  else
    4.10 +    return string.format("%.1f ms", real_time * 1000)
    4.11 +  end
    4.12  end
    4.13  
    4.14  local function open(class)
    4.15 @@ -7,36 +11,34 @@
    4.16  end
    4.17  local function open_head(node)
    4.18    slot.put('<div class="trace_head">')
    4.19 -  if node.start_hires_time and node.stop_hires_time then
    4.20 -    local total_duration = node.stop_hires_time - node.start_hires_time
    4.21 -    local child_duration = 0
    4.22 +  if node.start_real_time and node.stop_real_time then
    4.23 +    local total_real_time = node.stop_real_time - node.start_real_time
    4.24 +    local total_proc_time = node.stop_proc_time - node.start_proc_time
    4.25 +    local child_real_time = 0
    4.26 +    local child_proc_time = 0
    4.27      for i, child in ipairs(node) do
    4.28 -      if child.start_hires_time and child.stop_hires_time then
    4.29 -        child_duration = child_duration + child.stop_hires_time - child.start_hires_time
    4.30 +      if child.start_real_time then
    4.31 +        child_real_time = child_real_time + child.stop_real_time - child.start_real_time
    4.32 +        child_proc_time = child_proc_time + child.stop_proc_time - child.start_proc_time
    4.33        end
    4.34      end
    4.35 -    local duration = total_duration - child_duration
    4.36 -    local start_text = math.floor(node.start_hires_time * 10000 + 0.5) / 10
    4.37 -    local total_duration_text = math.floor(total_duration * 10000 + 0.5) / 10
    4.38 -    local child_duration_text = math.floor(child_duration * 10000 + 0.5) / 10
    4.39 -    local duration_text = math.floor(duration * 10000 + 0.5) / 10
    4.40 -    slot.put('<div class="time">')
    4.41 -    slot.put('<span class="start_label">start:</span>')
    4.42 -    slot.put(" ")
    4.43 -    slot.put('<span class="start">' .. start_text .. 'ms</span>')
    4.44 -    slot.put(" | ")
    4.45 -    slot.put('<span class="duration_label">this:</span>')
    4.46 -    slot.put(" ")
    4.47 -    slot.put('<span class="duration">' .. duration_text .. 'ms</span>')
    4.48 -    slot.put(" | ")
    4.49 -    slot.put('<span class="child_duration_label">children:</span>')
    4.50 -    slot.put(" ")
    4.51 -    slot.put('<span class="child_duration">' .. child_duration_text .. 'ms</span>')
    4.52 -    slot.put(" | ")
    4.53 -    slot.put('<span class="total_duration_label">total:</span>')
    4.54 -    slot.put(" ")
    4.55 -    slot.put('<span class="total_duration">' .. total_duration_text .. 'ms</span>')
    4.56 -    slot.put('</div>')
    4.57 +    local real_time = total_real_time - child_real_time
    4.58 +    local proc_time = total_proc_time - child_proc_time
    4.59 +    slot.put(
    4.60 +      '<div class="time">',
    4.61 +      '<span class="duration_label">this:</span>',
    4.62 +      ' ',
    4.63 +      '<span class="duration">', format_time(real_time, proc_time), '</span>',
    4.64 +      ' | ',
    4.65 +      '<span class="child_duration_label">children:</span>',
    4.66 +      ' ',
    4.67 +      '<span class="child_duration">', format_time(child_real_time, child_proc_time), '</span>',
    4.68 +      ' | ',
    4.69 +      '<span class="total_duration_label">total:</span>',
    4.70 +      ' ',
    4.71 +      '<span class="total_duration">', format_time(total_real_time, total_proc_time), '</span>',
    4.72 +      '</div>'
    4.73 +    )
    4.74    end
    4.75  end
    4.76  local function close_head()

Impressum / About Us