From eec3af3ae4321e5fbf43666b143792b6157f73ae Mon Sep 17 00:00:00 2001 From: pbailie Date: Thu, 1 Aug 2019 19:35:58 -0400 Subject: [PATCH 01/14] Update preferred_name_logging.php Some refactoring and needed adjustments to satisfy request from @bmcutler in PR Submitty/Submitty#4153 --- .../preferred_name_logging.php | 232 +++++++++++++++--- 1 file changed, 195 insertions(+), 37 deletions(-) diff --git a/preferred_name_logging/preferred_name_logging.php b/preferred_name_logging/preferred_name_logging.php index 9c475d2..4e7a206 100755 --- a/preferred_name_logging/preferred_name_logging.php +++ b/preferred_name_logging/preferred_name_logging.php @@ -19,7 +19,7 @@ class main { * @var const array * @access private */ - private const CONFIG = array( + private static $config = array( 'timezone' => "America/New_York", 'postgresql_logfile_path' => "/var/log/postgresql/", 'submitty_logfile_path' => "/var/log/submitty/", @@ -28,14 +28,21 @@ class main { 'submitty_log_retention' => 7 ); - private const CONSTANTS = array( - 'postgresql_log_row_count' => 23, - 'psql_validation_update' => 7, - 'psql_validation_log' => 11, - 'psql_validation_pfn' => 13, - 'psql_data_date' => 8, - 'psql_data_auth' => 19, - 'psql_data_pfn' => 14 + private const POSTGRESQL_LOG_ROW_COUNT = 23; + private const PSQL_VALIDATION_UPDATE = 7; + private const PSQL_VALIDATION_LOG = 11; + private const PSQL_VALIDATION_PFN = 13; + private const PSQL_DATA_DATE = 8; + private const PSQL_DATA_AUTH = 19; + private const PSQL_DATA_PFN = 14; + + /** @var Not a config option. Do NOT manually change. */ + private static $psql_log_time_offset = -86400; + /** @var Not a config option. Do NOT manually change. */ + private static $daemon_user = array( + 'name' => "root", + 'uid' => 0, + 'gid' => 0 ); /** @@ -45,22 +52,95 @@ class main { * @static */ public static function run() { - // make sure we are running as root from cli - switch (true) { - case posix_getuid() !== 0: - case PHP_SAPI !== 'cli': - fprintf(STDERR, "This is a command line script. Root required.%s", PHP_EOL); + //make sure we are running from cli + if (PHP_SAPI !== 'cli') { + fprintf(STDERR, "This is a command line script.%s", PHP_EOL); + exit(1); + } + + //check for which server to run on. + $args = cli_args::parse_args(); + + //must be run as root or submitty_daemon (submitty/vagrant only). + //submitty/vagrant servers need to lookup submitty_daemon user info. + switch($args) { + case "submitty": + case "vagrant": + self::get_daemon_user(); + } + + var_dump(self::$daemon_user); die; + if (posix_getuid() !== 0 && posix_getuid() !== self::$daemon_user['uid']) { + fprintf(STDERR, "Execution denied.%s", PHP_EOL); exit(1); } - date_default_timezone_set(self::CONFIG['timezone']); + //Prfocessing may continue. Submitty/vagrant systems need to override + //config with submitty.json. + switch($args) { + case "submitty": + self::override_config(); + break; + case "vagrant": + self::override_config(); + //vagrant should read today's psql CSV. + self::$psql_log_time_offset = 0; + break; + } + date_default_timezone_set(self::$config['timezone']); self::parse_and_write_logs(); self::log_retention_and_deletion(); exit(0); } + /** + * submitty/vagrant servers permit submitty_daemon to execute this script. + * + * self::$daemon_user by default mirrors root so by default only root has + * execution privilege. This function will attempt to lookup + * submitty_daemon in submitty_users.json, and when successful, copy that + * information to self::$daemon_user, therefore permitting submitty_daemon + * execution privilege. Submitty_daemon will also need group ownership and + * chmod g+rx privilege. + * + * @access private + * @static + */ + private static function get_daemon_user() { + $json = file_get_contents("../config/submitty_users.json"); + if ($json !== false) { + $json = json_decode($json, true); + self::$daemon_user = array( + 'name' => $json['daemon_user'], + 'uid' => $json['daemon_uid'], + 'gid' => $json['daemon_gid'] + ); + } + } + + /** + * Override self::$config with a few elements from submitty.json + * + * This function assumes that the script is running from submitty/sbin. + * + * @access private + * @static + */ + private static function override_config() { + $json['config'] = file_get_contents("../config/submitty.json"); + if ($json['config'] === false) { + fprintf(STDERR, "Cannot open config/submitty.json%s", PHP_EOL); + exit(1); + } + + $json['config'] = json_decode($json['config'], true); + self::$config['timezone'] = $json['config']['timezone']; + self::$config['postgresql_logfile_path'] = $json['config']['site_log_path'] . "/psql/"; + self::$config['submitty_logfile_path'] = $json['config']['site_log_path'] . "/preferred_names/"; + } + /** * Process method * @@ -69,15 +149,15 @@ public static function run() { */ private static function parse_and_write_logs() { //Check to make sure Submitty log directory path exists. Create it if needed. - if (file_exists(self::CONFIG['submitty_logfile_path']) === false) { - if (mkdir(self::CONFIG['submitty_logfile_path'], 0700) === false) { + if (file_exists(self::$config['submitty_logfile_path']) === false) { + if (mkdir(self::$config['submitty_logfile_path'], 0700) === false) { self::log("Submitty log folder needed, mkdir failed."); exit(1); } } //Prepare submitty preferred name change log file for today. - $submitty_logfile = sprintf("%s%s_%s.log", self::CONFIG['submitty_logfile_path'], self::CONFIG['submitty_logfile'], date("Y-m-d")); + $submitty_logfile = sprintf("%s%s_%s.log", self::$config['submitty_logfile_path'], self::$config['submitty_logfile'], date("Y-m-d")); $submitty_fh = fopen($submitty_logfile, 'w'); if ($submitty_fh === false) { self::log("Cannot create Submitty logfile."); @@ -88,11 +168,11 @@ private static function parse_and_write_logs() { //There can be multiple psql log files that need to be read. //But we want the ones dated one day prior (hence subtract 86400 seconds which is one day) - $preg_str = sprintf("~^%s\-%s_\d{6}\.csv$~", self::CONFIG['postgresql_logfile'], preg_quote(date("Y-m-d", time() - 86400))); - $logfiles = preg_grep($preg_str, scandir(self::CONFIG['postgresql_logfile_path'])); + $preg_str = sprintf("~^%s\-%s_\d{6}\.csv$~", self::$config['postgresql_logfile'], preg_quote(date("Y-m-d", time() + self::$psql_log_time_offset))); + $logfiles = preg_grep($preg_str, scandir(self::$config['postgresql_logfile_path'])); foreach ($logfiles as $logfile) { - $psql_fh = fopen(self::CONFIG['postgresql_logfile_path'] . $logfile, 'r'); + $psql_fh = fopen(self::$config['postgresql_logfile_path'] . $logfile, 'r'); if ($psql_fh === false) { self::log("Cannot open {$logfile}."); continue; @@ -103,11 +183,11 @@ private static function parse_and_write_logs() { while($psql_row !== false) { //Validation. Any case is true, validation fails and row is ignored. switch(true) { - case count($psql_row) !== self::CONSTANTS['postgresql_log_row_count']: - self::log(sprintf("NOTICE: PSQL log row %d had %d columns. %d columns expected. Row ignored.%s", $psql_row_num, count($psql_row), self::CONFIG['postgresql_log_row_count'])); - case $psql_row[self::CONSTANTS['psql_validation_update']] !== "UPDATE": - case $psql_row[self::CONSTANTS['psql_validation_log']] !== "LOG": - case $psql_row[self::CONSTANTS['psql_validation_pfn']] !== "PREFERRED_NAME DATA UPDATE": + case count($psql_row) !== self::POSTGRESQL_LOG_ROW_COUNT; + self::log(sprintf("NOTICE: PSQL log row %d had %d columns. %d columns expected. Row ignored.%s", $psql_row_num, count($psql_row), self::$config['postgresql_log_row_count'])); + case $psql_row[self::PSQL_VALIDATION_UPDATE] !== "UPDATE": + case $psql_row[self::PSQL_VALIDATION_LOG] !== "LOG": + case $psql_row[self::PSQL_VALIDATION_PFN] !== "PREFERRED_NAME DATA UPDATE": $psql_row = fgetcsv($psql_fh); $psql_row_num++; continue 2; @@ -118,14 +198,14 @@ private static function parse_and_write_logs() { $psql_row = array_map('trim', $psql_row); //Get date token. - $date = $psql_row[self::CONSTANTS['psql_data_date']]; + $date = $psql_row[self::PSQL_DATA_DATE]; //Get "AUTH" token (who logged the change). $key = array(); if (preg_match("~/\* AUTH: \"[\w\-]+\" \*/~", $psql_row[19]) === 1) { - $key['start'] = strpos($psql_row[self::CONSTANTS['psql_data_auth']], "/* AUTH: ") + 3; - $key['end'] = strpos($psql_row[self::CONSTANTS['psql_data_auth']], " */"); - $auth = " | " . substr($psql_row[self::CONSTANTS['psql_data_auth']], $key['start'], $key['end'] - $key['start']); + $key['start'] = strpos($psql_row[self::PSQL_DATA_AUTH], "/* AUTH: ") + 3; + $key['end'] = strpos($psql_row[self::PSQL_DATA_AUTH], " */"); + $auth = " | " . substr($psql_row[self::PSQL_DATA_AUTH], $key['start'], $key['end'] - $key['start']); } else { $auth = " | AUTH NOT LOGGED "; //Anything sent to STDERR gets emailed by cron. @@ -134,7 +214,7 @@ private static function parse_and_write_logs() { //Get user_id and preferred name change tokens. $preferred_name = array(); - $preferred_names_data = explode(" ", $psql_row[self::CONSTANTS['psql_data_pfn']]); + $preferred_names_data = explode(" ", $psql_row[self::PSQL_DATA_PFN]); //user_id token $key = array_search("USER_ID:", $preferred_names_data); @@ -194,15 +274,15 @@ private static function parse_and_write_logs() { * @static */ private static function log_retention_and_deletion() { - $preg_str = sprintf("~^%s_%s.log$~", self::CONFIG['submitty_logfile'], preg_quote(date("m-d-Y"))); - $logfiles = preg_grep($preg_str, scandir(self::CONFIG['submitty_logfile_path'])); - $expiration_epoch = (int)(strtotime(date('Y-m-d')) / 86400) - self::CONFIG['submitty_log_retention']; + $preg_str = sprintf("~^%s_%s.log$~", self::$config['submitty_logfile'], preg_quote(date("m-d-Y"))); + $logfiles = preg_grep($preg_str, scandir(self::$config['submitty_logfile_path'])); + $expiration_epoch = (int)(strtotime(date('Y-m-d')) / 86400) - self::$config['submitty_log_retention']; foreach($logfiles as $logfile) { $datestamp = substr($logfile, strpos($logfile, "_") + 1, 10); $datestamp_epoch = (int)(strtotime($datestamp) / 86400); if ($datestamp_epoch < $expiration_epoch) { - if (unlink(self::CONFIG['submitty_logfile_path'] . $logfile) === false) { + if (unlink(self::$config['submitty_logfile_path'] . $logfile) === false) { self::log("Could not delete old logfile: {$logfile}"); } } @@ -220,9 +300,87 @@ private static function log(string $msg) { error_log(sprintf("%s %s", $datestamp, $msg), 0); fprintf(STDERR, "%s%s", $msg, PHP_EOL); } -} +} //END class main + +/** + * class to parse command line arguments + * + * @static + */ +class cli_args { + + /** @var string usage help message */ + private static $help_usage = << Date: Tue, 20 Aug 2019 17:14:36 -0400 Subject: [PATCH 02/14] Update preferred_name_logging.php WIP --- .../preferred_name_logging.php | 61 +++++++++++-------- 1 file changed, 35 insertions(+), 26 deletions(-) diff --git a/preferred_name_logging/preferred_name_logging.php b/preferred_name_logging/preferred_name_logging.php index 4e7a206..b1d0c24 100755 --- a/preferred_name_logging/preferred_name_logging.php +++ b/preferred_name_logging/preferred_name_logging.php @@ -61,15 +61,17 @@ public static function run() { //check for which server to run on. $args = cli_args::parse_args(); - //must be run as root or submitty_daemon (submitty/vagrant only). - //submitty/vagrant servers need to lookup submitty_daemon user info. + //must be run as root or submitty_daemon (submitty/dev only). + //submitty/dev mode needs to lookup submitty_daemon user info. switch($args) { case "submitty": - case "vagrant": - self::get_daemon_user(); + case "dev": + if (self::get_daemon_user() === false) { + fprintf(STDERR, "Could not retrieve Submitty daemon uuid%s. Aborting.%s", PHP_EOL, PHP_EOL); + exit(1); + } } - var_dump(self::$daemon_user); die; if (posix_getuid() !== 0 && posix_getuid() !== self::$daemon_user['uid']) { fprintf(STDERR, "Execution denied.%s", PHP_EOL); exit(1); @@ -81,9 +83,9 @@ public static function run() { case "submitty": self::override_config(); break; - case "vagrant": + case "dev": self::override_config(); - //vagrant should read today's psql CSV. + //dev should read today's psql CSV. self::$psql_log_time_offset = 0; break; } @@ -110,13 +112,17 @@ public static function run() { */ private static function get_daemon_user() { $json = file_get_contents("../config/submitty_users.json"); - if ($json !== false) { + if ($json === false) { + return false; + } else { $json = json_decode($json, true); self::$daemon_user = array( 'name' => $json['daemon_user'], 'uid' => $json['daemon_uid'], 'gid' => $json['daemon_gid'] ); + + return true; } } @@ -311,7 +317,7 @@ class cli_args { /** @var string usage help message */ private static $help_usage = << Date: Mon, 9 Sep 2019 17:22:35 -0400 Subject: [PATCH 03/14] Update preferred_name_logging.php WIP --- .../preferred_name_logging.php | 21 ++++++++++--------- 1 file changed, 11 insertions(+), 10 deletions(-) diff --git a/preferred_name_logging/preferred_name_logging.php b/preferred_name_logging/preferred_name_logging.php index b1d0c24..8e6e5a8 100755 --- a/preferred_name_logging/preferred_name_logging.php +++ b/preferred_name_logging/preferred_name_logging.php @@ -54,7 +54,7 @@ class main { public static function run() { //make sure we are running from cli if (PHP_SAPI !== 'cli') { - fprintf(STDERR, "This is a command line script.%s", PHP_EOL); + fwrite(STDERR, "This is a command line script." . PHP_EOL); exit(1); } @@ -67,18 +67,18 @@ public static function run() { case "submitty": case "dev": if (self::get_daemon_user() === false) { - fprintf(STDERR, "Could not retrieve Submitty daemon uuid%s. Aborting.%s", PHP_EOL, PHP_EOL); + fwrite(STDERR, "Could not retrieve Submitty daemon uuid." . PHP_EOL . "Aborting." . PHP_EOL); exit(1); } } if (posix_getuid() !== 0 && posix_getuid() !== self::$daemon_user['uid']) { - fprintf(STDERR, "Execution denied.%s", PHP_EOL); + fwrite(STDERR, "Execution denied." . PHP_EOL); exit(1); } - //Prfocessing may continue. Submitty/vagrant systems need to override - //config with submitty.json. + //Prfocessing may continue. Submitty/dev modes need to override + //self::config with submitty.json. switch($args) { case "submitty": self::override_config(); @@ -98,14 +98,15 @@ public static function run() { } /** - * submitty/vagrant servers permit submitty_daemon to execute this script. + * submitty/dev modes permit submitty_daemon to execute this script. * * self::$daemon_user by default mirrors root so by default only root has * execution privilege. This function will attempt to lookup * submitty_daemon in submitty_users.json, and when successful, copy that * information to self::$daemon_user, therefore permitting submitty_daemon * execution privilege. Submitty_daemon will also need group ownership and - * chmod g+rx privilege. + * chmod g+rx privilege of this script. This also assumes the script is + * running from submitty/sbin. * * @access private * @static @@ -137,7 +138,7 @@ private static function get_daemon_user() { private static function override_config() { $json['config'] = file_get_contents("../config/submitty.json"); if ($json['config'] === false) { - fprintf(STDERR, "Cannot open config/submitty.json%s", PHP_EOL); + fwrite(STDERR, "Cannot open config/submitty.json" . PHP_EOL); exit(1); } @@ -304,7 +305,7 @@ private static function log_retention_and_deletion() { private static function log(string $msg) { $datestamp = date("m-d-Y"); error_log(sprintf("%s %s", $datestamp, $msg), 0); - fprintf(STDERR, "%s%s", $msg, PHP_EOL); + fwrite(STDERR, $msg . PHP_EOL); } } //END class main @@ -383,7 +384,7 @@ public static function parse_args() { } //If we reach here, invalid CLI arguments were given. - fprintf(STDERR, self::$help_usage); + fwrite(STDERR, self::$help_usage); exit(1); } } //END class parse_args From fb25d50c7601a44bb298b1514a7a8fc27ebf691a Mon Sep 17 00:00:00 2001 From: pbailie Date: Tue, 17 Sep 2019 18:50:47 -0400 Subject: [PATCH 04/14] Update preferred_name_logging.php Better integration and improved error logging --- .../preferred_name_logging.php | 254 +++++++----------- 1 file changed, 103 insertions(+), 151 deletions(-) diff --git a/preferred_name_logging/preferred_name_logging.php b/preferred_name_logging/preferred_name_logging.php index 8e6e5a8..4fcb0cd 100755 --- a/preferred_name_logging/preferred_name_logging.php +++ b/preferred_name_logging/preferred_name_logging.php @@ -14,20 +14,14 @@ class main { /** - * Config + * Operating config determined by main::get_config(). * - * @var const array + * @staticvar array * @access private */ - private static $config = array( - 'timezone' => "America/New_York", - 'postgresql_logfile_path' => "/var/log/postgresql/", - 'submitty_logfile_path' => "/var/log/submitty/", - 'postgresql_logfile' => "postgresql", - 'submitty_logfile' => "submitty_preferred_names", - 'submitty_log_retention' => 7 - ); + private static $config = array(); + //Do not change these. private const POSTGRESQL_LOG_ROW_COUNT = 23; private const PSQL_VALIDATION_UPDATE = 7; private const PSQL_VALIDATION_LOG = 11; @@ -35,21 +29,17 @@ class main { private const PSQL_DATA_DATE = 8; private const PSQL_DATA_AUTH = 19; private const PSQL_DATA_PFN = 14; - - /** @var Not a config option. Do NOT manually change. */ - private static $psql_log_time_offset = -86400; - /** @var Not a config option. Do NOT manually change. */ - private static $daemon_user = array( - 'name' => "root", - 'uid' => 0, - 'gid' => 0 - ); + private const POSTGRESQL_LOGDIR = '/psql/'; + private const POSTGRESQL_LOGFILE = 'postgresql'; + private const PREFERRED_NAMES_LOGDIR = '/preferred_names/'; + private const PREFERRED_NAMES_LOGFILE = 'preferred_names'; + private const ERROR_LOGFILE = 'errors.log'; /** - * Method to invoke to run this program: main::run() + * Main process. Invoke with main::run() * - * @access public * @static + * @access public */ public static function run() { //make sure we are running from cli @@ -58,124 +48,87 @@ public static function run() { exit(1); } - //check for which server to run on. - $args = cli_args::parse_args(); - - //must be run as root or submitty_daemon (submitty/dev only). - //submitty/dev mode needs to lookup submitty_daemon user info. - switch($args) { - case "submitty": - case "dev": - if (self::get_daemon_user() === false) { - fwrite(STDERR, "Could not retrieve Submitty daemon uuid." . PHP_EOL . "Aborting." . PHP_EOL); - exit(1); - } - } - - if (posix_getuid() !== 0 && posix_getuid() !== self::$daemon_user['uid']) { - fwrite(STDERR, "Execution denied." . PHP_EOL); - exit(1); - } - - //Prfocessing may continue. Submitty/dev modes need to override - //self::config with submitty.json. - switch($args) { - case "submitty": - self::override_config(); - break; - case "dev": - self::override_config(); - //dev should read today's psql CSV. - self::$psql_log_time_offset = 0; - break; - } - - date_default_timezone_set(self::$config['timezone']); + ini_set(display_errors, "0"); + self::get_config(); self::parse_and_write_logs(); self::log_retention_and_deletion(); exit(0); } - /** - * submitty/dev modes permit submitty_daemon to execute this script. + /** + * Read JSON config files to build self::$config array. * - * self::$daemon_user by default mirrors root so by default only root has - * execution privilege. This function will attempt to lookup - * submitty_daemon in submitty_users.json, and when successful, copy that - * information to self::$daemon_user, therefore permitting submitty_daemon - * execution privilege. Submitty_daemon will also need group ownership and - * chmod g+rx privilege of this script. This also assumes the script is - * running from submitty/sbin. + * This function assumes that the script is running from submitty/sbin. * - * @access private * @static + * @access private */ - private static function get_daemon_user() { - $json = file_get_contents("../config/submitty_users.json"); - if ($json === false) { - return false; - } else { - $json = json_decode($json, true); - self::$daemon_user = array( - 'name' => $json['daemon_user'], - 'uid' => $json['daemon_uid'], - 'gid' => $json['daemon_gid'] - ); + private static function get_config() { - return true; - } - } + self::$config['mode'] = cli_args::parse_args(); + //'prod' reads yesterday's CSV. 'dev' read's most current CSV. + self::$config['psql_log_time_offset'] = (self::$config['mode'] === 'prod' ? -86400 : 0); - /** - * Override self::$config with a few elements from submitty.json - * - * This function assumes that the script is running from submitty/sbin. - * - * @access private - * @static - */ - private static function override_config() { - $json['config'] = file_get_contents("../config/submitty.json"); - if ($json['config'] === false) { - fwrite(STDERR, "Cannot open config/submitty.json" . PHP_EOL); + $json = file_get_contents("../config/submitty.json"); + if ($json === false) { + // Error logging not configured yet. + fwrite(STDERR, print_r(error_get_last(), true)); exit(1); } - $json['config'] = json_decode($json['config'], true); - self::$config['timezone'] = $json['config']['timezone']; - self::$config['postgresql_logfile_path'] = $json['config']['site_log_path'] . "/psql/"; - self::$config['submitty_logfile_path'] = $json['config']['site_log_path'] . "/preferred_names/"; + $json = json_decode($json, true); + date_default_timezone_set($json['timezone']); + self::$config['postgresql_logfile_path'] = $json['site_log_path'] . self::POSTGRESQL_LOGDIR; + self::$config['pfn_logfile_path'] = $json['site_log_path'] . self::PREFERRED_NAMES_LOGDIR; + + $json = file_get_contents("../config/preferred_name_logging.json"); + if ($json !== false) { + $json = json_decode($json, true); + + if (array_key_exists('log_emails', $json)) { + if (is_array($json['log_emails'])) { + self::$config['log_emails'] = $json['log_emails']; + } else { + self::$config['log_emails'] = array($json['log_emails']); + } + } else { + self::$config['log_emails'] = null; + } + + if (array_key_exists('log_file_retention', $json)) { + self::$config['log_file_retention'] = intval($json['log_file_retention']); + } else { + self::$config['log_file_retention'] = 7; + } + } } /** - * Process method + * Scrape psql log and write preferred_names log * - * @access private * @static + * @access private */ private static function parse_and_write_logs() { //Check to make sure Submitty log directory path exists. Create it if needed. - if (file_exists(self::$config['submitty_logfile_path']) === false) { - if (mkdir(self::$config['submitty_logfile_path'], 0700) === false) { - self::log("Submitty log folder needed, mkdir failed."); - exit(1); - } + if (file_exists(self::$config['pfn_logfile_path']) === false) { + self::log("Submitty log folder missing."); + exit(1); } //Prepare submitty preferred name change log file for today. - $submitty_logfile = sprintf("%s%s_%s.log", self::$config['submitty_logfile_path'], self::$config['submitty_logfile'], date("Y-m-d")); - $submitty_fh = fopen($submitty_logfile, 'w'); - if ($submitty_fh === false) { + $pfn_log_file = sprintf("%s%s_%s.log", self::$config['pfn_logfile_path'], self::PREFERRED_NAMES_LOGFILE, date("Y-m-d")); + $pfn_fh = fopen($pfn_log_file, 'w'); + if ($pfn_fh === false) { self::log("Cannot create Submitty logfile."); exit(1); } else { - fwrite($submitty_fh, "Log opened." . PHP_EOL); + fwrite($pfn_fh, "Log opened." . PHP_EOL); } //There can be multiple psql log files that need to be read. - //But we want the ones dated one day prior (hence subtract 86400 seconds which is one day) - $preg_str = sprintf("~^%s\-%s_\d{6}\.csv$~", self::$config['postgresql_logfile'], preg_quote(date("Y-m-d", time() + self::$psql_log_time_offset))); + $preg_str = sprintf("~^%s\-%s_\d{6}\.csv$~", self::POSTGRESQL_LOGFILE, preg_quote(date("Y-m-d", time() + self::$config['psql_log_time_offset']))); $logfiles = preg_grep($preg_str, scandir(self::$config['postgresql_logfile_path'])); foreach ($logfiles as $logfile) { @@ -191,7 +144,7 @@ private static function parse_and_write_logs() { //Validation. Any case is true, validation fails and row is ignored. switch(true) { case count($psql_row) !== self::POSTGRESQL_LOG_ROW_COUNT; - self::log(sprintf("NOTICE: PSQL log row %d had %d columns. %d columns expected. Row ignored.%s", $psql_row_num, count($psql_row), self::$config['postgresql_log_row_count'])); + self::log(sprintf("NOTICE: PSQL log row %d had %d columns. %d columns expected. Row ignored.", $psql_row_num, count($psql_row), self::$config['postgresql_log_row_count'])); case $psql_row[self::PSQL_VALIDATION_UPDATE] !== "UPDATE": case $psql_row[self::PSQL_VALIDATION_LOG] !== "LOG": case $psql_row[self::PSQL_VALIDATION_PFN] !== "PREFERRED_NAME DATA UPDATE": @@ -209,14 +162,12 @@ private static function parse_and_write_logs() { //Get "AUTH" token (who logged the change). $key = array(); - if (preg_match("~/\* AUTH: \"[\w\-]+\" \*/~", $psql_row[19]) === 1) { + if (preg_match("~/\* AUTH: \"[\w\-]+\" \*/~", $psql_row[self::PSQL_DATA_AUTH]) === 1) { $key['start'] = strpos($psql_row[self::PSQL_DATA_AUTH], "/* AUTH: ") + 3; $key['end'] = strpos($psql_row[self::PSQL_DATA_AUTH], " */"); $auth = " | " . substr($psql_row[self::PSQL_DATA_AUTH], $key['start'], $key['end'] - $key['start']); } else { $auth = " | AUTH NOT LOGGED "; - //Anything sent to STDERR gets emailed by cron. - fprintf(STDERR, "WARNING: AUTH NOT LOGGED%s%s", PHP_EOL, var_export($psql_row, true)); } //Get user_id and preferred name change tokens. @@ -229,8 +180,6 @@ private static function parse_and_write_logs() { $user_id = " | USER_ID: {$preferred_names_data[$key+1]} "; } else { $user_id = " | USER_ID NOT LOGGED "; - //Anything sent to STDERR gets emailed by cron. - fprintf(STDERR, "WARNING: USER ID NOT LOGGED%s%s", PHP_EOL, var_export($psql_row, true)); } $key = array_search("PREFERRED_FIRSTNAME", $preferred_names_data); @@ -248,21 +197,21 @@ private static function parse_and_write_logs() { // It is possible that no Preferred Lastname was logged, in which we can ignore an move on. //Build preferred name change log entry. - $submitty_log = $date . $auth . $user_id; + $pfn_log_row = $date . $auth . $user_id; if (isset($preferred_name['first'])) { - $submitty_log .= " | PREFERRED_FIRSTNAME OLD: {$preferred_name['first']['old']} NEW: {$preferred_name['first']['new']}"; + $pfn_log_row .= " | PREFERRED_FIRSTNAME OLD: {$preferred_name['first']['old']} NEW: {$preferred_name['first']['new']}"; } else { - $submitty_log .= " | PREFERRED_FIRSTNAME UNCHANGED"; + $pfn_log_row .= " | PREFERRED_FIRSTNAME UNCHANGED"; } if (isset($preferred_name['last'])) { - $submitty_log .= " | PREFERRED_LASTNAME OLD: {$preferred_name['last']['old']} NEW: {$preferred_name['last']['new']}"; + $pfn_log_row .= " | PREFERRED_LASTNAME OLD: {$preferred_name['last']['old']} NEW: {$preferred_name['last']['new']}"; } else { - $submitty_log .= " | PREFERRED_LASTNAME UNCHANGED"; + $pfn_log_row .= " | PREFERRED_LASTNAME UNCHANGED"; } //Write log entry and go to next row. - fwrite($submitty_fh, $submitty_log . PHP_EOL); + fwrite($pfn_fh, $pfn_log_row . PHP_EOL); $psql_row = fgetcsv($psql_fh); $psql_row_num++; } @@ -270,26 +219,26 @@ private static function parse_and_write_logs() { fclose($psql_fh); } - fwrite($submitty_fh, "Log closed." . PHP_EOL); - fclose($submitty_fh); + fwrite($pfn_fh, "Log closed." . PHP_EOL); + fclose($pfn_fh); } /** * Automatically remove old logs * - * @access private * @static + * @access private */ private static function log_retention_and_deletion() { $preg_str = sprintf("~^%s_%s.log$~", self::$config['submitty_logfile'], preg_quote(date("m-d-Y"))); - $logfiles = preg_grep($preg_str, scandir(self::$config['submitty_logfile_path'])); + $logfiles = preg_grep($preg_str, scandir(self::$config['pfn_logfile_path'])); $expiration_epoch = (int)(strtotime(date('Y-m-d')) / 86400) - self::$config['submitty_log_retention']; foreach($logfiles as $logfile) { $datestamp = substr($logfile, strpos($logfile, "_") + 1, 10); $datestamp_epoch = (int)(strtotime($datestamp) / 86400); if ($datestamp_epoch < $expiration_epoch) { - if (unlink(self::$config['submitty_logfile_path'] . $logfile) === false) { + if (unlink(self::$config['pfn_logfile_path'] . $logfile) === false) { self::log("Could not delete old logfile: {$logfile}"); } } @@ -297,50 +246,55 @@ private static function log_retention_and_deletion() { } /** - * Log messages to error log and STDERR. + * Log messages to error log. Also log to STDERR in 'dev' mode. * - * @access private * @static + * @access private */ private static function log(string $msg) { - $datestamp = date("m-d-Y"); - error_log(sprintf("%s %s", $datestamp, $msg), 0); - fwrite(STDERR, $msg . PHP_EOL); + $msg = sprintf("%s %s%s%s%s", date("m-d-Y"), $msg, PHP_EOL, var_export(error_get_last(), true), PHP_EOL); + error_log($msg, 3, self::$config['pfn_logfile_path'] . self::ERROR_LOGFILE); + + if (self::$config['mode'] === 'dev') { + fwrite(STDERR, $msg); + } + + if (is_array(self::$config['log_emails'])) { + $send_msg = "Error log from Submitty preferred name logging." . PHP_EOL . $msg; + $send_msg = wordwrap($send_msg, 70); + foreach(self::$config['log_emails'] as $email) { + error_log($send_msg, 1, $email); + } + } } } //END class main -/** - * class to parse command line arguments - * - * @static - */ +/** Class to parse command line arguments */ class cli_args { - /** @var string usage help message */ + /** @staticvar string usage help message */ private static $help_usage = << From f129a2582353a57955737d64cf753c6ceb7bb072 Mon Sep 17 00:00:00 2001 From: pbailie Date: Tue, 17 Sep 2019 19:01:08 -0400 Subject: [PATCH 05/14] Update preferred_name_logging.php WIP --- preferred_name_logging/preferred_name_logging.php | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/preferred_name_logging/preferred_name_logging.php b/preferred_name_logging/preferred_name_logging.php index 4fcb0cd..1586c17 100755 --- a/preferred_name_logging/preferred_name_logging.php +++ b/preferred_name_logging/preferred_name_logging.php @@ -259,7 +259,7 @@ private static function log(string $msg) { fwrite(STDERR, $msg); } - if (is_array(self::$config['log_emails'])) { + if (!is_null(self::$config['log_emails'])) { $send_msg = "Error log from Submitty preferred name logging." . PHP_EOL . $msg; $send_msg = wordwrap($send_msg, 70); foreach(self::$config['log_emails'] as $email) { From 36557cb5671237927d40f739962e25be51cabd2d Mon Sep 17 00:00:00 2001 From: pbailie Date: Wed, 25 Sep 2019 19:39:45 -0400 Subject: [PATCH 06/14] Update preferred_name_logging.php WIP --- .../preferred_name_logging.php | 47 ++++++++++--------- 1 file changed, 25 insertions(+), 22 deletions(-) diff --git a/preferred_name_logging/preferred_name_logging.php b/preferred_name_logging/preferred_name_logging.php index 1586c17..360c91b 100755 --- a/preferred_name_logging/preferred_name_logging.php +++ b/preferred_name_logging/preferred_name_logging.php @@ -48,7 +48,7 @@ public static function run() { exit(1); } - ini_set(display_errors, "0"); + ini_set('display_errors', '0'); self::get_config(); self::parse_and_write_logs(); self::log_retention_and_deletion(); @@ -70,37 +70,40 @@ private static function get_config() { //'prod' reads yesterday's CSV. 'dev' read's most current CSV. self::$config['psql_log_time_offset'] = (self::$config['mode'] === 'prod' ? -86400 : 0); - $json = file_get_contents("../config/submitty.json"); - if ($json === false) { + if (file_exists("../config/submitty.json")) { + $json = file_get_contents("../config/submitty.json"); + $json = json_decode($json, true); + } else { // Error logging not configured yet. fwrite(STDERR, print_r(error_get_last(), true)); exit(1); } - $json = json_decode($json, true); date_default_timezone_set($json['timezone']); self::$config['postgresql_logfile_path'] = $json['site_log_path'] . self::POSTGRESQL_LOGDIR; self::$config['pfn_logfile_path'] = $json['site_log_path'] . self::PREFERRED_NAMES_LOGDIR; - $json = file_get_contents("../config/preferred_name_logging.json"); - if ($json !== false) { + if (file_exists("../config/preferred_name_logging.json")) { + $json = file_get_contents("../config/preferred_name_logging.json"); $json = json_decode($json, true); + } else { + $json = array(); + } - if (array_key_exists('log_emails', $json)) { - if (is_array($json['log_emails'])) { - self::$config['log_emails'] = $json['log_emails']; - } else { - self::$config['log_emails'] = array($json['log_emails']); - } + if (array_key_exists('log_emails', $json)) { + if (is_array($json['log_emails'])) { + self::$config['log_emails'] = $json['log_emails']; } else { - self::$config['log_emails'] = null; + self::$config['log_emails'] = array($json['log_emails']); } + } else { + self::$config['log_emails'] = null; + } - if (array_key_exists('log_file_retention', $json)) { - self::$config['log_file_retention'] = intval($json['log_file_retention']); - } else { - self::$config['log_file_retention'] = 7; - } + if (array_key_exists('log_file_retention', $json)) { + self::$config['log_file_retention'] = (int)$json['log_file_retention']; + } else { + self::$config['log_file_retention'] = 7; } } @@ -111,7 +114,7 @@ private static function get_config() { * @access private */ private static function parse_and_write_logs() { - //Check to make sure Submitty log directory path exists. Create it if needed. + //Check to make sure Submitty log directory path exists. if (file_exists(self::$config['pfn_logfile_path']) === false) { self::log("Submitty log folder missing."); exit(1); @@ -230,15 +233,15 @@ private static function parse_and_write_logs() { * @access private */ private static function log_retention_and_deletion() { - $preg_str = sprintf("~^%s_%s.log$~", self::$config['submitty_logfile'], preg_quote(date("m-d-Y"))); + $preg_str = sprintf("~^%s_%s.log$~", self::$config['pfn_logfile_path'], preg_quote(date("m-d-Y"))); $logfiles = preg_grep($preg_str, scandir(self::$config['pfn_logfile_path'])); - $expiration_epoch = (int)(strtotime(date('Y-m-d')) / 86400) - self::$config['submitty_log_retention']; + $expiration_epoch = (int)(strtotime(date('Y-m-d')) / 86400) - self::$config['log_file_retention']; foreach($logfiles as $logfile) { $datestamp = substr($logfile, strpos($logfile, "_") + 1, 10); $datestamp_epoch = (int)(strtotime($datestamp) / 86400); if ($datestamp_epoch < $expiration_epoch) { - if (unlink(self::$config['pfn_logfile_path'] . $logfile) === false) { + if (unlink(self::$config['log_file_retention'] . $logfile) === false) { self::log("Could not delete old logfile: {$logfile}"); } } From 26e43dc6a24afe945053b683e32edb56c3748b55 Mon Sep 17 00:00:00 2001 From: pbailie Date: Fri, 27 Sep 2019 20:19:41 -0400 Subject: [PATCH 07/14] Update readme.md WIP --- preferred_name_logging/readme.md | 154 +++++++++++++++---------------- 1 file changed, 72 insertions(+), 82 deletions(-) diff --git a/preferred_name_logging/readme.md b/preferred_name_logging/readme.md index 9e0f16f..ff7e925 100644 --- a/preferred_name_logging/readme.md +++ b/preferred_name_logging/readme.md @@ -1,96 +1,86 @@ # Preferred Name Logging -This tool will help track when user preferred names are changed. It attempts to -log who was authenticated for the change, and what change occurred. +This script will help track when user preferred names are changed. It attempts +to log who was authenticated for the change, and what change occurred. It works by first having Postgresql log the required information as the data is updated in Submitty's databases. Then the sysadmin tool in this folder will scrape the Postgresql logfile and record only those entries that showed preferred name change. +This is setup and cofnigured by Submitty during system installation and should +automatically operate daily at 2:05AM. + ## FERPA Data processed and logged by this tool may be protected by [FERPA (20 U.S.C. ยง 1232g)](https://www2.ed.gov/policy/gen/guid/fpco/ferpa/index.html). Please consult and abide by your institute's data protection policies. -## Postgresql - -Submitty's website code and database schema will instruct Postgresql to log any -`UPDATE` query involving any user's preferred first or last name changes. - -### Postgresql Configuration - -Postgresql needs to be configured to produce the required logs as the necessary -logging is not enabled by default. - -#### Config file - -- Config file is `Postgresql.conf` - - In Ubuntu 18.04, it is located in `/etc/postgresql/10/main/postgresql.conf` - -#### Config options - -You will find these options under "ERROR REPORTING AND LOGGING". Please enable -(remove the '#' symbol preceding the line) and set these values: - -- `log_destination = 'csvlog'` - - The sysadmin tool will scrape a CSV file. -- `logging_collector = on` - - Postgresql doesn't write logs without. this. -- `log_directory = '/var/log/postgresql'` - - You can use a different folder, if needed. -- `log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log'` - - You can change the filename a little, but it **must** end with `-%Y-%m-%d_%H%M%S.log` -- `log_file_mode = 0600` - - Limits access to this logfile. -- `log_rotation_age = 2d` - - At least 2 days of logs will be needed since the sysadmin tool is intended - to run the following day. -- `log_rotation_size = 10MB` - - This doesn't need to be changed. Any additional logfiles created for a - single day will be picked up by the sysadmin tool. -- `log_min_messages = log` - - Preferred name changes are logged at the `log` level. You can set any - higher level of detail, but not lower than `log`. -- `log_min_duration_statement = 0` - - We want all log instances regardless of process time. -- `log_line_prefix = '%m [%p] %q%u@%d '` - - This can be changed so long as the very first detail is a timestamp. The - sysadmin tool expects to find a timestamp at the very first column. - -## Sysadmin Tool - -The sysadmin tool needs to be run on a machine with local file access to the -Postgresql log file. It is written in PHP. - -### Sysdamin Tool Config - -The configuration is defined as a class constant. Near the top of the code is a -small block starting as `private const CONFIG = array(`. Inside the block will -be a config element in single quotes, an arrow like `=>`, a value possibly -enclosed in double quotes, followed by a comma. (Do not lose the comma!) - -- `'timezone' => "America/New_York",` - - Set this to your local timezone. q.v. - [https://www.php.net/manual/en/timezones.php](https://www.php.net/manual/en/timezones.php) - for more information. -- `'postgresql_logfile_path' => "/var/log/postgresql/",` - - Set this to the same setting as `log_directory` in `postgresql.conf`. -- `'submitty_logfile_path' => "/var/log/submitty/",` - - Where the sysadmin tool will write the preferred name logfile. -- `'postgresql_logfile' => "postgresql",` - - The name of the logfile created by Postgresql. Do not include the time - stamp. This only needs to be changed when `log_filename` in - `postgresql.conf` is changed. -- `'submitty_logfile' => "submitty_preferred_names",` - - Name of the preferred name change logfile. You can leave this as is. -- `'submitty_log_retention' => 7` - - How many days of preferred name change logs to keep. - -### Running the Sysadmin Tool - -This tool is meant to be executed on the command line and can be scheduled as a -cron job. Errors will be outputted to `STDERR`, which in a crontab can either -be redirected to `/dev/null` or emailed to a sysadmin. Running as `root` is -required, and there are no command line arguments. +## Logs + +Submitty's installation scripts will configure postgresql to write its logs to +`/var/local/submitty/logs/psql/`, rotated on a daily basis. + +This script will scrape the previous day's Postgresql log for any logged +changes to any user's preferred names. It will then create a daily log of +*preferred name changes* within `/var/local/submitty/logs/preferred_names`. + +This script will also remove postgresql logs older than 2 days as postgresql's +own log rotation system will not selectively remove outdated logs. + +## postgresql.conf + +The following configuration will be applied to postgresql: +``` +log_destination = 'csvlog' +logging_collector = on +log_directory = '/var/log/postgresql' +log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log' +log_file_mode = 0640 +log_rotation_age = 1d +log_rotation_size = 0 +log_min_messages = log +log_min_duration_statement = 0 +log_line_prefix = '%t ' +``` + +## preferred_names.json + +A sysadmin may optionally create a json file to configure a couple of options +for preferred name logging. If this json is not created, the script will +assume default settings, instead. + +To set these options, first create an empty text file in +`usr/local/submitty/config/preferred_names.json` + +Next, following the json format, you may set the following options (anything +else in the file will be ignored). + +* `log_emails` + This is either a singular email address or a list of email addresses. The + script will send error messages to the email address(es) listed. + + If this is a list, key values are ignored. But you could set key values to be + descriptive to who owns a particular email address. + + Set to `null` to turn this off. Default setting is `null`. + +* `log_file_retention` + A whole number representing how many days of preferred name change logs to + keep. *This does not affect the lifetime cycle of postgresql's logs* + Default setting is 7. + + Example json: + ```json +{ + "log_emails": + { + "Ada_Lovelace": "alovelace@submitty.com", + "Charles_Babbage": "cbabbage@submitty.com", + "Sysadmin_Mailing_List": "sysadmins@lists.submitty.com" + }, + + "log_file_retention": 30 +} +``` From 0710e45ba99a16557996da1d09dbaff6daf42030 Mon Sep 17 00:00:00 2001 From: pbailie Date: Fri, 27 Sep 2019 20:23:16 -0400 Subject: [PATCH 08/14] Update readme.md WIP --- preferred_name_logging/readme.md | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/preferred_name_logging/readme.md b/preferred_name_logging/readme.md index ff7e925..12e1b3d 100644 --- a/preferred_name_logging/readme.md +++ b/preferred_name_logging/readme.md @@ -24,7 +24,7 @@ Submitty's installation scripts will configure postgresql to write its logs to This script will scrape the previous day's Postgresql log for any logged changes to any user's preferred names. It will then create a daily log of -*preferred name changes* within `/var/local/submitty/logs/preferred_names`. +*preferred name changes* within `/var/local/submitty/logs/preferred_names/`. This script will also remove postgresql logs older than 2 days as postgresql's own log rotation system will not selectively remove outdated logs. @@ -61,8 +61,8 @@ else in the file will be ignored). This is either a singular email address or a list of email addresses. The script will send error messages to the email address(es) listed. - If this is a list, key values are ignored. But you could set key values to be - descriptive to who owns a particular email address. + If this is a list, key values are ignored. But you could set key values to + document who owns a particular email address. Set to `null` to turn this off. Default setting is `null`. @@ -72,7 +72,7 @@ else in the file will be ignored). Default setting is 7. Example json: - ```json +```json { "log_emails": { From ada59d97d248eda867f0c64a8a531513f7180f60 Mon Sep 17 00:00:00 2001 From: pbailie Date: Fri, 27 Sep 2019 20:29:45 -0400 Subject: [PATCH 09/14] Update readme.md WIP --- preferred_name_logging/readme.md | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/preferred_name_logging/readme.md b/preferred_name_logging/readme.md index 12e1b3d..e9bdaa3 100644 --- a/preferred_name_logging/readme.md +++ b/preferred_name_logging/readme.md @@ -68,8 +68,7 @@ else in the file will be ignored). * `log_file_retention` A whole number representing how many days of preferred name change logs to - keep. *This does not affect the lifetime cycle of postgresql's logs* - Default setting is 7. + keep. *This does not affect postgresql's logs.* Default setting is 7. Example json: ```json From 4fcf569f60dddf536689b62e31b913551123a71d Mon Sep 17 00:00:00 2001 From: pbailie Date: Fri, 27 Sep 2019 21:38:32 -0400 Subject: [PATCH 10/14] Update preferred_name_logging.php WIP --- .../preferred_name_logging.php | 36 ++++++++++++------- 1 file changed, 24 insertions(+), 12 deletions(-) diff --git a/preferred_name_logging/preferred_name_logging.php b/preferred_name_logging/preferred_name_logging.php index 360c91b..367f9ab 100755 --- a/preferred_name_logging/preferred_name_logging.php +++ b/preferred_name_logging/preferred_name_logging.php @@ -227,25 +227,37 @@ private static function parse_and_write_logs() { } /** - * Automatically remove old logs + * Automatically remove expired postgresql and preferred name change logs. + * + * Note that there is 86400 seconds in a day. * * @static * @access private */ private static function log_retention_and_deletion() { - $preg_str = sprintf("~^%s_%s.log$~", self::$config['pfn_logfile_path'], preg_quote(date("m-d-Y"))); - $logfiles = preg_grep($preg_str, scandir(self::$config['pfn_logfile_path'])); - $expiration_epoch = (int)(strtotime(date('Y-m-d')) / 86400) - self::$config['log_file_retention']; - - foreach($logfiles as $logfile) { - $datestamp = substr($logfile, strpos($logfile, "_") + 1, 10); - $datestamp_epoch = (int)(strtotime($datestamp) / 86400); - if ($datestamp_epoch < $expiration_epoch) { - if (unlink(self::$config['log_file_retention'] . $logfile) === false) { - self::log("Could not delete old logfile: {$logfile}"); + $remove_logfiles = function($logfiles, $expiration_epoch) { + foreach($logfiles as $logfile) { + $datestamp = substr($logfile, strpos($logfile, "_") + 1, 10); + $datestamp_epoch = strtotime($datestamp) / 86400; + if ($datestamp_epoch < $expiration_epoch) { + if (unlink(self::$config['log_file_retention'] . $logfile) === false) { + self::log("Could not delete expired logfile: {$logfile}"); + } } } - } + }; + + // Remove expired postgresql logs + $regex_pattern = sprintf("~^%s_\d{4}\-\d{2}\-\d{2}\-\d{6}\.csv|log$~", self::POSTGRESQL_LOGFILE); + $logfiles = preg_grep($regex_pattern, scandir(self::$config['postgresql_logfile_path'])); + $expiration_epoch = strtotime(date('Y-m-d')) / 86400 - 2; + $remove_logfiles($logfiles, $expiration_epoch); + + // Remove expired preferred name change logs + $regex_pattern = sprintf("~^%s_\d{4}\-\d{2}\-\d{2}\.log$~", self::PREFERRED_NAMES_LOGFILE); + $logfiles = preg_grep($regex_pattern, scandir(self::$config['pfn_logfile_path'])); + $expiration_epoch = strtotime(date('Y-m-d')) / 86400 - self::$config['log_file_retention']; + $remove_logfiles($logfiles, $expiration_epoch); } /** From 37b20eea1497b0272e210af3ed6ac0f5c266ca78 Mon Sep 17 00:00:00 2001 From: pbailie Date: Fri, 27 Sep 2019 21:48:31 -0400 Subject: [PATCH 11/14] Update readme.md and preferred_name_logging.php WIP --- preferred_name_logging/preferred_name_logging.php | 2 +- preferred_name_logging/readme.md | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/preferred_name_logging/preferred_name_logging.php b/preferred_name_logging/preferred_name_logging.php index 367f9ab..74c6add 100755 --- a/preferred_name_logging/preferred_name_logging.php +++ b/preferred_name_logging/preferred_name_logging.php @@ -131,7 +131,7 @@ private static function parse_and_write_logs() { } //There can be multiple psql log files that need to be read. - $preg_str = sprintf("~^%s\-%s_\d{6}\.csv$~", self::POSTGRESQL_LOGFILE, preg_quote(date("Y-m-d", time() + self::$config['psql_log_time_offset']))); + $preg_str = sprintf("~^%s_%s\-\d{6}\.csv$~", self::POSTGRESQL_LOGFILE, preg_quote(date("Y-m-d", time() + self::$config['psql_log_time_offset']))); $logfiles = preg_grep($preg_str, scandir(self::$config['postgresql_logfile_path'])); foreach ($logfiles as $logfile) { diff --git a/preferred_name_logging/readme.md b/preferred_name_logging/readme.md index e9bdaa3..055e023 100644 --- a/preferred_name_logging/readme.md +++ b/preferred_name_logging/readme.md @@ -36,7 +36,7 @@ The following configuration will be applied to postgresql: log_destination = 'csvlog' logging_collector = on log_directory = '/var/log/postgresql' -log_filename = 'postgresql-%Y-%m-%d_%H%M%S.log' +log_filename = 'postgresql_%Y-%m-%d-%H%M%S.log' log_file_mode = 0640 log_rotation_age = 1d log_rotation_size = 0 From 10d8822d0546e28506d99e6575c0ec0329760128 Mon Sep 17 00:00:00 2001 From: pbailie Date: Mon, 30 Sep 2019 17:24:06 -0400 Subject: [PATCH 12/14] Update preferred_name_logging.php WIP --- .../preferred_name_logging.php | 20 +++++++++---------- 1 file changed, 10 insertions(+), 10 deletions(-) diff --git a/preferred_name_logging/preferred_name_logging.php b/preferred_name_logging/preferred_name_logging.php index 74c6add..9cb425d 100755 --- a/preferred_name_logging/preferred_name_logging.php +++ b/preferred_name_logging/preferred_name_logging.php @@ -32,7 +32,7 @@ class main { private const POSTGRESQL_LOGDIR = '/psql/'; private const POSTGRESQL_LOGFILE = 'postgresql'; private const PREFERRED_NAMES_LOGDIR = '/preferred_names/'; - private const PREFERRED_NAMES_LOGFILE = 'preferred_names'; + private const PREFERRED_NAMES_LOGFILE = 'preferred-names'; private const ERROR_LOGFILE = 'errors.log'; /** @@ -235,13 +235,13 @@ private static function parse_and_write_logs() { * @access private */ private static function log_retention_and_deletion() { - $remove_logfiles = function($logfiles, $expiration_epoch) { + $remove_logfiles = function($path, $logfiles, $expiration_epoch) { foreach($logfiles as $logfile) { $datestamp = substr($logfile, strpos($logfile, "_") + 1, 10); - $datestamp_epoch = strtotime($datestamp) / 86400; + $datestamp_epoch = intdiv(strtotime($datestamp), 86400); if ($datestamp_epoch < $expiration_epoch) { - if (unlink(self::$config['log_file_retention'] . $logfile) === false) { - self::log("Could not delete expired logfile: {$logfile}"); + if (unlink($path . $logfile) === false) { + self::log("Unable to delete expired log {$logfile}"); } } } @@ -250,14 +250,14 @@ private static function log_retention_and_deletion() { // Remove expired postgresql logs $regex_pattern = sprintf("~^%s_\d{4}\-\d{2}\-\d{2}\-\d{6}\.csv|log$~", self::POSTGRESQL_LOGFILE); $logfiles = preg_grep($regex_pattern, scandir(self::$config['postgresql_logfile_path'])); - $expiration_epoch = strtotime(date('Y-m-d')) / 86400 - 2; - $remove_logfiles($logfiles, $expiration_epoch); + $expiration_epoch = intdiv(time(), 86400) - 2; + $remove_logfiles(self::$config['postgresql_logfile_path'], $logfiles, $expiration_epoch); // Remove expired preferred name change logs $regex_pattern = sprintf("~^%s_\d{4}\-\d{2}\-\d{2}\.log$~", self::PREFERRED_NAMES_LOGFILE); $logfiles = preg_grep($regex_pattern, scandir(self::$config['pfn_logfile_path'])); - $expiration_epoch = strtotime(date('Y-m-d')) / 86400 - self::$config['log_file_retention']; - $remove_logfiles($logfiles, $expiration_epoch); + $expiration_epoch = intdiv(time(), 86400) - self::$config['log_file_retention']; + $remove_logfiles(self::$config['pfn_logfile_path'], $logfiles, $expiration_epoch); } /** @@ -267,7 +267,7 @@ private static function log_retention_and_deletion() { * @access private */ private static function log(string $msg) { - $msg = sprintf("%s %s%s%s%s", date("m-d-Y"), $msg, PHP_EOL, var_export(error_get_last(), true), PHP_EOL); + $msg = sprintf("%s %s%s%s%s", date("m-d-Y H:i:s"), $msg, PHP_EOL, var_export(error_get_last(), true), PHP_EOL); error_log($msg, 3, self::$config['pfn_logfile_path'] . self::ERROR_LOGFILE); if (self::$config['mode'] === 'dev') { From 6c858b624b6623995387b15b8e5b4346a918743f Mon Sep 17 00:00:00 2001 From: pbailie Date: Tue, 8 Oct 2019 19:50:47 -0400 Subject: [PATCH 13/14] Update WIP --- .../preferred_name_logging.php | 4 ++-- preferred_name_logging/readme.md | 18 ++++++++++-------- 2 files changed, 12 insertions(+), 10 deletions(-) diff --git a/preferred_name_logging/preferred_name_logging.php b/preferred_name_logging/preferred_name_logging.php index 9cb425d..01e7560 100755 --- a/preferred_name_logging/preferred_name_logging.php +++ b/preferred_name_logging/preferred_name_logging.php @@ -131,7 +131,7 @@ private static function parse_and_write_logs() { } //There can be multiple psql log files that need to be read. - $preg_str = sprintf("~^%s_%s\-\d{6}\.csv$~", self::POSTGRESQL_LOGFILE, preg_quote(date("Y-m-d", time() + self::$config['psql_log_time_offset']))); + $preg_str = sprintf("~^%s_%sT\d{6}\.csv$~", self::POSTGRESQL_LOGFILE, preg_quote(date("Y-m-d", time() + self::$config['psql_log_time_offset']))); $logfiles = preg_grep($preg_str, scandir(self::$config['postgresql_logfile_path'])); foreach ($logfiles as $logfile) { @@ -267,7 +267,7 @@ private static function log_retention_and_deletion() { * @access private */ private static function log(string $msg) { - $msg = sprintf("%s %s%s%s%s", date("m-d-Y H:i:s"), $msg, PHP_EOL, var_export(error_get_last(), true), PHP_EOL); + $msg = sprintf("%s %s%sDetails: %s%s", date("m-d-Y H:i:s"), $msg, PHP_EOL, print_r(error_get_last(), true), PHP_EOL); error_log($msg, 3, self::$config['pfn_logfile_path'] . self::ERROR_LOGFILE); if (self::$config['mode'] === 'dev') { diff --git a/preferred_name_logging/readme.md b/preferred_name_logging/readme.md index 055e023..14eb1b1 100644 --- a/preferred_name_logging/readme.md +++ b/preferred_name_logging/readme.md @@ -8,7 +8,7 @@ updated in Submitty's databases. Then the sysadmin tool in this folder will scrape the Postgresql logfile and record only those entries that showed preferred name change. -This is setup and cofnigured by Submitty during system installation and should +This is setup and configured by Submitty during system installation and should automatically operate daily at 2:05AM. ## FERPA @@ -27,22 +27,24 @@ changes to any user's preferred names. It will then create a daily log of *preferred name changes* within `/var/local/submitty/logs/preferred_names/`. This script will also remove postgresql logs older than 2 days as postgresql's -own log rotation system will not selectively remove outdated logs. +own log rotation will not selectively remove outdated logs. ## postgresql.conf -The following configuration will be applied to postgresql: +Postgresql's original configuration is first copied to `postgresql.conf.backup`. +The following changes will be applied: ``` log_destination = 'csvlog' logging_collector = on log_directory = '/var/log/postgresql' -log_filename = 'postgresql_%Y-%m-%d-%H%M%S.log' +log_filename = 'postgresql_%Y-%m-%dT%H%M%S.log' log_file_mode = 0640 log_rotation_age = 1d log_rotation_size = 0 -log_min_messages = log -log_min_duration_statement = 0 -log_line_prefix = '%t ' +log_min_messages = warning +log_min_duration_statement = -1 +log_statement = 'ddl' +log_error_verbosity = default ``` ## preferred_names.json @@ -70,7 +72,7 @@ else in the file will be ignored). A whole number representing how many days of preferred name change logs to keep. *This does not affect postgresql's logs.* Default setting is 7. - Example json: +## Example json: ```json { "log_emails": From 17d2b731a5bc6fb30b4b1a44f918067f37ff99fd Mon Sep 17 00:00:00 2001 From: pbailie Date: Mon, 4 Nov 2019 18:01:30 -0500 Subject: [PATCH 14/14] Update preferred_name_logging.php WIP (correct spacing of log output) --- preferred_name_logging/preferred_name_logging.php | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/preferred_name_logging/preferred_name_logging.php b/preferred_name_logging/preferred_name_logging.php index 01e7560..07eeeb0 100755 --- a/preferred_name_logging/preferred_name_logging.php +++ b/preferred_name_logging/preferred_name_logging.php @@ -170,7 +170,7 @@ private static function parse_and_write_logs() { $key['end'] = strpos($psql_row[self::PSQL_DATA_AUTH], " */"); $auth = " | " . substr($psql_row[self::PSQL_DATA_AUTH], $key['start'], $key['end'] - $key['start']); } else { - $auth = " | AUTH NOT LOGGED "; + $auth = " | AUTH NOT LOGGED"; } //Get user_id and preferred name change tokens. @@ -180,9 +180,9 @@ private static function parse_and_write_logs() { //user_id token $key = array_search("USER_ID:", $preferred_names_data); if ($key !== false) { - $user_id = " | USER_ID: {$preferred_names_data[$key+1]} "; + $user_id = " | USER_ID: {$preferred_names_data[$key+1]}"; } else { - $user_id = " | USER_ID NOT LOGGED "; + $user_id = " | USER_ID NOT LOGGED"; } $key = array_search("PREFERRED_FIRSTNAME", $preferred_names_data);