diff --git a/extra/provision.sh b/extra/provision.sh index 00b15291..341de6ef 100755 --- a/extra/provision.sh +++ b/extra/provision.sh @@ -60,6 +60,7 @@ DOMAIN="none" EMAIL="none" CODE_PATH="/vagrant" CTF_PATH="/var/www/fbctf" +LOG_PATH="/var/log/fbctf" HHVM_CONFIG_PATH="/etc/hhvm/server.ini" DOCKER=false MULTIPLE_SERVERS=false @@ -332,6 +333,10 @@ fi log "Creating custom logos folder, and setting ownership to www-data" sudo mkdir -p "$CTF_PATH/src/data/customlogos" sudo chown -R www-data:www-data "$CTF_PATH/src/data/customlogos" + + log "Creating scripts log folder, and setting ownership to www-data" + sudo mkdir -p "$LOG_PATH" + sudo chown -R www-data:www-data "$LOG_PATH" fi # If multiple servers are being utilized, ensure provision was called from the "cache" server diff --git a/src/Utils.php b/src/Utils.php index a0747f2a..96e52ee2 100644 --- a/src/Utils.php +++ b/src/Utils.php @@ -108,6 +108,10 @@ public static function getFILES(): Map> { return new Map($_FILES); } + public static function get_src_root() : string { + return preg_replace(':/src/.*$:', '/src', __DIR__); + } + public static function redirect(string $location): void { header('Location: '.$location); } @@ -140,4 +144,21 @@ public static function error_response( ): string { return self::request_response('ERROR', $msg, $redirect); } + + public static function logMessage( + string $message + ): void { + $date = date('m/d/Y h:i:s a', time()); + $message = "[$date] $message\n"; + + if (php_sapi_name() === 'cli') { + fwrite(STDOUT, $message); + } else { + $filename = '/var/log/fbctf/web.log'; + if ($handle = fopen($filename, 'a')) { + fwrite($handle, $message); + fclose($handle); + } + } + } } diff --git a/src/models/Control.php b/src/models/Control.php index 93c6b7a1..53f4bcf6 100644 --- a/src/models/Control.php +++ b/src/models/Control.php @@ -52,7 +52,37 @@ class Control extends Model { if ($result->numRows() > 0) { $pid = intval(must_have_idx($result->mapRows()[0], 'pid')); } - return $pid; + + // Check that the process is actually running + $actual_pid = await self::genRunningScriptPid($name); + if ($pid == $actual_pid) { + return $pid; + } + if ($actual_pid == 0 && $pid != 0) { + Utils::logMessage("Warning: Script ($name) started as PID $pid but is no longer running"); + await self::genStopScriptLog($pid); + } else if ($actual_pid != 0 && $pid == 0) { + Utils::logMessage("Warning: Script ($name) was not started, but is running as PID $actual_pid"); + } else if ($actual_pid != $pid) { + Utils::logMessage("Warning: Script ($name) started as PID $pid but is actually running as $actual_pid"); + await self::genStopScriptLog($pid); + } + + return $actual_pid; + } + + public static async function genRunningScriptPid(string $name): Awaitable { + $lines = array(); + exec( "ps -C hhvm --format 'pid args' | grep '$name.php'", $lines ); + if (count($lines) === 0) { + return 0; + } else if (count($lines) > 1) { + Utils::logMessage("Error: multiple instances of ($name.php) running!"); + } + + $matches = array(); + $results = preg_match('/\s*([0-9]+)\s/', $lines[0], $matches); + return $results > 0 ? intval($matches[1]) : 0; } public static async function genClearScriptLog(): Awaitable { @@ -65,6 +95,7 @@ class Control extends Model { } public static async function genBegin(): Awaitable { + Utils::logMessage('Starting game'); await \HH\Asio\va( Announcement::genDeleteAll(), // Clear announcements log ActivityLog::genDeleteAll(), // Clear activity log @@ -129,6 +160,7 @@ class Control extends Model { Progressive::genReset(), // Reset and kick off progressive scoreboard ); + Utils::logMessage('Starting background scripts'); await \HH\Asio\va( Progressive::genRun(), Level::genBaseScoring(), // Kick off scoring for bases @@ -136,6 +168,7 @@ class Control extends Model { } public static async function genEnd(): Awaitable { + Utils::logMessage('Ending game'); await \HH\Asio\va( Announcement::genCreateAuto('Game has ended!'), // Announce game ending ActivityLog::genCreateGenericLog('Game has ended!'), // Log game ending @@ -152,6 +185,7 @@ class Control extends Model { $game_paused = $pause->getValue() === '1'; if (!$game_paused) { + Utils::logMessage('Stopping background scripts'); // Stop bases scoring process // Stop progressive scoreboard process await \HH\Asio\va(Level::genStopBaseScoring(), Progressive::genStop()); @@ -162,6 +196,7 @@ class Control extends Model { } public static async function genPause(): Awaitable { + Utils::logMessage('Pausing game'); await \HH\Asio\va( Announcement::genCreateAuto('Game has been paused!'), // Announce game paused ActivityLog::genCreateGenericLog('Game has been paused!'), // Log game paused @@ -179,6 +214,7 @@ class Control extends Model { } public static async function genUnpause(): Awaitable { + Utils::logMessage('Unpausing game'); await Configuration::genUpdate('scoring', '1'); // Enable scoring list($config_pause_ts, $config_start_ts, $config_end_ts) = await \HH\Asio\va( @@ -260,6 +296,7 @@ class Control extends Model { public static async function genRunAutoRunScript(): Awaitable { $autorun_status = await Control::checkScriptRunning('autorun'); if ($autorun_status === false) { + Utils::logMessage('Starting background script: autorun'); $autorun_location = escapeshellarg( must_have_string(Utils::getSERVER(), 'DOCUMENT_ROOT'). '/scripts/autorun.php', @@ -267,36 +304,54 @@ class Control extends Model { $cmd = 'hhvm -vRepo.Central.Path=/var/run/hhvm/.hhvm.hhbc_autorun '. $autorun_location. - ' > /dev/null 2>&1 & echo $!'; + ' >> /var/log/fbctf/autorun.log 2>&1 & echo $!'; + Utils::logMessage("Using command: [$cmd]"); $pid = shell_exec($cmd); await Control::genStartScriptLog(intval($pid), 'autorun', $cmd); } } + public static async function genRunScript( + string $name + ): Awaitable { + Utils::logMessage("Starting background script: $name"); + $running = await self::checkScriptRunning($name); + if ($running) { + Utils::logMessage("Warning: $name is already running"); + } + + $document_root = Utils::get_src_root(); + $cmd = + "hhvm -vRepo.Central.Path=/var/run/hhvm/.hhvm.hhbc_$name ". + $document_root. + "/scripts/$name.php >> /var/log/fbctf/$name.log 2>&1 & echo $!"; + Utils::logMessage("Using command: [$cmd]"); + $pid = shell_exec($cmd); + await Control::genStartScriptLog(intval($pid), $name, $cmd); + } + + public static async function genStopScript( + string $name + ): Awaitable { + Utils::logMessage("Stopping background script: $name"); + + do { + // Kill running process + $pid = await Control::genScriptPid($name); + if ($pid > 0) { + Utils::logMessage("Killing $name with PID $pid"); + exec('kill -9 '.escapeshellarg(strval($pid))); + } + // Mark process as stopped + await Control::genStopScriptLog($pid); + } while ($pid > 0); // In case there are multiple instances + } + public static async function checkScriptRunning( string $name, ): Awaitable { - $db = await self::genDb(); - $host = await Control::genServerAddr(); - $result = await $db->queryf( - 'SELECT pid FROM scripts WHERE name = %s AND host = %s AND status = 1', - $name, - $host, - ); - $status = false; - if ($result->numRows() >= 1) { - foreach ($result->mapRows() as $row) { - $pid = intval(must_have_idx($row, 'pid')); - $status = file_exists("/proc/$pid"); - if ($status === false) { - await Control::genStopScriptLog($pid); - await Control::genClearScriptLog(); - } - } - return $status; - } else { - return false; - } + $pid = await self::genScriptPid($name); + return $pid !== 0; } public static async function importGame(): Awaitable { diff --git a/src/models/Level.php b/src/models/Level.php index e559621b..02fdd569 100644 --- a/src/models/Level.php +++ b/src/models/Level.php @@ -1283,24 +1283,12 @@ public static function getBasesResponses( // Bases processing and scoring. public static async function genBaseScoring(): Awaitable { - $document_root = must_have_string(Utils::getSERVER(), 'DOCUMENT_ROOT'); - $cmd = - 'hhvm -vRepo.Central.Path=/var/run/hhvm/.hhvm.hhbc_bases '. - $document_root. - '/scripts/bases.php > /dev/null 2>&1 & echo $!'; - $pid = shell_exec($cmd); - await Control::genStartScriptLog(intval($pid), 'bases', $cmd); + await Control::genRunScript('bases'); } // Stop bases processing and scoring process. public static async function genStopBaseScoring(): Awaitable { - // Kill running process - $pid = await Control::genScriptPid('bases'); - if ($pid > 0) { - exec('kill -9 '.escapeshellarg(strval($pid))); - } - // Mark process as stopped - await Control::genStopScriptLog($pid); + await Control::genStopScript('bases'); } // Check if a level already exists by type, title and entity. diff --git a/src/models/Progressive.php b/src/models/Progressive.php index 03eb0e6e..170e4432 100644 --- a/src/models/Progressive.php +++ b/src/models/Progressive.php @@ -146,23 +146,11 @@ private static function progressiveFromRow( // Kick off the progressive scoreboard in the background. public static async function genRun(): Awaitable { - $document_root = must_have_string(Utils::getSERVER(), 'DOCUMENT_ROOT'); - $cmd = - 'hhvm -vRepo.Central.Path=/var/run/hhvm/.hhvm.hhbc_progressive '. - $document_root. - '/scripts/progressive.php > /dev/null 2>&1 & echo $!'; - $pid = shell_exec($cmd); - await Control::genStartScriptLog(intval($pid), 'progressive', $cmd); + await Control::genRunScript('progressive'); } // Stop the progressive scoreboard process in the background public static async function genStop(): Awaitable { - // Kill running process - $pid = await Control::genScriptPid('progressive'); - if ($pid > 0) { - exec('kill -9 '.escapeshellarg(strval($pid))); - } - // Mark process as stopped - await Control::genStopScriptLog($pid); + await Control::genStopScript('progressive'); } } diff --git a/src/scripts/autorun.php b/src/scripts/autorun.php index 19c07cf0..8750afc2 100644 --- a/src/scripts/autorun.php +++ b/src/scripts/autorun.php @@ -23,6 +23,8 @@ require_once (__DIR__.'/../models/Announcement.php'); require_once (__DIR__.'/../models/ActivityLog.php'); +Utils::logMessage('Starting autorun'); + while (1) { \HH\Asio\join(Control::genAutoRun()); diff --git a/src/scripts/bases.php b/src/scripts/bases.php index 0e0746e2..3dce85fb 100644 --- a/src/scripts/bases.php +++ b/src/scripts/bases.php @@ -23,6 +23,8 @@ $conf_game = \HH\Asio\join(Configuration::gen('game')); while ($conf_game->getValue() === '1') { + Utils::logMessage('Fetching base endpoints'); + // Get all active base levels $bases_endpoints = array(); foreach (\HH\Asio\join(Level::genAllActiveBases()) as $base) { @@ -30,6 +32,7 @@ 'id' => $base->getId(), 'url' => \HH\Asio\join(Level::genBaseIP($base->getId())), ); + Utils::logMessage("Adding endpoint to call for level ${endpoint['id']}: ${endpoint['url']}"); array_push($bases_endpoints, $endpoint); } @@ -45,10 +48,10 @@ \HH\Asio\join(Level::genScoreBase($response['id'], $team->getId())); //echo "Points\n"; } - //echo "Base(".strval($response['id']).") taken by ".$team_name."\n"; + Utils::logMessage("Base(".strval($response['id']).") taken by $team_name."); } else { $code = -1; - //echo "Base(".strval($response['id']).") is DOWN\n"; + Utils::logMessage("Base(".strval($response['id']).") is DOWN"); } \HH\Asio\join( Level::genLogBaseEntry( @@ -60,7 +63,9 @@ } // Wait until next iteration $bases_cycle = \HH\Asio\join(Configuration::gen('bases_cycle')); - sleep(intval($bases_cycle->getValue())); + $sleep_length = $bases_cycle->getValue(); + Utils::logMessage("Sleeping for $sleep_length seconds"); + sleep(intval($sleep_length)); // Flush the local cache before the next cycle to ensure the game is still running and the configuration of the bases hasn't changed (the script runs continuously). Model::deleteLocalCache(); @@ -68,3 +73,4 @@ // Get current game status $conf_game = \HH\Asio\join(Configuration::gen('game')); } +Utils::logMessage('Game is no longer running. Shutting down.'); diff --git a/src/scripts/liveimport.php b/src/scripts/liveimport.php index 9b138d05..68a5c3bd 100644 --- a/src/scripts/liveimport.php +++ b/src/scripts/liveimport.php @@ -597,8 +597,11 @@ public static function debug( string $indicator, string $message, ): void { + $msg = "[".date('D M j G:i:s Y')."] [$url] $indicator $message\n"; if ($debug === true) { - print "[".date('D M j G:i:s Y')."] [$url] $indicator $message\n"; + print $msg; + } else { + Utils::logMessage($msg); } } } diff --git a/src/scripts/progressive.php b/src/scripts/progressive.php index 0d9e75c1..d63dddcf 100644 --- a/src/scripts/progressive.php +++ b/src/scripts/progressive.php @@ -12,6 +12,8 @@ require_once (__DIR__.'/../models/Progressive.php'); while (\HH\Asio\join(Progressive::genGameStatus())) { + Utils::logMessage('Progressive scoreboard cycling'); \HH\Asio\join(Progressive::genTake()); sleep(\HH\Asio\join(Progressive::genCycle())); } +Utils::logMessage('Game is no longer running. Shutting down.');