diff --git a/.gitignore b/.gitignore index a54800f..7ca5f92 100644 --- a/.gitignore +++ b/.gitignore @@ -9,6 +9,7 @@ phpunit *.sqlite *.txt storage/upload/css +storage/logs # Testing stuff /docker-compose.yml diff --git a/README.md b/README.md index a789d33..e333c2a 100644 --- a/README.md +++ b/README.md @@ -143,6 +143,19 @@ tkr stores profile information, custom emojis, and uploaded css metadata in a SQ You don't have to do any database setup. The database is automatically created and initialized on first run. +## FAQ + +### Why don't I see the right IPs in the logs? + +This can happen for a few reasons. Some common ones are: + +**Docker Development:** If running via Docker, you may see `192.168.65.1` (Docker Desktop gateway). This is normal for development. + +**Behind a Proxy/CDN:** If you're behind Cloudflare (with proxy enabled), load balancers, or other proxies, all requests may appear to come from the proxy's IP addresses. + +- **For accurate IP logging:** Configure your web server to trust proxy headers. See your proxy provider's documentation for the required nginx/Apache configuration. + + ## Acknowledgements It's been a lot of fun to get back to building something. I'm grateful to the people and projects that inspired me to do it: diff --git a/config/migrations/006_add_log_level_setting.sql b/config/migrations/006_add_log_level_setting.sql new file mode 100644 index 0000000..dbfd65b --- /dev/null +++ b/config/migrations/006_add_log_level_setting.sql @@ -0,0 +1,2 @@ +ALTER TABLE settings +ADD COLUMN log_level INTEGER NULL; diff --git a/public/index.php b/public/index.php index a94c73f..f7512c6 100644 --- a/public/index.php +++ b/public/index.php @@ -67,6 +67,7 @@ if (strpos($path, $config->basePath) === 0) { // strip the trailing slash from the resulting route $path = trim($path, '/'); +Log::debug("Path requested: {$path}"); // if this is a POST and we aren't in setup, // make sure there's a valid session @@ -75,12 +76,14 @@ if ($method === 'POST' && $path != 'setup') { if ($path != 'login'){ if (!Session::isValid($_POST['csrf_token'])) { // Invalid session - redirect to /login + Log::info('Attempt to POST with invalid session. Redirecting to login.'); header('Location: ' . $config->basePath . '/login'); exit; } } else { if (!Session::isValidCsrfToken($_POST['csrf_token'])) { // Just die if the token is invalid on login + Log::error("Attempt to log in with invalid CSRF token."); die('Invalid CSRF token'); exit; } @@ -92,6 +95,7 @@ header('Content-Type: text/html; charset=utf-8'); // Render the requested route or throw a 404 if (!Router::route($path, $method)){ + Log::error("No route found for path {$path}"); http_response_code(404); echo "404 - Page Not Found"; exit; diff --git a/src/Controller/AdminController/AdminController.php b/src/Controller/AdminController/AdminController.php index fffb607..a0898a3 100644 --- a/src/Controller/AdminController/AdminController.php +++ b/src/Controller/AdminController/AdminController.php @@ -64,7 +64,7 @@ class AdminController extends Controller { $basePath = trim($_POST['base_path'] ?? '/'); $itemsPerPage = (int) ($_POST['items_per_page'] ?? 25); $strictAccessibility = isset($_POST['strict_accessibility']); - $showTickMood = isset($_POST['show_tick_mood']); + $logLevel = (int) ($_POST['log_level'] ?? ''); // Password $password = $_POST['password'] ?? ''; @@ -114,6 +114,7 @@ class AdminController extends Controller { $config->basePath = $basePath; $config->itemsPerPage = $itemsPerPage; $config->strictAccessibility = $strictAccessibility; + $config->logLevel = $logLevel; // Save site settings and reload config from database // TODO - raise and handle exception on failure @@ -131,7 +132,7 @@ class AdminController extends Controller { // Update the password if one was sent // TODO - raise and handle exception on failure if($password){ - $user->set_password($password); + $user->setPassword($password); } Session::setFlashMessage('success', 'Settings updated'); diff --git a/src/Controller/AuthController/AuthController.php b/src/Controller/AuthController/AuthController.php index b13264b..72fe40e 100644 --- a/src/Controller/AuthController/AuthController.php +++ b/src/Controller/AuthController/AuthController.php @@ -20,21 +20,21 @@ class AuthController extends Controller { $username = $_POST['username'] ?? ''; $password = $_POST['password'] ?? ''; - // TODO: move into user model - global $db; - $stmt = $db->prepare("SELECT id, username, password_hash FROM user WHERE username = ?"); - $stmt->execute([$username]); - $user = $stmt->fetch(); + Log::debug("Login attempt for user {$username}"); + $userModel = new UserModel(); + $user = $userModel->getByUsername($username); + + //if ($user && password_verify($password, $user['password_hash'])) { if ($user && password_verify($password, $user['password_hash'])) { - session_regenerate_id(true); - // TODO: move into session.php - $_SESSION['user_id'] = $user['id']; - $_SESSION['username'] = $user['username']; - Session::generateCsrfToken(true); + Log::info("Successful login for {$username}"); + + Session::newLoginSession($user); header('Location: ' . $config->basePath); exit; } else { + Log::warning("Failed login for {$username}"); + // Set a flash message and reload the login page Session::setFlashMessage('error', 'Invalid username or password'); header('Location: ' . $_SERVER['PHP_SELF']); @@ -44,7 +44,9 @@ class AuthController extends Controller { } function handleLogout(){ + Log::info("Logout from user " . $_SESSION['username']); Session::end(); + global $config; header('Location: ' . $config->basePath); exit; diff --git a/src/Framework/Database/Database.php b/src/Framework/Database/Database.php index b503d23..2631176 100644 --- a/src/Framework/Database/Database.php +++ b/src/Framework/Database/Database.php @@ -60,6 +60,7 @@ class Database{ foreach ($files as $file) { $version = $this->migrationNumberFromFile($file); if ($version > $currentVersion) { + Log::debug("Found pending migration ({$version}): " . basename($file)); $pending[$version] = $file; } } @@ -72,9 +73,11 @@ class Database{ $migrations = $this->getPendingMigrations(); if (empty($migrations)) { - # TODO: log + Log::debug("No pending migrations"); return; } + Log::info("Found " . count($migrations) . "pending migrations."); + Log::info("Updating database. Current Version: " . $this->getVersion()); $db = self::get(); $db->beginTransaction(); @@ -82,7 +85,7 @@ class Database{ try { foreach ($migrations as $version => $file) { $filename = basename($file); - // TODO: log properly + Log::debug("Starting migration: {$filename}"); $sql = file_get_contents($file); if ($sql === false) { @@ -96,17 +99,20 @@ class Database{ // Execute each statement foreach ($statements as $statement){ if (!empty($statement)){ + Log::debug("Migration statement: {$statement}"); $db->exec($statement); } } + + Log::info("Applied migration {$filename}"); } // Update db version $db->commit(); $this->setVersion($version); - //TODO: log properly - //echo "All migrations completed successfully.\n"; + Log::info("Applied " . count($migrations) . " migrations."); + Log::info("Updated database version to " . $this->getVersion()); } catch (Exception $e) { $db->rollBack(); throw new SetupException( diff --git a/src/Framework/Exception/SetupException.php b/src/Framework/Exception/SetupException.php index 439157d..0bf0c54 100644 --- a/src/Framework/Exception/SetupException.php +++ b/src/Framework/Exception/SetupException.php @@ -12,6 +12,14 @@ class SetupException extends Exception { // Exceptions don't generally define their own handlers, // but this is a very specific case. public function handle(){ + // try to log the error, but keep going if it fails + try { + Log::error($this->setupIssue . ", " . $this->getMessage()); + } catch (Exception $e) { + // Do nothing and move on to the normal error handling + // We don't want to short-circuit this if there's a problem logging + } + switch ($this->setupIssue){ case 'database_connection': case 'db_migration': diff --git a/src/Framework/Log/Log.php b/src/Framework/Log/Log.php new file mode 100644 index 0000000..25158c4 --- /dev/null +++ b/src/Framework/Log/Log.php @@ -0,0 +1,89 @@ + 1, + 'INFO' => 2, + 'WARNING' => 3, + 'ERROR' => 4 + ]; + + private static $logFile; + private static $maxLines = 1000; + private static $maxFiles = 5; + + public static function init() { + self::$logFile = STORAGE_DIR . '/logs/tkr.log'; + + // Ensure log directory exists + // (should be handled by Prerequisites, but doesn't hurt) + $logDir = dirname(self::$logFile); + if (!is_dir($logDir)) { + mkdir($logDir, 0770, true); + } + } + + public static function debug($message) { + self::write('DEBUG', $message); + } + + public static function info($message) { + self::write('INFO', $message); + } + + public static function error($message) { + self::write('ERROR', $message); + } + + public static function warning($message) { + self::write('WARNING', $message); + } + + private static function write($level, $message) { + global $config; + $logLevel = $config->logLevel ?? self::LEVELS['INFO']; + + // Only log messages if they're at or above the configured log level. + if (self::LEVELS[$level] < $logLevel){ + return; + } + + if (!self::$logFile) { + self::init(); + } + + $timestamp = date('Y-m-d H:i:s'); + $logEntry = "[{$timestamp}] {$level}: " . Util::getClientIp() . " - {$message}\n"; + + // Rotate if we're at the max file size (1000 lines) + if (file_exists(self::$logFile)) { + $lineCount = count(file(self::$logFile)); + if ($lineCount >= self::$maxLines) { + self::rotate(); + Log::info("Log rotated at {$timestamp}"); + } + } + + file_put_contents(self::$logFile, $logEntry, FILE_APPEND | LOCK_EX); + } + + private static function rotate() { + // Rotate existing history files: tkr.4.log -> tkr.5.log, etc. + for ($i = self::$maxFiles - 1; $i >= 1; $i--) { + $oldFile = self::$logFile . '.' . $i; + $newFile = self::$logFile . '.' . ($i + 1); + + if (file_exists($oldFile)) { + if ($i == self::$maxFiles - 1) { + unlink($oldFile); // Delete oldest log if we already have 5 files of history + } else { + rename($oldFile, $newFile); // Bump the file number up by one + } + } + } + + // Move current active log to .1 + if (file_exists(self::$logFile)) { + rename(self::$logFile, self::$logFile . '.1'); + } + } +} \ No newline at end of file diff --git a/src/Framework/Prerequisites/Prerequisites.php b/src/Framework/Prerequisites/Prerequisites.php index b107fe2..6ff902e 100644 --- a/src/Framework/Prerequisites/Prerequisites.php +++ b/src/Framework/Prerequisites/Prerequisites.php @@ -37,7 +37,6 @@ class Prerequisites { */ private function log($message, $overwrite=false) { $logDir = dirname($this->logFile); - //print("Log dir: {$logDir}"); if (!is_dir($logDir)) { if (!@mkdir($logDir, 0770, true)) { // Can't create storage dir - just output, don't log to file @@ -48,6 +47,10 @@ class Prerequisites { } } + // Overwrite the log if $overwrite is set + // I overwrite the log for each new validation run, + // because prior results are irrelevant. + // This keeps it from growing without bound. $flags = LOCK_EX; if (!$overwrite) { $flags |= FILE_APPEND; @@ -66,6 +69,7 @@ class Prerequisites { } } + // Record the result of a validation check. private function addCheck($name, $status, $message, $severity = 'info') { $this->checks[] = array( 'name' => $name, @@ -85,6 +89,7 @@ class Prerequisites { } private function checkPhpVersion() { + // TODO - move to bootstrap.php? $minVersion = '8.2.0'; $currentVersion = PHP_VERSION; $versionOk = version_compare($currentVersion, $minVersion, '>='); @@ -192,6 +197,7 @@ class Prerequisites { $storageDirs = array( 'storage', 'storage/db', + 'storage/logs', 'storage/upload', 'storage/upload/css' ); diff --git a/src/Framework/Router/Router.php b/src/Framework/Router/Router.php index 5be25f9..e689f84 100644 --- a/src/Framework/Router/Router.php +++ b/src/Framework/Router/Router.php @@ -33,6 +33,8 @@ class Router { $controller = $routeHandler[1]; $methods = $routeHandler[2] ?? ['GET']; + Log::debug("Route: '{$routePattern}', Controller {$controller}, Methods: ". implode(',' , $methods)); + # Only allow valid route and filename characters # to prevent directory traversal and other attacks $routePattern = preg_replace('/\{([^}]+)\}/', '([a-zA-Z0-9._-]+)', $routePattern); @@ -43,18 +45,21 @@ class Router { // Save any path elements we're interested in // (but discard the match on the entire path) array_shift($matches); + Log::debug("Captured path elements: " . implode(',', $matches)); if (strpos($controller, '@')) { // Get the controller and method that handle this route - [$controllerName, $methodName] = explode('@', $controller); + [$controllerName, $functionName] = explode('@', $controller); } else { // Default to 'index' if no method specified $controllerName = $controller; - $methodName = 'index'; + $functionName = 'index'; } + Log::debug("Handling request with Controller {$controllerName} and function {$functionName}"); + $instance = new $controllerName(); - call_user_func_array([$instance, $methodName], $matches); + call_user_func_array([$instance, $functionName], $matches); return true; } } diff --git a/src/Framework/Session/Session.php b/src/Framework/Session/Session.php index 4220451..aad7e92 100644 --- a/src/Framework/Session/Session.php +++ b/src/Framework/Session/Session.php @@ -6,10 +6,30 @@ class Session { // global $_SESSION associative array public static function start(): void{ if (session_status() === PHP_SESSION_NONE) { + $existingSessionId = $_COOKIE['PHPSESSID'] ?? null; session_start(); + + if ($existingSessionId && session_id() === $existingSessionId) { + Log::debug("Resumed existing login session: " . session_id()); + } else { + Log::debug("Created new login session: " . session_id()); + } + } else { + Log::debug('Session already active in this request: ' . session_id()); } } + public static function newLoginSession(Array $user){ + Log::debug("Starting new login session for {$user['username']}"); + + session_regenerate_id(true); + $_SESSION['user_id'] = $user['id']; + $_SESSION['username'] = $user['username']; + self::generateCsrfToken(true); + + Log::debug("Started new login session for {$user['username']}"); + } + public static function generateCsrfToken(bool $regenerate = false): void{ if (!isset($_SESSION['csrf_token']) || $regenerate) { $_SESSION['csrf_token'] = bin2hex(random_bytes(32)); @@ -59,6 +79,7 @@ class Session { } public static function end(): void { + Log::debug("Ending session: " . session_id()); $_SESSION = []; session_destroy(); } diff --git a/src/Framework/Util/Util.php b/src/Framework/Util/Util.php index 63c0ef1..69ce7a0 100644 --- a/src/Framework/Util/Util.php +++ b/src/Framework/Util/Util.php @@ -1,5 +1,13 @@ fetch(PDO::FETCH_ASSOC); @@ -37,6 +39,7 @@ class ConfigModel { $c->itemsPerPage = (int) $row['items_per_page']; $c->cssId = (int) $row['css_id']; $c->strictAccessibility = (bool) $row['strict_accessibility']; + $c->logLevel = $row['log_level']; } return $c; @@ -67,9 +70,10 @@ class ConfigModel { base_path, items_per_page, css_id, - strict_accessibility + strict_accessibility, + log_level ) - VALUES (1, ?, ?, ?, ?, ?, ?, ?)"); + VALUES (1, ?, ?, ?, ?, ?, ?, ?, ?)"); } else { $stmt = $db->prepare("UPDATE settings SET site_title=?, @@ -78,9 +82,11 @@ class ConfigModel { base_path=?, items_per_page=?, css_id=?, - strict_accessibility=? + strict_accessibility=?, + log_level=? WHERE id=1"); } + $stmt->execute([$this->siteTitle, $this->siteDescription, $this->baseUrl, @@ -88,6 +94,7 @@ class ConfigModel { $this->itemsPerPage, $this->cssId, $this->strictAccessibility, + $this->logLevel ]); return self::load(); diff --git a/src/Model/UserModel/UserModel.php b/src/Model/UserModel/UserModel.php index 6a30671..7556016 100644 --- a/src/Model/UserModel/UserModel.php +++ b/src/Model/UserModel/UserModel.php @@ -42,11 +42,20 @@ class UserModel { // Making this a separate function to avoid // loading the password into memory - public function set_password(string $password): void { + public function setPassword(string $password): void { global $db; $hash = password_hash($password, PASSWORD_DEFAULT); $stmt = $db->prepare("UPDATE user SET password_hash=? WHERE id=1"); $stmt->execute([$hash]); } + + public function getByUsername($username){ + global $db; + $stmt = $db->prepare("SELECT id, username, password_hash FROM user WHERE username = ?"); + $stmt->execute([$username]); + $record = $stmt->fetch(); + + return $record; + } } diff --git a/templates/partials/admin.php b/templates/partials/admin.php index 64d5962..2bdf051 100644 --- a/templates/partials/admin.php +++ b/templates/partials/admin.php @@ -67,6 +67,13 @@ name="strict_accessibility" value="1" strictAccessibility): ?> checked > + +