class.log.php

Go to the documentation of this file.

<?php
/*
 *
 *  * Copyright (c) 2022-2025 Bearsampp
 *  * License: GNU General Public License version 3 or later; see LICENSE.txt
 *  * Website: https://bearsampp.com
 *  * Github: https://github.com/Bearsampp
 *
 */

class Log
{
    const ERROR = 'ERROR';
    const WARNING = 'WARNING';
    const INFO = 'INFO';
    const DEBUG = 'DEBUG';
    const TRACE = 'TRACE';

    const MAX_QUEUE_CONTENT_LENGTH = 1048576; // 1 MB

    const MAX_QUEUE_BATCH = 200;

    const MAX_QUEUE_TARGETS = 50;

    private static $logBuffer = [];

    private static $logBufferSize = 50;

    private static $shutdownRegistered = false;

    private static $logStats = [
        'buffered' => 0,
        'flushed'  => 0,
        'writes'   => 0,
        'async'    => 0,
    ];

    private static $silentMode = false;

    private static $asyncQueueDir = null;

    private static $asyncEnabled = true;

    private static $maxAsyncQueueBatch = 5;

    public static function init()
    {
        if (!self::$shutdownRegistered) {
            register_shutdown_function([__CLASS__, 'flush']);
            register_shutdown_function([__CLASS__, 'flushAsyncQueue']);
            self::$shutdownRegistered = true;
 
            // Initialize async queue directory
            self::initializeAsyncQueue();
 
            // Auto-disable async when TRACE logging is enabled (for live log monitoring)
            self::checkVerbosityAndAdjustAsync();
        }
    }

    private static function checkVerbosityAndAdjustAsync()
    {
        global $bearsamppConfig;
 
        try {
            if (!isset($bearsamppConfig)) {
                return;
            }
 
            $verbosity = $bearsamppConfig->getLogsVerbose();
 
            // Disable async and reduce buffer size for DEBUG/TRACE logging
            // This ensures live log monitoring shows logs immediately
            if ($verbosity === Config::VERBOSE_TRACE) {
                self::$asyncEnabled = false;
                // Use smaller buffer for TRACE to flush more frequently (every 10 entries)
                self::$logBufferSize = 10;
            } elseif ($verbosity === Config::VERBOSE_DEBUG) {
                self::$asyncEnabled = false;
                // For DEBUG level, use moderate buffer size (25 entries)
                self::$logBufferSize = 25;
            }
            // For INFO and REPORT levels, use default buffer size (50) with async enabled
        } catch (Exception $e) {
            // Silently fail - this is just an optimization
        }
    }

    private static function initializeAsyncQueue()
    {
        try {
            // Set up queue directory in tmp
            self::$asyncQueueDir = Path::getTmpPath() . '/log-queue';
 
            // Create queue directory if it doesn't exist
            if (!is_dir(self::$asyncQueueDir)) {
                @mkdir(self::$asyncQueueDir, 0755, true);
            }
        } catch (Exception $e) {
            self::$asyncEnabled = false;
        }
    }

