feat(core): Add command stack system for better error output

Document location traces are printed on error, and if -t is enabled,
also on warning. Also print stack traces on SU.error.

core/inputs-common.lua

@@ -55,17 +55,22 @@ SILE.process = function(input)
   if SU.debugging("ast") then
     debugAST(input,0)
   end
+
   for i=1, #input do
-    SILE.currentCommand = input[i]
     local content = input[i]
+
     if type(content) == "string" then
       SILE.typesetter:typeset(content)
     elseif SILE.Commands[content.tag] then
       SILE.call(content.tag, content.attr, content)
     elseif content.id == "texlike_stuff" or (not content.tag and not content.id) then
+      local pId = SILE.currentCommandStack:pushContent(content, "texlike_stuff")
       SILE.process(content)
+      SILE.currentCommandStack:pop(pId)
     else
+      local pId = SILE.currentCommandStack:pushContent(content)
       SU.error("Unknown command "..(content.tag or content.id))
+      SILE.currentCommandStack:pop(pId)
     end
   end
 end

core/inputs-xml.lua

@@ -16,7 +16,7 @@ SILE.inputs.XML = {
       end
       SILE.inputs.common.init(doc, content)
     end
-    SILE.currentCommand = content
+
     if SILE.Commands[content.tag] then
       SILE.call(content.tag, content.attr, content)
     else

core/sile.lua

@@ -132,6 +132,7 @@ Options:
   -- http://lua-users.org/wiki/VarargTheSecondClassCitizen
   local identity = function (...) return unpack({...}, 1, select('#', ...)) end
   SILE.errorHandler = opts.traceback and debug.traceback or identity
+  SILE.detailedErrors = not not opts.traceback
 end
 
 function SILE.initRepl ()
@@ -240,10 +241,250 @@ function SILE.resolveFile(filename, pathprefix)
   return nil
 end
 
+SILE.currentCommandStack = {
+  --- Internal: push-pop balance checking ID
+  _lastPushId = 0,
+  --- Internal: Function assigned to frames to convert them to string
+  _frameToString = function(self, skipFile, withAttrs)
+    local str
+    if skipFile or not self.file then
+      str = ""
+    else
+      str = self.file .. " "
+    end
+
+    if self.line then
+      str = str .. "l." .. self.line .. " "
+      if self.column then
+        str = str .. "col." .. self.column .. " "
+      end
+    end
+
+    if self.tag then
+      -- Command
+      str = str .. "\\" .. self.tag
+      if withAttrs then
+        str = str .. "["
+        local first = true
+        for key, value in pairs(self.options) do
+          if first then first = false else str = str .. ", " end
+          str = str .. key .. "=" .. value
+        end
+        str = str .. "]"
+      end
+    elseif self.text then
+      -- Literal string
+      local text = self.text
+      if text:len() > 20 then
+        text = text:sub(1, 18) .. "…"
+      end
+      text = text:gsub("\n", "␤"):gsub("\t", "␉"):gsub("\v", "␋")
+
+      str = str .. "\"" .. text .. "\""
+    else
+      -- Unknown
+      str = str .. type(self.content) .. "(" .. self.content .. ")"
+    end
+
+    --str = str .. "\n\n" .. self.pushTrace .. "\n"
+
+    return str
+  end
+}
+--- Push a command frame on to the stack to record the execution trace for debugging.
+--- Carries information about the command call, not the command itself.
+--- Must be popped with `pop(returnOfPush)`.
+function SILE.currentCommandStack:pushCommand(tag, line, column, options, file)
+  return self:_pushFrame({
+    tag = tag or "???",
+    file = file or SILE.currentlyProcessingFile,
+    line = line,
+    column = column,
+    options = options or {}
+  })
+end
+--- Push a command frame on to the stack to record the execution trace for debugging.
+--- Command arguments are inferred from AST content, any item may be overridden.
+--- Must be popped with `pop(returnOfPush)`.
+function SILE.currentCommandStack:pushContent(content, tag, line, column, options, file)
+  return self:_pushFrame({
+    tag = tag or (type(content) == "table" and content.tag) or "???",
+    file = file or SILE.currentlyProcessingFile,
+    line = line or (type(content) == "table" and content.line),
+    column = column or (type(content) == "table" and content.col),
+    options = options or (type(content) == "table" and content.attr) or {}
+  })
+end
+--- Push a text that is going to get typeset on to the stack to record the execution trace for debugging.
+--- Must be popped with `pop(returnOfPush)`.
+function SILE.currentCommandStack:pushText(text, line, column, file)
+  return self:_pushFrame({
+    text = text,
+    file = file,
+    line = line,
+    column = column
+  })
+end
+--- Internal: Push complete frame
+function SILE.currentCommandStack:_pushFrame(frame)
+  frame.toString = self._frameToString
+  frame.typesetter = SILE.typesetter
+  --frame.pushTrace = debug.traceback(nil, 3)
+
+  -- Push the frame
+  if SU.debugging("commandStack") then
+    print(string.rep(" ", #self) .. "PUSH(" .. frame:toString(false, true) .. ")")
+  end
+  self[#self + 1] = frame
+  self.lastCommand = nil
+  self._lastPushId = self._lastPushId + 1
+  frame.pushId = self._lastPushId
+  return self._lastPushId
+end
+--- Pop previously pushed command from the stack.
+--- Return value of `push` function must be provided as argument to check for balanced usage.
+function SILE.currentCommandStack:pop(pushId)
+  if type(pushId) ~= "number" then
+    SU.error("SILE.currentCommandStack:pop's argument must be the result value of the corresponding push", true)
+  end
+
+  -- First verify that push/pop is balanced
+  local popped = self[#self]
+  if popped.pushId ~= pushId then
+    local message = "Unbalanced content push/pop"
+    local debug = SILE.detailedErrors or SU.debugging("commandStack")
+    if debug then
+      message = message .. ". Expected " .. popped.pushId .. " - (" .. popped:toString() .. "), got " .. pushId
+    end
+    SU.warn(message, debug)
+  else
+    -- Correctly balanced: pop the frame
+    self.lastCommand = popped
+    self[#self] = nil
+    if SU.debugging("commandStack") then
+      print(string.rep(" ", #self) .. "POP(" .. popped:toString(false, true) .. ")")
+    end
+  end
+end
+--- Returns a stack of commands, which can be used to show information about location in document.
+--- Most relevant object is in the last index.
+--- Second return: recently popped value which could provide extra location information
+function SILE.currentCommandStack:locationStack(currentTypesetterOnly)
+  local result = {}
+
+  for i = 1, #self do
+    if not currentTypesetterOnly or (self[i].typesetter == SILE.typesetter) then
+      result[#result + 1] = self[i]
+    end
+  end
+
+  local extra = self.lastCommand
+  if (not extra) -- skip other checks if extra is nil
+          or extra == result[#result] -- no extra if it already is on the stack
+          or (currentTypesetterOnly and (extra.typesetter ~= SILE.typesetter)) -- no extra if wrong typesetter
+  then
+    extra = nil
+  end
+
+  return result, extra
+end
+
+--- Internal: Format top of the stack from locationStack(), may return nil
+function SILE.currentCommandStack:_locationTraceEntry(stack, after)
+  -- Stack may contain mix of tables and strings.
+  -- We hope to get a table, because that contains position information.
+  -- A string may also be useful, but preferably with a table as well.
+  local top = stack[#stack]
+
+  if not top then
+    -- Stack is empty, there is not much we can do
+    if after then
+      return "after " .. after:toString()
+    else
+      return nil
+    end
+  end
+
+  local base -- real content frame with location information
+  local string -- string being typeset, closer to the real problem, but has no location information
+  if type(top.content) == "table" then
+    base = top
+    string = nil
+  else
+    string = top
+    for i = #stack - 1, 1, -1 do
+      if type(stack[i].content) == "table" then
+        base = stack[i]
+        break
+      end
+    end
+  end
+
+  -- Join
+  local info
+  if not string then
+    info = base:toString()
+  else
+    info = string:toString()
+    if base then
+      info = info .. " near " .. base:toString(--[[skipFile=]] base.file == string.file)
+    end
+  end
+
+  -- Print after, if it is in a relevant file
+  if after and (not base or after.file == base.file) then
+    info = info .. " after " .. after:toString(--[[skipFile=]] true)
+  end
+
+  return info
+end
+--- Returns short string with most relevant location information for user messages.
+function SILE.currentCommandStack:locationInfo()
+  local stack, after = self:locationStack()
+  return self:_locationTraceEntry(stack, after) or SILE.currentlyProcessingFile or "<nowhere>"
+end
+--- Returns multiline trace string, with full document location information for user messages.
+function SILE.currentCommandStack:locationTrace()
+  local stack, after = self:locationStack()
+
+  local prefix = "  at "
+  local trace = self:_locationTraceEntry({ stack[#stack] } --[[we handle rest of the stack ourselves]], after)
+  if not trace then
+    -- There is nothing else then
+    return prefix .. (SILE.currentlyProcessingFile or "<nowhere>") .. "\n"
+  end
+  trace = prefix .. trace .. "\n"
+
+  -- Iterate backwards, skipping the last element
+  for i = #stack - 1, 1, -1 do
+    local s = stack[i]
+    trace = trace .. prefix .. s:toString() .. "\n"
+  end
+
+  return trace
+end
+
 function SILE.call(cmd, options, content)
-  SILE.currentCommand = content
+  -- Prepare trace information for command stack
+  local file, line, column
+  if SILE.detailedErrors and not (type(content) == "table" and content.line) then
+    -- This call is from code (no content.line) and we want to spend the time
+    -- to determine everything we need about the caller
+    local caller = debug.getinfo(2, "Sl")
+    file = caller.short_src
+    line = caller.currentline
+  elseif type(content) == "table" then
+    line = content.line
+    column = content.col
+  end
+
+  local pId = SILE.currentCommandStack:pushCommand(cmd, line, column, options, file)
+
   if not SILE.Commands[cmd] then SU.error("Unknown command "..cmd) end
-  return SILE.Commands[cmd](options or {}, content or {})
+  local result = SILE.Commands[cmd](options or {}, content or {})
+
+  SILE.currentCommandStack:pop(pId)
+  return result
 end
 
 return SILE

core/typesetter.lua

@@ -183,13 +183,16 @@ SILE.defaultTypesetter = std.object {
   -- Actual typesetting functions
   typeset = function (self, text)
     if text:match("^%\r?\n$") then return end
+
+    local pId = SILE.currentCommandStack:pushText(text)
     for token in SU.gtoke(text,SILE.settings.get("typesetter.parseppattern")) do
       if (token.separator) then
         self:endline()
       else
         self:setpar(token.string)
       end
     end
+    SILE.currentCommandStack:pop(pId)
   end,
 
   initline = function (self)

core/utilities.lua

@@ -25,21 +25,43 @@ if not table.maxn then
   end
 end
 
-utilities.error = function (message, bug)
-  if(SILE.currentCommand and type(SILE.currentCommand) == "table") then
-    io.stderr:write("\n! "..message.. " at "..SILE.currentlyProcessingFile.." l."..(SILE.currentCommand.line)..", col."..(SILE.currentCommand.col))
+utilities.error = function(message, bug)
+  io.stderr:write("\n! " .. message)
+  if not SILE.detailedErrors and not bug then
+    -- Normal operation, show only inline info
+    io.stderr:write(" at " .. SILE.currentCommandStack:locationInfo())
+    io.stderr:write("\n")
   else
-    io.stderr:write("\n! "..message.. " at "..SILE.currentlyProcessingFile)
+    -- Using full error handler, print whole trace
+    io.stderr:write("\n")
+    io.stderr:write(SILE.currentCommandStack:locationTrace())
+    io.stderr:write(debug.traceback(nil, 2))
+    io.stderr:write("\n")
   end
-  if bug then io.stderr:write(debug.traceback()) end
-  io.stderr:write("\n")
+  io.stderr:flush()
+
   SILE.outputter:finish()
   os.exit(1)
 end
 
-utilities.warn = function (message)
-  io.stderr:write("\n! "..message.."\n")
-  --print(debug.traceback())
+utilities.warn = function (message, bug)
+  io.stderr:write("\n! "..message)
+  if not (SILE.detailedErrors or bug) then
+    -- Normal operation, show only inline info
+    io.stderr:write(" at "..SILE.currentCommandStack:locationInfo())
+    io.stderr:write("\n")
+  else
+    -- Show full trace
+    io.stderr:write("\n")
+    io.stderr:write(SILE.currentCommandStack:locationTrace())
+  end
+
+  if bug then
+    -- Something weird has happened, but the program can continue
+    io.stderr:write(debug.traceback(nil, 2))
+    io.stderr:write("\n")
+  end
+
   --os.exit(1)
 end