Source Log parsing - games.log (SOF/1fx-specific)

Source code of specific applications

Janno

why let your life be controlled by fairytales
For outsiders, we have an abuse reporting page available, that also has all of the log files in it. I store log files to the database for easier search. So I built a script quite some time ago which parses all of the log files and pushes them to a database table where others can have access to them without having FTP access.

The script runs in 2 parts - one is a shell script, which is executed by the PHP script to copy the log file to a folder which the script can easily access. This is done directly over a SSH connection to be sure that we won't miss any data during the time when we copy the file and when we clear out the file in the logs folder.

Bash:
#!/bin/bash

#/home/server/1fx/admin.log
#/home/server/1fx/logs/rcon.log

srvPath="/home/server/"
logFolderRcon="1fx/logs/"
logName="games.log"

destination="/var/www/xxxx/gameslog/"

cp $srvPath$logFolderRcon$logName $destination

echo -n > $srvPath$logFolderRcon$logName

chown www-data $destination$logName

What this small script does:
1. Copies the games.log file from /home/server/1fx/logs/games.log to /var/www/xxxx/gameslog/ folder.
2. Clears out the /home/server/1fx/logs/games.log file.
3. Gives permission to the web server user to have full access to the log file.

This script is called directly from the PHP script.

Table spec:
SQL:
CREATE TABLE abuse_gameslog (
    abuse_gameslog_id INTEGER NOT NULL AUTO_INCREMENT PRIMARY KEY
    , gameslog_action_id INTEGER
    , dt DATETIME
    , ip_addr VARCHAR(15)
    , action_initiator VARCHAR(512)
    , action_receiver VARCHAR(512)
    , action_text TEXT
);

CREATE TABLE abuse_gameslog_actions (
    gameslog_action_id INTEGER NOT NULL AUTO_INCREMENT PRIMARY KEY
    , action_name VARCHAR(255)
    , action_description TEXT
);
INSERT INTO abuse_gameslog_actions (action_name, action_description) VALUES

('InitGame:', 'Game / Map start')
, ('ClientConnect:', 'Player joining')
, ('Kill:', 'Player killed')
, ('say:', 'Public message')
, ('sayteam:', 'Team message')
, ('ClientDisconnect:', 'Player leaving')
, ('admtalk:', 'Admin public message')
, ('tell:', 'Private message')
, ('sadmchat:', 'S-Admin only chat')
, ('admchat:', 'Admin only chat')
, ('Exit:', 'Gametype end')
, ('clanchat:', 'Clan only chat')
, ('clantalk:', 'Clan public talk')
, ('Error', 'Generic error (e.g. wpnfile)')
, ('N/A', 'Generic message (shown as cleartext)')  ;

As the table can get quite large and you're most likely going to search by the dt field, it's best to index that. Even tho the insert speed suffers from it and you don't want to insert often thanks to the fact that you might miss a row or two when inserting (and clearing out) the games.log file, it seems to be okay with a 5-minute interval updates.
SQL:
CREATE INDEX idx_abuse_gameslog_dt ON abuse_gameslog(dt);
The index will speed up the queries on DT field by a huge margin.

The script itself is below. Yet again, this was done quite some time ago and wasn't meant to be a showcase script, therefore it still has some weird comments, echo/print_r statements in it etc.

PHP:
<?php

$runFromFile = false;

if (!$runFromFile) {
 

    $handle = ssh2_connect("127.0.0.1", 22);
    if (!ssh2_auth_password($handle, "account", "password")) {
        throw new Exception("Can't connect!");
    }

    $stream = ssh2_exec($handle, "/root/copygameslog"); //THIS IS THE SCRIPT MENTIONED BEFORE
    stream_set_blocking($stream, true);
    stream_set_timeout($stream, 15);
    $stream_err = ssh2_fetch_stream($stream, SSH2_STREAM_STDERR);
    print_r(array("stdio" => stream_get_contents($stream), "stderr" => stream_get_contents($stream_err)));
 
}

//06/21/2018 14:59
//first part is always date.
//map ERROR: to 14 Error
$action_ids = array('InitGame:' => 1
, 'ClientConnect:' => 2
, 'Kill:' => 3
, 'say:' => 4
, 'sayteam:' => 5
, 'ClientDisconnect:' => 6
, 'admtalk:' => 7
, 'tell:' => 8
, 'sadmchat:' => 9
, 'admchat:' => 10
, 'Exit:' => 11
, 'clanchat:' => 12
, 'clantalk:' => 13
, 'Error' => 14
, 'N/A' => 15
, 'ERROR:' => 14
, '^1Error:' => 14
, 'heyadmin:' => 16
);