    private static function write($data, $type, $file = null)
    {
        global $bearsamppRoot, $bearsamppCore, $bearsamppConfig;
 
        // Safety check: if globals aren't initialised, fall back to error_log
        if (!isset($bearsamppRoot) || !isset($bearsamppCore) || !isset($bearsamppConfig)) {
            error_log('[' . $type . '] ' . $data);
 
            return;
        }
 
        // Lazily register the shutdown handler if init() was not called explicitly
        self::init();
 
        // Resolve default file path only when the caller did not supply one
        if ($file === null) {
            $file = $type === self::ERROR
                ? Path::getErrorLogFilePath()
                : Path::getLogFilePath();
 
            if (!$bearsamppRoot->isRoot()) {
                $file = Path::getHomepageLogFilePath();
            }
        }
 
        $verbose                         = [];
        $verbose[Config::VERBOSE_SIMPLE] = $type === self::ERROR || $type === self::WARNING;
        $verbose[Config::VERBOSE_REPORT] = $verbose[Config::VERBOSE_SIMPLE] || $type === self::INFO;
        $verbose[Config::VERBOSE_DEBUG]  = $verbose[Config::VERBOSE_REPORT] || $type === self::DEBUG;
        $verbose[Config::VERBOSE_TRACE]  = $verbose[Config::VERBOSE_DEBUG] || $type === self::TRACE;
 
        $writeLog = false;
        if ($bearsamppConfig->getLogsVerbose() === Config::VERBOSE_SIMPLE && $verbose[Config::VERBOSE_SIMPLE]) {
            $writeLog = true;
        } elseif ($bearsamppConfig->getLogsVerbose() === Config::VERBOSE_REPORT && $verbose[Config::VERBOSE_REPORT]) {
            $writeLog = true;
        } elseif ($bearsamppConfig->getLogsVerbose() === Config::VERBOSE_DEBUG && $verbose[Config::VERBOSE_DEBUG]) {
            $writeLog = true;
        } elseif ($bearsamppConfig->getLogsVerbose() === Config::VERBOSE_TRACE && $verbose[Config::VERBOSE_TRACE]) {
            $writeLog = true;
        }
 
        if ($writeLog) {
            // Sanitize line breaks to prevent log forging (injecting fake log lines).
            self::$logBuffer[] = [
                'file' => $file,
                'data' => str_replace(["\r", "\n"], ' ', (string)$data),
                'type' => $type,
                'time' => time(),
            ];
            self::$logStats['buffered']++;
 
            // In silent mode, suppress auto-flush so the caller can decide
            // whether to commit (flush) or rollback (discard) the buffer.
            // ERROR entries always flush — they must never be silently dropped.
            if (self::$silentMode && $type !== self::ERROR) {
                return;
            }
 
            // Flush immediately for:
            // 1. Errors (always)
            // 2. TRACE/DEBUG level logs (for real-time visibility during debugging)
            // 3. When buffer reaches the configured size limit
            $debugVerbosity = $bearsamppConfig->getLogsVerbose();
            $isDebugMode    = ($debugVerbosity === Config::VERBOSE_TRACE || $debugVerbosity === Config::VERBOSE_DEBUG);
            $shouldFlush    = $type === self::ERROR ||
                $isDebugMode ||
                count(self::$logBuffer) >= self::$logBufferSize;
 
            if ($shouldFlush) {
                self::flush();
            }
        }
    }

    public static function flush()
    {
        if (empty(self::$logBuffer)) {
            return;
        }
 
        global $bearsamppCore, $bearsamppConfig;
 
        // If the core global is gone (e.g. during an abnormal shutdown), fall back to error_log
        if (!isset($bearsamppCore)) {
            foreach (self::$logBuffer as $log) {
                error_log('[' . date('Y-m-d H:i:s', $log['time']) . '] [' . $log['type'] . '] ' . $log['data']);
            }
            self::$logStats['flushed'] += count(self::$logBuffer);
            self::$logBuffer           = [];
 
            return;
        }
 
        // Check if DEBUG or TRACE logging is active and force sync writes
        $forceSync = false;
        try {
            if (isset($bearsamppConfig)) {
                $verbosity = $bearsamppConfig->getLogsVerbose();
                if ($verbosity === Config::VERBOSE_TRACE || $verbosity === Config::VERBOSE_DEBUG) {
                    $forceSync = true;
                }
            }
        } catch (Exception $e) {
            // Ignore errors checking config
        }
 
        // Group logs by destination file
        $logsByFile = [];
        foreach (self::$logBuffer as $log) {
            $logsByFile[$log['file']][] = $log;
        }
 
        foreach ($logsByFile as $file => $logs) {
            $content = '';
            foreach ($logs as $log) {
                $content .= '[' . date('Y-m-d H:i:s', $log['time']) . '] # ' .
                    APP_TITLE . ' ' . $bearsamppCore->getAppVersion() . ' # ' .
                    $log['type'] . ': ' . $log['data'] . PHP_EOL;
            }
 
            // Use sync writes if TRACE is enabled or async is disabled
            if (!$forceSync && self::$asyncEnabled) {
                // Queue for async processing (non-blocking)
                $queued = self::queueAsyncWrite($file, $content);
 
                if ($queued) {
                    // Successfully queued, content will be written in background
                    self::$logStats['async']++;
                    self::$logStats['writes']++;
                    continue;
                }
                // If async queueing failed, fall through to sync write
            }
 
            // Synchronous write (immediate for TRACE, fallback for others)
            $written = @file_put_contents($file, $content, FILE_APPEND | LOCK_EX);
            if ($written === false) {
                // File write failed — ensure entries are not silently lost
                foreach ($logs as $log) {
                    error_log('[' . $log['type'] . '] ' . $log['data'] . ' (target: ' . $file . ')');
                }
            }
 
            self::$logStats['writes']++;
        }
 
        self::$logStats['flushed'] += count(self::$logBuffer);
        self::$logBuffer           = [];
    }

