ULX

Author Topic: LuaLog  (Read 3438 times)

0 Members and 1 Guest are viewing this topic.

Offline Buzzkill

  • Respected Community Member
  • Full Member
  • *****
  • Posts: 176
  • Karma: 59
    • The Hundred Acre Bloodbath
LuaLog
« on: March 05, 2015, 09:32:28 AM »
This is something I started working on yesterday, and is a mix of an actual need for me as well as my glorified "Hello World"  in Lua (everything I've done up until now in Lua has been done strictly within GMod).

This will parse srcds log files and insert them into a sqlite3 db. It provides some rudimentary config control, as well as supporting multiple servers on the same box.  Ultimately I envision building a query interface for it within GMod, and perhaps migrating the entire thing into GMod directly (which is why I chose to build it in Lua versus Python or even perl, for that matter). 

I'm posting it because it's probably the first thing if any substance I can give back, and I'm posting it here because it's not ULX/Ulib dependent. I don't expect this to be of much value to anyone as-is, but perhaps some of the logic will be useful to someone under the right circumstances.  As it grows and becomes more solid it may attract more attention.

Code: [Select]
local driver = require "luasql.sqlite3"

-- user configuration --
local logDirs = {sbox1 = "/home/steam/sbox1/garrysmod/logs", jb1 = "/home/steam/jb1/garrysmod/logs", zs1 = "/home/steam/zs1/garrysmod/logs" };
local fileMask = "L*.log"
local ShouldArchiveFiles = true;
local targetDB = "/var/db/srcdslog.db"
local ShouldFlushDB = false;

local ShouldProcessLuaErrors = false;
local ShouldProcessRcon = false;
local ShouldProcessUnknown = true;
local ShouldProcessAdminSay = false; -- not yet implemented
local ShouldProcessPrivateSay = false; -- not yet implemented


-- psuedo enums --
-- Establish some positional info for matches
local LOGDT_START, LOGDT_END, LOGTM_START, LOGTM_END, LOGENTRY_START = 3,12, 16,23, 26

-- Establish internal logging types
local LOGTYPE_ERROR, LOGTYPE_WARNING, LOGTYPE_INFO, LOGTYPE_DEBUG  = 1,2,3,4
local LOGTYPEMSG = {"Error", "Warning", "Info", "Debug"}

-- Establish context types for srcds log entries
local LOGCONTEXT_UNKNOWN, LOGCONTEXT_SAY, LOGCONTEXT_CONNECT, LOGCONTEXT_VALIDATED, LOGCONTEXT_ENTERED, LOGCONTEXT_ULXCMD, LOGCONTEXT_RCON, LOGCONTEXT_BANID, LOGCONTEXT_LUAERROR, LOGCONTEXT_LUAERRORDETAIL, LOGCONTEXT_SAYTEAM, LOGCONTEXT_DISCONNECTED = 1,2,3,4,5,6,7,8,9,10,11,12
local LOGCONTEXTMSG = {"Unknown","Say", "Connected", "Validated", "Entered", "ULX Command", "RCON", "Ban", "Lua Error", "Lua Error Detail", "SayTeam", "Disconnected"}

-- Establish basic check pattents
local LOGCONTEXT_SICHECKS = {"say_team", "say", "connected, address", "STEAM USERID validated", "entered the game", "disconnected"}
local LOGCONTEXT_SICHECKID = {LOGCONTEXT_SAYTEAM, LOGCONTEXT_SAY,LOGCONTEXT_CONNECT, LOGCONTEXT_VALIDATED, LOGCONTEXT_ENTERED, LOGCONTEXT_DISCONNECTED}

-- Establish secondary checks
local LOGCONTEXT_NONSICHECKS = {"%[ULX%]","rcon from","Banid:", "Lua Error:"}
local LOGCONTEXT_NONSICHECKID = {LOGCONTEXT_ULXCMD, LOGCONTEXT_RCON, LOGCONTEXT_BANID, LOGCONTEXT_LUAERROR}


-- logging level
local ShowLogLevel = LOGTYPE_INFO

------------------------------------------------------------------------------------------------------------------------

-- Misc globals --
local linesWritten = 0;
local ProcessingLuaError = false
local lastLuaErrorDate, lastLuaErrorTime = "",""
local currLogFileTag = ""
local currServer =""
local con, env






-- Some helper functions --
local function log(type, ...)
if (type == nil) then type = LOGTYPE_INFO end;
if (type > ShowLogLevel) then return end;
local printResult = LOGTYPEMSG[type] .. "\t"

for i,v in ipairs(arg) do
printResult = printResult .. tostring(v) .. "\t"
end
print (printResult);
end


local function DeleteExistingTag(logtag)
log(LOGTYPE_INFO,"Removing entries for "..currServer..logtag)
res = assert (con:execute(string.format([[DELETE from logs where logfile = '%s']], currServer..logtag)))
end


local function MoveFile(logfile)
os.rename(logfile, logfile..".archive")
end


function quotetrim(s)
  -- from PiL2 20.4
  s = s:gsub("^%s*(.-)%s*$", "%1")
  return (s:gsub("^\"*(.-)\"*$", "%1"))
end


local function IsLineValid(logline)
local t = string.match(logline, 'L %d%d/%d%d/%d%d%d%d [-] %d%d:%d%d:%d%d: ')
if (t == nil) then return false
else return true end
end


----- Main code

local function ProcessLineContext(logdt, logtm, logentry)

log (LOGTYPE_DEBUG, "Processing context: ", logentry);
local contextid = LOGCONTEXT_UNKNOWN
local nick, steamid, slot, ip, team, truelogentry = "","","","",""
local cmd1, cmd2 = "",""

-- Do basic checks for a standard steam info line plus context
nick, slot, steamid, team, truelogentry  = string.match(logentry, '"(.*)<(%d+)><(.+)><(.*)>" (.*)')
if (steamid ~= nil) then -- we have a typical Steam entry, like a say or a join
log(LOGTYPE_DEBUG, "Steam Info parse:", nick, steamid, slot, ip, team, contextid, truelogentry)
for key,value in pairs(LOGCONTEXT_SICHECKS) do
local part1, part2 = string.match(truelogentry, '^('..value..')(.*)')
if (part1 ~= nil) then
contextid = LOGCONTEXT_SICHECKID[key]
truelogentry = quotetrim(part2)
break
end
end

else 
truelogentry = logentry -- default
nick, steamid, slot, ip, team = "","","","",""  -- clear them
log (LOGTYPE_DEBUG, "No Steam Info found", logentry)

-- There are other checks to do.
for key,value in pairs(LOGCONTEXT_NONSICHECKS) do
local part1 = string.match(truelogentry, '^('..value..')')
if (part1 ~= nil) then
contextid = LOGCONTEXT_NONSICHECKID[key]
truelogentry = truelogentry
break
end
end

end

-- if we're processing lua error details out of bound and we get something other than unknown, turn off error processing
if (ProcessingLuaError and contextid ~= LOGCONTEXT_UNKNOWN) then
ProcessingLuaError = false;
end

-- if we encountered a lua error, prep to record future lines against it
if (contextid == LOGCONTEXT_LUAERROR and ShouldProcessLuaErrors) then
ProcessingLuaError = true;
lastLuaErrorDate = logdt
lastLuaErrorTime = logtm
end

-- we have an unknown line during lua error processing -- it's the stack.
if (contextid == LOGCONTEXT_UNKNOWN and ProcessingLuaError) then
contextid = LOGCONTEXT_LUAERRORDETAIL
end

if (contextid == LOGCONTEXT_RCON and ShouldProcessRcon == false) then
return
end

log(LOGTYPE_DEBUG,LOGCONTEXTMSG[contextid], nick, steamid, slot, ip, team, truelogentry)

if (contextid ~= LOGCONTEXT_UNKNOWN or ShouldProcessUnknown == true) then
linesWritten = linesWritten + 1
local logdatetime = logdt .. ' ' .. logtm

res = assert (con:execute(string.format([[INSERT INTO logs (server, logfile, logrowid, logdatetime, context, logentry, nick, steamid, ip, team)
VALUES ('%s','%s', %d, '%s', '%s', '%s', '%s', '%s','%s','%s')]], currServer, currServer..currLogFileTag,linesWritten, logdatetime,LOGCONTEXTMSG[contextid], con:escape(truelogentry), con:escape(nick), steamid, ip, team )))
end
end


local function ProcessLine(rownum, logline)
log (LOGTYPE_DEBUG, "Processing line # "..rownum, logline);
if (IsLineValid(logline)) then
local logdt = string.sub(logline,LOGDT_START,LOGDT_END)
local logtm = string.sub(logline,LOGTM_START,LOGTM_END)
local logentry = string.sub(logline,LOGENTRY_START)
ProcessLineContext(logdt, logtm, logentry)
else
if (ProcessingLuaError) then
ProcessLineContext(lastLuaErrorDate, lastLuaErrorTime, logline)
else
log (LOGTYPE_DEBUG, "Row number "..rownum.." rejected. Not a valid log entry");
end
end
end

local function ProcessFile(logfile)
log (nil, "Processing: "..logfile);
currLogFileTag = string.match(logfile, ".-([^\\/]-%.?[^%.\\/]*)$")
currLogFileTag = string.match(currLogFileTag,"([^%.]*)")
DeleteExistingTag(currLogFileTag)

lines = {}
    for line in io.lines(logfile) do
log(LOGTYPE_DEBUG, line)
lines[#lines+1] = line;
end
log(nil, "Lines loaded: "..#lines);
linesWritten = 0;
for key,logline in pairs(lines) do
ProcessLine(key, logline)
end
log(nil, "Lines written: "..linesWritten);
end


local function CheckAndCreateTable()
-- reset our table
if (ShouldFlushDB) then res = con:execute"DROP TABLE logs" end
res = assert (con:execute[[
CREATE TABLE IF NOT EXISTS logs(
server varchar(50),
logfile varchar(50),
logrowid int,
logdatetime datetime,
nick varchar(50),
steamid varchar(50),
slot int,
ip varchar(50),
context varchar(50),
team varchar(50),
logentry varchar(255)
)
]])
end


-- Entry point --

env = assert (driver.sqlite3())
con = assert (env:connect(targetDB))
CheckAndCreateTable()
for key, value in pairs(logDirs) do

local filesToProcess = {}
dir = value
currServer = key
log (nil,"Building log file list")
local p = io.popen('find "'..dir..'" -type f -name "'..fileMask..'" | xargs ls -1tr') 

for file in p:lines() do                         --Loop through all files
   filesToProcess[#filesToProcess + 1] = file;
   log (LOGTYPE_DEBUG, "Queued for processing: "..filesToProcess[#filesToProcess]);
end
for key,logfile in pairs(filesToProcess) do
ProcessFile(logfile)

-- don't archive the last file, it's most likely in use.
if next(filesToProcess,key) ~= nil and ShouldArchiveFiles == true then
MoveFile(logfile)
end
end

end
con:close()
env:close()



Offline Buzzkill

  • Respected Community Member
  • Full Member
  • *****
  • Posts: 176
  • Karma: 59
    • The Hundred Acre Bloodbath
Re: LuaLog
« Reply #1 on: March 06, 2015, 08:46:48 AM »
Question I'm going to throw out here based on this.

Using hooks instead of doing log analysis would be a much cleaner way. It would avoid a lot of the parsing nastiness. I chose to do log analysis versus event hooks for two reasons.  One, I don't have to worry about ancestor event handlers throwing an error and breaking the chain, and two, I can analyze lua error entries.  I can mitigate #1 by hooking to events with a low/read only priority (-20 or -19).  However, #2 still presents an issue.  There is no undocumented way to hook into lua error handlers, is there?

Thanks,
Mike

Offline Bite That Apple

  • Hero Member
  • *****
  • Posts: 858
  • Karma: 416
  • Apple Innovations 2010®
    • Fun 4 Everyone Gaming
Re: LuaLog
« Reply #2 on: March 06, 2015, 07:44:33 PM »
I'm dyslexic, so maybe I didn't read something correctly, though because you have so much lines of code, I still didn't really entirely understand what your idea is here. So, you think you could reexplain it a bit, or give it a good overview on your ending goal of this project so others or maybe I could assist you?
Quote from: John F. Kennedy 1963
A man may die, nations may rise and fall, but an idea lives on.

Offline JamminR

  • Ulysses Team Member
  • Hero Member
  • *****
  • Posts: 8096
  • Karma: 390
  • Sertafide Ulysses Jenius
    • Team Ulysses [ULib/ULX, other fine releases]
Re: LuaLog
« Reply #3 on: March 06, 2015, 10:11:55 PM »
There is no undocumented way to hook into lua error handlers, is there?
I'm guessing - yes.
One would have to find and see if the original lua error system in Gmod was done in lua (or, sadly in this case, it might be the lua compiler itself)
I've not researched how to look at all of Gmod lua code in quite some years. It used to be quite plainly visible.

If it WAS someway lua, well, it would be risky, but you'd over-ride it.
Just like we do in hook.Add (for adding priorities), you'd need to hook into original error output code.
"Though a program be but three lines long, someday it will have to be maintained." -- The Tao of Programming

An Error Has Occurred!

array_keys(): Argument #1 ($array) must be of type array, null given