function stripQ3Colors($input) {
    return preg_replace("/(\^.)/", "", $input);
}

require_once __DIR__ . "/../classes/pdo/SQL.php";
$dsn = "mysql:host=localhost;dbname=database";
$username = "username";
$password = "password";
$sql = new SQL($dsn, $username, $password);
$sql->query("DELETE FROM abuse_gameslog WHERE dt < CURRENT_DATE - INTERVAL 60 DAY");
/*
* CREATE TABLE abuse_gameslog (abuse_gameslog_id INTEGER NOT NULL AUTO_INCREMENT
* PRIMARY KEY, gameslog_action_id INTEGER NOT NULL, dt DATETIME, ip_addr VARCHAR(255),
* action_initiator VARCHAR(512), action_receiver VARCHAR(512), action_text TEXT)
*/

$noneed = array("Loading", "Number", "Parsing", "Loaded", "score:", "ShutdownGame:",
    "------------------------------------------------------------"
    , ":Q", "this", "red:");

$keepFullStrings = array("Now", "Writing", "Closed", "Please", "by", "Trying", "Auto");

ini_set("memory_limit", -1); //this is not needed, but this script was first built to parse all historic data as well (I think the text file itself was 500MB already)
set_time_limit(0); //same comment as previous.
//$fileContents = file_get_contents(__DIR__ . "/games.log");//was too slow to use on a huge file.
//$file = file(__DIR__ . "/games.log", FILE_IGNORE_NEW_LINES | FILE_SKIP_EMPTY_LINES);
$stream = fopen(__DIR__ . "/games.log", 'r');
$arr = array();
$i = 0;
$toCheck = 'Exit:';
$checked = false;
$noArr = true;
$break = true;
$printNextSplit = false;
$noqry = false;
$sql->beginTransaction();
$getLine = false;
$lineF = 0;
$lineT = 512;
$j = 0;
$dateObjectLargerThan = new DateTime("2018-06-01 00:00:00");
while (($line = fgets($stream)) !== false) {
    $j++;
    if ($getLine) {
        if ($j >= $lineF && $j <= $lineT) {
            print_r($line);
        } else {
            break;
        }
        continue;
    }
    if ($printNextSplit) {
        print_r($line);
        $printNextSplit = false;
    }
    if (strlen($line) < 10) {
        continue;
    }
    $split = preg_split("/[\s\\\\]+/", $line);
 
    if (sizeof($split) < 4) {
        continue;
    }
 
    if (in_array($split[3], $noneed)) {
        continue;
    }
 
    if (strpos($split[3], 'red:') !== false) {
        continue;
    }
    /**
     * gameslog_action_id INTEGER NOT NULL, dt DATETIME, ip_addr VARCHAR(255),
* action_initiator VARCHAR(512), action_receiver VARCHAR(512), action_text TEXT)
     */
    if ($split[1] === "FATAL") {
        continue;
    }
    $dateobject = new DateTime($split[0] . " " . $split[1]);
 
    if ($dateobject < $dateObjectLargerThan) {
        continue;
    }
    $dt = $dateobject->format("Y-m-d H:i:s");
    $ip_addr = "";
    $action_initiator = "";
    $action_receiver = "";
    $action_text = "";
    $gameslog_action_id = 15;
    if (in_array($split[3], $keepFullStrings)) {
        $gameslog_action_id = 14;
    }
    if (array_key_exists($split[3], $action_ids)) {
        $gameslog_action_id = $action_ids[$split[3]];
    }
    if ($split[3] === "InitGame:") {
        for ($i = 3; $i < sizeof($split); $i++) {
            if ($split[$i] === 'mapname') {
                $action_text = "Map switch to " . $split[$i + 1];
                break;
            }
        }
    } else if ($split[3] === "ClientConnect:") {
        $ip_addr = $split[5];
        $action_text = "Connected with ID " . $split[4];
        for ($i = 6; $i < sizeof($split) - 1; $i++) {
            $action_initiator .= $split[$i] . " ";
        }
        $action_initiator = stripQ3Colors(trim($action_initiator));
    } else if ($split[3] === "ClientDisconnect:") {
        $ip_addr = $split[5];
        $action_text = "ID " . $split[4] . " disconnected.";
        for ($i = 6; $i < sizeof($split) - 1; $i++) {
            $action_initiator .= $split[$i] . " ";
        }
        $action_initiator = stripQ3Colors(trim($action_initiator));
    } else if ($split[3] === "Kill:") {
        $i = 0;
        for ($i = 4; $i < sizeof($split); $i++) {
            if (strpos($split[$i], ':') !== false) {
                break;
            }
        }
        for ($i = $i + 1; $i < sizeof($split); $i++) {
            if ($split[$i] === "killed") {
                $action_initiator = stripQ3Colors(trim($action_initiator));
                break;
            }
            $action_initiator .= $split[$i] . " ";
        }
        for ($i = $i + 1; $i < sizeof($split); $i++) {
            if ($split[$i] === "by") {
                $action_receiver = stripQ3Colors(trim($action_receiver));
                break;
            }
            $action_receiver = $split[$i] . " ";
        }
        for ($i = $i + 1; $i < sizeof($split) - 1; $i++) {
            $action_text .= $split[$i] . " ";
        }
        $action_text = trim($action_text);
    } else if ($split[3] === "say:" || $split[3] === "sayteam:" || $split[3] === "admtalk:" || $split[3] === "heyadmin:" || $split[3] === "sadmchat:" || $split[3] === "admchat:" || $split[3] === "clanchat:" || $split[3] === "clantalk:") {
        $i = 0;
        for ($i = 4; $i < sizeof($split); $i++) {
            if (strpos($split[$i], ':') !== false) {
                $action_initiator .= $split[$i];
                $action_initiator = stripQ3Colors(trim(rtrim($action_initiator, ":")));
                break;
            }
            $action_initiator .= $split[$i] . " ";
        }
        for ($i = $i + 1; $i < sizeof($split) - 1; $i++) {
            $action_text .= $split[$i] . " ";
        }
        $action_text = stripQ3Colors(trim($action_text));
    } else if ($split[3] === "tell:") {
        $i = 0;
        for ($i = 4; $i < sizeof($split); $i++) {
            if ($split[$i] === "to") {
                $action_initiator = stripQ3Colors(trim($action_initiator));
                break;
             
            }
            $action_initiator .= $split[$i] . " ";
        }
        for ($i = $i + 1; $i < sizeof($split) - 1; $i++) {
            if (strpos($split[$i], ":") !== false) {
                $action_receiver .= $split[$i];
                $action_receiver = stripQ3Colors(trim(rtrim($action_receiver, ":")));
                break;
            }
            $action_receiver .= $split[$i] . " ";
        }
        for ($i = $i + 1; $i < sizeof($split) - 1; $i++) {
            $action_text .= $split[$i] . " ";
        }
        $action_text = stripQ3Colors(trim($action_text));
    } else {
        for ($i = 4; $i < sizeof($split) - 1; $i++) {
            $action_text .= $split[$i] . " ";
        }
        $action_text = trim($action_text);
    }
 
    if (!$noArr) {
        if (array_key_exists($split[3], $arr)) {
            $arr[$split[3]] = $arr[$split[3]] + 1;
        } else {
            $arr[$split[3]] = 1;
        }
    }
 
 
    //show stuff
    /*
    if (!$checked && $split[3] === $toCheck) {
        if ($break) {
            $checked = true;
        }

        print_r($lastSplit);
        print_r($split);
        $printNextSplit = true;
        if ($noArr && $break) {
            break;
        }
    }
    $lastSplit = $split;
     * */

    if (!$noqry) {
        $sql->query("INSERT INTO abuse_gameslog (gameslog_action_id, dt, ip_addr, action_initiator, action_receiver, action_text) VALUES (?, ?, ?, ?, ?, ?)",
            array($gameslog_action_id, $dt, $ip_addr, $action_initiator, $action_receiver, $action_text));

    }
}

$sql->commit();

/*
if (!$noArr) {
    print_r($arr);
}*/
fclose($stream);

$stream = ssh2_exec($handle, "echo -n > /var/www/xxxx/gameslog/games.log");
stream_set_blocking($stream, true);
stream_set_timeout($stream, 2);
$stream_err = ssh2_fetch_stream($stream, SSH2_STREAM_STDERR);
print_r(array("stdio" => stream_get_contents($stream), "stderr" => stream_get_contents($stream_err)));
ssh2_disconnect($handle);
 
Back
Top