Hi Codeans,
As my game is maturing and I have many classes and it is all getting hideously complex, I have found that debugging via print statements to the console is getting pretty tough, they get truncated sometimes etc…
I have therefore written a simple logging framework to generate a log file which can then be ‘flushed’ to a tab in the project…
Here is the class:
-- Log4Codea: Simon Brooke 2014
Log4Codea = class()
Log4Codea.DEBUG="__1_DEBUG"
Log4Codea.INFO ="__2_INFO"
Log4Codea.WARN ="__3_WARN"
Log4Codea.ERROR="__4_ERROR"
Log4Codea.InfoLevels = {
[Log4Codea.DEBUG]="DEBUG",
[Log4Codea.INFO] ="INFO ",
[Log4Codea.WARN]="WARN ",
[Log4Codea.ERROR]="ERROR"
}
function Log4Codea:init(file, level)
assert(file, "No file specified")
self.level = level or Log4Codea.DEBUG
assert(Log4Codea.InfoLevels[self.level], "Log4Codea:init: Invalid level: "..self.level)
self.file = os.getenv("HOME").."/Documents/"..file
self.shortName = file
self:prepareLog()
self.fileHandle = io.open(self.file, "a+")
end
function Log4Codea:setLevel(level)
assert(Log4Codea.InfoLevels[level], "Log4Codea:setLevel: Invalid level: "..tostring(level))
self.level = level
end
function Log4Codea:prepareLog()
local handle = io.open(self.file, "w")
assert(handle, "Log4Codea: Unable to open file: "..self.file)
handle:write("-- Log4Codea: Date: "..os.date("%Y-%m-%d").."..\\r\
")
handle:close()
end
function Log4Codea:log(...)
-- Check last argument of arg (variable arguments) for level
local level = Log4Codea.DEBUG
if(Log4Codea.InfoLevels[arg[arg.n]]) then
level = arg[arg.n]
arg[arg.n] = nil
arg.n = arg.n - 1
end
if(level >= self.level) then
if(__oldprint) then __oldprint(unpack(arg)) end
-- Create log line, date etc.
local line = ""..os.date("%H:%M:%S").." "..Log4Codea.InfoLevels[level]..": "
for k,v in ipairs(arg) do
line = line .. tostring(v).." "
end
self:write(line)
end
end
function Log4Codea:logStack(...)
local level = Log4Codea.DEBUG
if(Log4Codea.InfoLevels[arg[arg.n]]) then
level = arg[arg.n]
arg[arg.n] = nil
arg.n = arg.n - 1
end
if(level >= self.level) then
if(__oldprint) then __oldprint(value) end
-- Create log line, date etc.
local line = ""..os.date("%H:%M:%S").." "..Log4Codea.InfoLevels[level]..": "
for k,v in ipairs(arg) do
line = line .. tostring(v).." "
end
line = line .."\\r\
"..debug.traceback():gsub("\
","\\r\
")
self:write(line)
end
end
function Log4Codea:write(value)
self.fileHandle:write(value.."\\r\
")
end
function Log4Codea:read()
local buf = { "--[[\\r\
" }
for line in io.lines(self.file) do
table.insert(buf, line)
end
return table.concat(buf).."\\r\
--]]"
end
function Log4Codea:flush()
self.fileHandle:close()
saveProjectTab(self.shortName, self:read())
end
Basically you create a Log4Codea object, then call the log() method, e.g. in Main…
function setup()
-- Logging
_logger = Log4Codea("game.log")
...
end
The default logger level is Log4Codea.DEBUG, you can pass a different level to the constructor (see class code above)…
Then you can do things like:
_logger:log("My variable values", a, b, c)
_logger:log("My whotsit values", x, y, z, Log4Codea.INFO)
The :log() method takes variable arguments (…) and detects if the last argument is a Log4Codea log level, if it is then it applies that level, otherwise it logs at debug level.
At the end you MUST execute _logger:flush() in the console to close the file and display the log file in a project tab for inspection….
Each time the logger is created, the previous log gets overwritten unless you specify a different name…
Example output:
--[[
-- Log4Codea: Date: 2014-01-15..
10:10:50 INFO : math.randomseed: 1.38978e+09
10:11:01 DEBUG: MapView:init(2)
10:11:02 DEBUG: DebugTimer:create: water
10:11:02 DEBUG: shaderVal 0.488922
10:11:07 DEBUG: DebugTimer:report: water 5.61683
10:11:07 DEBUG: DebugTimer:create: water
--]]
Now, I hear you say, that’s all very well Mr Brookesi, but I have hundreds of print() statements and I can’t be bothered to replace them all with this newfangled loggery trickery. Never fear gentle user, if you actually instantiate the logger thusly:
function setup()
-- Logging
__oldprint=print
_logger = Log4Codea("game.log", Log4Codea.INFO)
print = function(...) _logger:log(...) end
...
end
Then magically every print statement writes to your log file instead, and you can just pick and choose certain print statements and add a log level, e.g.:
print("I'm a happy print statement", Log4Codea.INFO)
So instantiating the logger as e.g. INFO would initially hide all your print() statements, and you can selectively turn them on…
Note: If you DO override print, and you assign it to the function ‘__oldprint’, then this is detected in the framework and it will still log to the console if the log level allows it. This allows for the fact that you will want to quickly check the console during runtime, but still have the opportunity to view the same data in the logfile later…
You can also do :logStack(message, [log level]) to get a stacktrace, it uses debug.traceback under the covers…
I’m sure it can be improved, but its working well for me!
You can of course instantiate multiple loggers if you want to split logging into ‘streams’…
And theoretically you could ship this with your app and have a ‘send’ function that posts the file via http or something if users had problems…
Regards,
Brookesi