    private static function queueAsyncWrite($file, $content)
    {
        if (!self::$asyncEnabled || !is_dir(self::$asyncQueueDir)) {
            return false;
        }
 
        // Defense-in-depth: reject oversized content at the source.
        if (strlen((string)$content) > self::MAX_QUEUE_CONTENT_LENGTH) {
            return false;
        }
 
        try {
            // Create a unique queue file for this write
            $queueFile = self::$asyncQueueDir . '/' . uniqid('log_', true) . '.queue';
 
            // Queue entry contains the target file and content
            $queueEntry = [
                'file'      => $file,
                'content'   => $content,
                'timestamp' => time(),
            ];
 
            // Write queue entry (this is a small, fast operation)
            $serialized = serialize($queueEntry);
            $written    = @file_put_contents($queueFile, $serialized, LOCK_EX);
 
            return ($written !== false);
        } catch (Exception $e) {
            // Silently fail - this is async so we don't want to interrupt main process
            return false;
        }
    }

    private static function sanitizeQueueTarget($file)
    {
        $file = (string)$file;
        if ($file === '') {
            return null;
        }
 
        $normalized = str_replace('\\', '/', $file);
        if (strpos($normalized, '..') !== false) {
            return null;
        }
 
        $logsPath           = Path::getLogsPath();
        $logsPathNormalized = str_replace('\\', '/', rtrim($logsPath, '/\\')) . '/';
 
        // Only allow appends into the application logs directory.
        if (strpos($normalized, $logsPathNormalized) !== 0) {
            return null;
        }
 
        return $file;
    }

    public static function flushAsyncQueue()
    {
        $totalProcessed = 0;
 
        // processAsyncQueue() processes one bounded batch; loop until nothing is left so the
        // manual flush and the shutdown path drain the queue completely.
        $iterationCap = 1000;
        for ($i = 0; $i < $iterationCap; $i++) {
            $processed = self::processAsyncQueue();
            if ($processed <= 0) {
                break;
            }
            $totalProcessed += $processed;
        }
 
        return $totalProcessed;
    }

    public static function processAsyncQueue()
    {
        if (!is_dir(self::$asyncQueueDir)) {
            return 0;
        }
 
        $processed = 0;
 
        try {
            $queueFiles = glob(self::$asyncQueueDir . '/*.queue');
            if (!is_array($queueFiles) || empty($queueFiles)) {
                return 0;
            }
 
            // Bound the work performed in one pass: read at most MAX_QUEUE_BATCH files so
            // a flood of queue entries cannot exhaust memory. Anything beyond the batch,
            // or deferred by the target cap below, is left on disk for a later pass.
            $batchFiles = array_slice($queueFiles, 0, self::MAX_QUEUE_BATCH);
 
            // Group entries by target file
            $entriesByFile = [];
 
            foreach ($batchFiles as $queueFile) {
                try {
                    // Read and deserialize queue entry
                    $serialized = @file_get_contents($queueFile);
                    if ($serialized === false) {
                        continue;
                    }
 
                    $entry = @unserialize($serialized, ['allowed_classes' => false]);
                    if ($entry === false || !isset($entry['file']) || !isset($entry['content'])) {
                        // Invalid queue entry, remove it
                        @unlink($queueFile);
                        continue;
                    }
 
                    // Validate the destination is inside the logs directory and not a path traversal.
                    // Queue files live in a shared tmp dir, so a local attacker could plant a rogue
                    // entry and redirect appends to arbitrary files if we trusted $entry['file'] blindly.
                    $targetFile = self::sanitizeQueueTarget($entry['file']);
                    if ($targetFile === null) {
                        // Invalid/unsafe target - discard the rogue entry
                        @unlink($queueFile);
                        continue;
                    }
 
                    // Cap the distinct target files processed in this pass. Once reached, stop
                    // accumulating and leave this entry (and those after it) untouched so they
                    // are preserved for a later pass rather than being dropped.
                    if (!isset($entriesByFile[$targetFile]) &&
                        count($entriesByFile) >= self::MAX_QUEUE_TARGETS) {
                        break;
                    }
 
                    // Cap the content size to prevent log bloat / disk exhaustion from rogue entries.
                    $content = (string)$entry['content'];
                    if (strlen($content) > self::MAX_QUEUE_CONTENT_LENGTH) {
                        @unlink($queueFile);
                        continue;
                    }
 
                    if (!isset($entriesByFile[$targetFile])) {
                        $entriesByFile[$targetFile] = [];
                    }
 
                    $entriesByFile[$targetFile][] = $content;
                    $processed++;
 
                    // Remove the processed queue file
                    @unlink($queueFile);
                } catch (Exception $e) {
                    // Skip bad entries
                    @unlink($queueFile);
                }
            }
 
            // Write all accumulated entries to their target files
            foreach ($entriesByFile as $targetFile => $contents) {
                try {
                    $combined = implode('', $contents);
                    @file_put_contents($targetFile, $combined, FILE_APPEND | LOCK_EX);
                } catch (Exception $e) {
                    // Log write failed - use error_log as fallback
                    error_log('Failed to write to ' . $targetFile);
                }
            }
 
            // Clean up any stale queue files
            self::cleanupStaleAsyncQueue(3600);
        } catch (Exception $e) {
            // Silently fail
        }
 
        return $processed;
    }

