--[[
@title lua-profiler
@version 1.1
@description Code profiling for Lua based code;
The output is a report file (text) and optionally to a console or other logger.

The initial reason for this project was to reduce  misinterpretations of code profiling
caused by the lengthy measurement time of the 'ProFi' profiler v1.3;
and then to remove the self-profiler functions from the output report.

The profiler code has been substantially rewritten to remove dependence to the 'OO'
class definitions, and repetitions in code;
thus this profiler has a smaller code footprint and reduced execution time up to ~900% faster.

The second purpose was to allow slight customisation of the output report,
which I have parametrised the output report and rewritten.

Caveats: I didn't include an 'inspection' function that ProFi had, also the RAM
output is gone. Please configure the profiler output in top of the code, particularly the
location of the profiler source file (if not in the 'main' root source directory).

@authors Charles Mallah
@copyright (c) 2018-2020 Charles Mallah
@license MIT license

@sample Output will be generated like this, all output here is ordered by time:
`> TOTAL TIME   = 0.030000 s
`--------------------------------------------------------------------------------------
`| FILE                : FUNCTION                    : LINE   : TIME   : %     : #    |
`--------------------------------------------------------------------------------------
`| map                 : new                         :   301  : 0.1330 : 52.2  :    2 |
`| map                 : unpackTileLayer             :   197  : 0.0970 : 38.0  :   36 |
`| engine              : loadAtlas                   :   512  : 0.0780 : 30.6  :    1 |
`| map                 : init                        :   292  : 0.0780 : 30.6  :    1 |
`| map                 : setTile                     :    38  : 0.0500 : 19.6  : 20963|
`| engine              : new                         :   157  : 0.0220 : 8.6   :    1 |
`| map                 : unpackObjectLayer           :   281  : 0.0190 : 7.5   :    2 |
`--------------------------------------------------------------------------------------
`| ui                  : sizeCharLimit               :   328  : ~      : ~     :    2 |
`| modules/profiler    : stop                        :   192  : ~      : ~     :    1 |
`| ui                  : sizeWidthToScreenWidthHalf  :   301  : ~      : ~     :    4 |
`| map                 : setRectGridTo               :   255  : ~      : ~     :    7 |
`| ui                  : sizeWidthToScreenWidth      :   295  : ~      : ~     :   11 |
`| character           : warp                        :    32  : ~      : ~     :   15 |
`| panels              : Anon                        :     0  : ~      : ~     :    1 |
`--------------------------------------------------------------------------------------

The partition splits the notable code that is running the slowest, all other code is running
too fast to determine anything specific, instead of displaying "0.0000" the script will tidy
this up as "~". Table headers % and # refer to percentage total time, and function call count.

@example Print a profile report of a code block
`local profiler = require("profiler")
`profiler.start()
`-- Code block and/or called functions to profile --
`profiler.stop()
`profiler.report("profiler.log")

@example Profile a code block and allow mirror print to a custom print function
`local profiler = require("profiler")
`function exampleConsolePrint()
`  -- Custom function in your code-base to print to file or console --
`end
`profiler.attachPrintFunction(exampleConsolePrint, true)
`profiler.start()
`-- Code block and/or called functions to profile --
`profiler.stop()
`profiler.report("profiler.log") -- exampleConsolePrint will now be called from this

@example Override a configuration parameter programmatically; insert your override values into a
new table using the matched key names:

`local overrides = {
`                    fW = 100, -- Change the file column to 100 characters (from 20)
`                    fnW = 120, -- Change the function column to 120 characters (from 28)
`                  }
`profiler.configuration(overrides)
]]

--[[ Configuration ]]--

local config = {
    outputFile = "Profiler.lua", -- Name of this profiler (to remove itself from reports)
    emptyToThis = "~", -- Rows with no time are set to this value
    fW = 30, -- Width of the file column
    fnW = 48, -- Width of the function name column
    lW = 9, -- Width of the line column
    tW = 12, -- Width of the time taken column
    rW = 9, -- Width of the relative percentage column
    cW = 12, -- Width of the call count column
    reportSaved = "> Report saved to: ", -- Text for the file output confirmation
  }

  --[[ Locals ]]--

  local module = {}
  local getTime = os.clock
  local string, debug, table = string, debug, table
  local reportCache = {}
  local allReports = {}
  local reportCount = 0
  local startTime = 0
  local stopTime = 0
  local printFun = nil
  local verbosePrint = false

  local outputHeader, formatHeader, outputTitle, formatOutput, formatTotalTime
  local formatFunLine, formatFunTime, formatFunRelative, formatFunCount, divider, nilTime

  local function deepCopy(input)
    if type(input) == "table" then
      local output = {}
      for i, o in next, input, nil do
        output[deepCopy(i)] = deepCopy(o)
      end
      return output
    else
      return input
    end
  end

  local function charRepetition(n, character)
    local s = ""
    character = character or " "
    for _ = 1, n do
      s = s..character
    end
    return s
  end

  local function singleSearchReturn(inputString, search)
    for _ in string.gmatch(inputString, search) do -- luacheck: ignore
      return true
    end
    return false
  end

  local function rebuildColumnPatterns()
    local c = config
    local str = "s: %-"
    outputHeader = "| %-"..c.fW..str..c.fnW..str..c.lW..str..c.tW..str..c.rW..str..c.cW.."s|\n"
    formatHeader = string.format(outputHeader, "FILE", "FUNCTION", "LINE", "TIME", "%", "#")
    outputTitle = "%-"..c.fW.."."..c.fW..str..c.fnW.."."..c.fnW..str..c.lW.."s"
    formatOutput = "| %s: %-"..c.tW..str..c.rW..str..c.cW.."s|\n"
    formatTotalTime = "Total time: %f s\n"
    formatFunLine = "%"..(c.lW - 2).."i"
    formatFunTime = "%04.4f"
    formatFunRelative = "%03.1f"
    formatFunCount = "%"..(c.cW - 1).."i"
    divider = charRepetition(#formatHeader - 1, "-").."\n"
    -- nilTime = "0."..charRepetition(c.tW - 3, "0")
    nilTime = "0.0000"
  end

  local function functionReport(information)
    local src = information.short_src
    if not src then
      src = "<C>"
    elseif string.sub(src, #src - 3, #src) == ".lua" then
      src = string.sub(src, 1, #src - 4)
    end
    local name = information.name
    if not name then
      name = "Anon"
    elseif string.sub(name, #name - 1, #name) == "_l" then
      name = string.sub(name, 1, #name - 2)
    end
    local title = string.format(outputTitle, src, name,
    string.format(formatFunLine, information.linedefined or 0))
    local report = reportCache[title]
    if not report then
      report = {
        title = string.format(outputTitle, src, name,
        string.format(formatFunLine, information.linedefined or 0)),
        count = 0, timer = 0,
      }
      reportCache[title] = report
      reportCount = reportCount + 1
      allReports[reportCount] = report
    end
    return report
  end

  local onDebugHook = function(hookType)
    local information = debug.getinfo(2, "nS")
    if hookType == "call" then
      local funcReport = functionReport(information)
      funcReport.callTime = getTime()
      funcReport.count = funcReport.count + 1
    elseif hookType == "return" then
      local funcReport = functionReport(information)
      if funcReport.callTime and funcReport.count > 0 then
        funcReport.timer = funcReport.timer + (getTime() - funcReport.callTime)
      end
    end
  end

  --[[ Functions ]]--

  --[[Attach a print function to the profiler, to receive a single string parameter
  @param fn (function) <required>
  @param verbose (boolean) <default: false>
  ]]
  function module.attachPrintFunction(fn, verbose)
    printFun = fn
    verbosePrint = verbose or false
  end

  --[[Start the profiling
  ]]
  function module.start()
    if not outputHeader then
      rebuildColumnPatterns()
    end
    reportCache = {}
    allReports = {}
    reportCount = 0
    startTime = getTime()
    stopTime = nil
    debug.sethook(onDebugHook, "cr", 0)
  end

  --[[Stop profiling
  ]]
  function module.stop()
    stopTime = getTime()
    debug.sethook()
  end

  --[[Writes the profile report to file (will stop profiling if not stopped already)
  @param filename (string) <default: "profiler.log"> [File will be created and overwritten]
  ]]
  function module.report(filename)
    if not stopTime then
      module.stop()
    end
    filename = filename or "profiler.log"
    table.sort(allReports, function(a, b) return a.timer > b.timer end)
    local fileWriter = io.open(filename, "w+")
    local divide = false
    local totalTime = stopTime - startTime
    local totalTimeOutput = "> "..string.format(formatTotalTime, totalTime)
    fileWriter:write(totalTimeOutput)
    if printFun ~= nil then
      printFun(totalTimeOutput)
    end
    fileWriter:write(divider)
    fileWriter:write(formatHeader)
    fileWriter:write(divider)
    for i = 1, reportCount do
      local funcReport = allReports[i]
      if funcReport.count > 0 and funcReport.timer <= totalTime then
        local printThis = true
        if config.outputFile ~= "" then
          if singleSearchReturn(funcReport.title, config.outputFile) then
            printThis = false
          end
        end
        if printThis then -- Remove lines that are not needed
          if singleSearchReturn(funcReport.title, "[[C]]") then
            printThis = false
          end
        end
        if printThis then
          local count = string.format(formatFunCount, funcReport.count)
          local timer = string.format(formatFunTime, funcReport.timer)
          local relTime = string.format(formatFunRelative, (funcReport.timer / totalTime) * 100)
          if not divide and timer == nilTime then
            fileWriter:write(divider)
            divide = true
          end
          if timer == nilTime then
            timer = config.emptyToThis
            relTime = config.emptyToThis
          end
          -- Build final line
          local output = string.format(formatOutput, funcReport.title, timer, relTime, count)
          fileWriter:write(output)
          -- This is a verbose print to the attached print function
          if printFun ~= nil and verbosePrint then
            printFun(output)
          end
        end
      end
    end
    fileWriter:write(divider)
    fileWriter:close()
    if printFun ~= nil then
      printFun(config.reportSaved.."'"..filename.."'")
    end
  end

  --[[Modify the configuration of this module programmatically;
  Provide a table with keys that share the same name as the configuration parameters:
  @param overrides (table) <required> [Each key is from a valid name, the value is the override]
  @unpack config
  ]]
  function module.configuration(overrides)
    local safe = deepCopy(overrides)
    for k, v in pairs(safe) do
      if config[k] == nil then
        print("error: override field '"..k.."' not found (configuration)")
      else
        config[k] = v
      end
    end
    rebuildColumnPatterns()
  end

  --[[ End ]]--
  return module