    private static function cleanupStaleAsyncQueue($maxAge)
    {
        if (!is_dir(self::$asyncQueueDir)) {
            return 0;
        }
 
        $removed = 0;
        $now     = time();
 
        try {
            $queueFiles = @glob(self::$asyncQueueDir . '/*.queue');
 
            if (!is_array($queueFiles)) {
                return 0;
            }
 
            foreach ($queueFiles as $queueFile) {
                try {
                    // Remove files older than maxAge
                    if ($now - @filemtime($queueFile) > $maxAge) {
                        @unlink($queueFile);
                        $removed++;
                    }
                } catch (Exception $e) {
                    // Skip
                }
            }
        } catch (Exception $e) {
            // Ignore cleanup errors
        }
 
        return $removed;
    }

    public static function reset()
    {
        self::$logBuffer          = [];
        self::$shutdownRegistered = false;
        self::$logStats           = [
            'buffered' => 0,
            'flushed'  => 0,
            'writes'   => 0,
            'async'    => 0,
        ];
    }

    public static function setAsyncEnabled($enabled)
    {
        self::$asyncEnabled = (bool)$enabled;
    }

    public static function isAsyncEnabled()
    {
        return self::$asyncEnabled;
    }

    public static function getAsyncQueueDir()
    {
        return self::$asyncQueueDir;
    }

    public static function getAsyncQueueSize()
    {
        if (!is_dir(self::$asyncQueueDir)) {
            return 0;
        }
 
        $files = @glob(self::$asyncQueueDir . '/*.queue');
 
        return is_array($files) ? count($files) : 0;
    }

    public static function getStats()
    {
        return self::$logStats;
    }

    public static function setBufferSize($size)
    {
        if ($size > 0 && $size <= 1000) {
            self::$logBufferSize = $size;
        }
    }

    public static function getBufferSize()
    {
        return self::$logBufferSize;
    }

    public static function separator()
    {
        if (self::$silentMode) {
            return;
        }
 
        global $bearsamppRoot;
 
        $logs = [
            Path::getLogFilePath(),
            Path::getErrorLogFilePath(),
            Path::getServicesLogFilePath(),
            Path::getRegistryLogFilePath(),
            Path::getStartupLogFilePath(),
            Path::getBatchLogFilePath(),
            Path::getWinbinderLogFilePath(),
            Path::getHomepageLogFilePath(),
        ];
 
        $separator = '========================================================================================' . PHP_EOL;
        foreach ($logs as $log) {
            if (!file_exists($log)) {
                continue;
            }
            $logContent = @file_get_contents($log);
            if ($logContent !== false && !str_ends_with($logContent, $separator)) {
                @file_put_contents($log, $separator, FILE_APPEND);
            }
        }
    }

    public static function trace($data, $file = null)
    {
        self::write($data, self::TRACE, $file);
    }

    public static function debug($data, $file = null)
    {
        self::write($data, self::DEBUG, $file);
    }

    public static function info($data, $file = null)
    {
        self::write($data, self::INFO, $file);
    }

    public static function warning($data, $file = null)
    {
        self::write($data, self::WARNING, $file);
    }

    public static function error($data, $file = null)
    {
        self::write($data, self::ERROR, $file);
    }

    private static $initClassCounts = array();

    private static $reloadClassCounts = array();

    public static function initClass($classInstance)
    {
        $className = get_class($classInstance);
 
        if (isset(self::$initClassCounts[$className])) {
            self::$initClassCounts[$className]++;
 
            return;
        }
 
        self::$initClassCounts[$className] = 1;
        self::trace('Init ' . $className);
    }

    public static function reloadClass($classInstance)
    {
        $className = get_class($classInstance);
 
        if (isset(self::$reloadClassCounts[$className])) {
            self::$reloadClassCounts[$className]++;
 
            return;
        }
 
        self::$reloadClassCounts[$className] = 1;
        self::trace('Reload ' . $className);
    }

    public static function startSilentBuffer()
    {
        self::$silentMode = true;
        // Discard anything already buffered from early bootstrap (e.g. separator)
        self::$logBuffer = [];
    }

    public static function commitSilentBuffer()
    {
        self::$silentMode = false;
        self::flush();
    }

    public static function rollbackSilentBuffer()
    {
        self::$silentMode = false;
        self::$logBuffer  = [];
    }

    public static function isSilent()
    {
        return self::$silentMode;
    }
}