From bfca7be0008a58a0333b0c195d189431af58fed7 Mon Sep 17 00:00:00 2001
From: Guillermo Dev <public.guillermo@gmail.com>
Date: Fri, 12 Oct 2018 00:33:02 +0200
Subject: [PATCH] refactored logger

---
 src/Utils/Logger/Logger.php       | 226 ++++++++++++++++++++++--------
 tests/Utils/Logger/LoggerTest.php | 166 ++++++++++++++++++++++
 2 files changed, 334 insertions(+), 58 deletions(-)
 create mode 100644 tests/Utils/Logger/LoggerTest.php

diff --git a/src/Utils/Logger/Logger.php b/src/Utils/Logger/Logger.php
index f12116a..f52cf0c 100644
--- a/src/Utils/Logger/Logger.php
+++ b/src/Utils/Logger/Logger.php
@@ -1,7 +1,10 @@
 <?php
 namespace BSR\Utils\Logger;
 
+use BSR\Utils\Configuration\Configuration;
+
 class Logger {
+
     const QUIET = 0;
     const NORMAL = 1;
     const VERBOSE = 2;
@@ -10,19 +13,38 @@ class Logger {
     private static $data = array();
     private static $log = '';
 
-    private static function ip() {
+    /**
+     * Get the ip address from server variables if applicable
+     * @return string
+     */
+    private static function ip()
+    {
+        $ip = '(n-a)';
+
         if (isset($_SERVER['HTTP_X_FORWARDED_FOR'])) {
-            return array_shift(
+            $ip = array_shift(
                 array_map('trim', explode(',', $_SERVER['HTTP_X_FORWARDED_FOR']))
             );
         } else if (isset($_SERVER['REMOTE_ADDR'])) {
-            return $_SERVER['REMOTE_ADDR'];
+            $ip = $_SERVER['REMOTE_ADDR'];
         }
 
-        return '(n-a)';
+        return $ip;
     }
 
-    public static function start($data = array()) {
+    /**
+     * Initialize the start property with microtime in float format
+     * Initialize self::$data array with a union from argument $data 
+     * and some initial values array : ip, date and some default (none)
+     * 
+     * If $data param contains some of the keys in the right hand array:
+     * 'ip', 'date', ..., 'error', then the $data will prevail
+     * 
+     * @param array $data
+     * @return void
+     */
+    public static function start($data = array())
+    {
         self::$start = microtime(true);
 
         self::$data = $data + array(
@@ -34,7 +56,20 @@ class Logger {
         );
     }
 
-    public static function info($info, $key = null) {
+    /**
+     * If $key is passed, creates/overwrites existing self::$data[$key] with $info
+     * Otherwise, uses array_merge: 
+     *  if $info has same string keys as self::$data, $info overwrites
+     *  if $info has same integer keys as self::$data, $info keys are renumbered 
+     *  and appended to self::$data
+     *
+     * @param any $info
+     * @param string $key optional, store the whole info under a $key in self::$data
+     * @return void
+     * @see self::start($data)
+     */
+    public static function info($info, $key = null)
+    {
         if(is_null($key)) {
             self::$data = array_merge(self::$data, $info);
         } else {
@@ -49,7 +84,8 @@ class Logger {
      * @param string $message
      * @param int $verbosity
      */
-    public static function log($message, $verbosity = Logger::VERBOSE) {
+    public static function log($message, $verbosity = Logger::VERBOSE)
+    {
         if(Configuration::get('log.verbosity') < $verbosity) {
             return;
         }
@@ -57,69 +93,143 @@ class Logger {
         self::$log .= $message."\n";
     }
 
-    public static function stop($data = null) {
-        if(! is_null($data)) {
+    /**
+     * Allow stopping by overriding some self::$data values with $data param
+     *  - store the time lapse between start() and stop() calls in self::$data 
+     *
+     * @param $data allow storing some info on stop
+     */
+    public static function stop($data = null)
+    {
+        if (!is_null($data)) {
             self::info($data);
         }
 
         $time = (microtime(true) - self::$start) * 1000;
         self::$data['time'] = round($time, 2).'ms';
 
-        if(Configuration::get('log.verbosity') > Logger::QUIET) {
-            $format = Configuration::get('log.format');
-
-            $patterns = array_map(function($p) { return "%$p%"; }, array_keys(self::$data));
-            $msg = str_replace($patterns, array_values(self::$data), $format)."\n";
-
-            if(strlen(self::$log) > 0) {
-                $msg .= self::$log;
-            }
-
-            $file = Configuration::get('log.file');
-            if(! file_exists($file)) {
-                mkdir(dirname($file), 0777, true);
-                touch($file);
-            } else {
-                $mtime = filemtime($file);
-                // start of the current day
-                $start = strtotime("midnight");
-
-                // log rotate if the last entry in the log is from yesterday
-                if($mtime < $start) {
-                    $files = glob($file.'.?');
-                    natsort($files);
-                    $files = array_reverse($files);
-                    $files[] = $file;
-
-                    // we count before adding the next file
-                    $len = count($files);
-
-                    $next = intval(substr($files[0], -1)) + 1;
-                    $next = $next == 1 ? "$file.1" : substr($files[0], 0, -1).$next;
-
-                    array_unshift($files, $next);
-                    for($i = 0; $i < $len; ++$i) {
-                        // move all the log files to the next name
-                        rename($files[$i + 1], $files[$i]);
-                    }
-
-                    // delete all files with a number bigger than 9
-                    $files = glob($file.'.??');
-                    array_map('unlink', $files);
-
-                    // recreate the new log file
-                    touch($file);
-                }
-            }
-            file_put_contents($file, $msg, FILE_APPEND | LOCK_EX);
+        if (Configuration::get('log.verbosity') > Logger::QUIET) {
+            self::saveLogMessageToFile(self::generateLogMessage());
+        }
+    }
+
+    /**
+     * @return string
+     */
+    private static function generateLogMessage()
+    {
+        $format = Configuration::get('log.format');
+
+        $patterns = array_map(function($p) { return "%$p%"; }, array_keys(self::$data));
+        $msg = str_replace($patterns, array_values(self::$data), $format)."\n";
+        return $msg . (strlen(self::$log) > 0 ? self::$log : '');
+    }
+
+    /**
+     *
+     * @param string $msg
+     */
+    private static function saveLogMessageToFile($msg)
+    {
+        $mostRecentLogFileName = Configuration::get('log.file');
+
+        if(self::isMostRecentLogFileFromYesterday()) {
+            self::makeRoomForNewLogFile($mostRecentLogFileName);
+        } else {
+            mkdir(dirname($mostRecentLogFileName), 0777, true);
+        }
+
+        touch($mostRecentLogFileName);
+        file_put_contents($mostRecentLogFileName, $msg, FILE_APPEND | LOCK_EX);
+    }
+
+    /**
+     * @return bool
+     */
+    private static function isMostRecentLogFileFromYesterday()
+    {
+        $mostRecentLogFileName = Configuration::get('log.file');
+        if (!file_exists($mostRecentLogFileName)) {
+            return false;
+        }
+        return filemtime($mostRecentLogFileName) < strtotime("midnight");
+    }
+
+    /**
+     * Use config log filename as pattern. We want to save the latest log
+     * in a file named after config. But if there is another file with
+     * same name (for example the one for yesterday's log), then we want
+     * to append a number to the end of the file, which basically is the
+     * number of days the log dates from today.
+     * We only keep 10 day logs from (0) to 9.
+     *
+     * glob: think of the * as the pcre equivalent of .* and ? as the pcre equivalent of the dot (.)
+     */
+    private static function makeRoomForNewLogFile()
+    {
+        $files = self::getExistingNumberedLogFilesArrayDesc();
+        $files[] = Configuration::get('log.file');
+        self::renameExsitingLogFilesToHigherCounts($files);
+        self::deleteTenDaysOlderLogFiles();
+    }
+
+    /**
+     * @param array $files
+     */
+    private static function renameExsitingLogFilesToHigherCounts($files)
+    {
+        $oldLogFilesCount = count($files);
+        $newOldestLogFileName = self::getOldestLogFileNameIncrementedByOne($files[0]);
+        array_unshift($files, $newOldestLogFileName);
+        for($i = 0; $i < $oldLogFilesCount; ++$i) {
+            rename($files[$i + 1], $files[$i]);
         }
     }
 
-    public static function data() {
+    /**
+     * Delete all files with a number bigger than 9
+     */
+    private static function deleteTenDaysOlderLogFiles()
+    {
+        $mostRecentLogFileName = Configuration::get('log.file');
+        $files = glob($mostRecentLogFileName.'.??');
+        array_map('unlink', $files);
+    }
+
+    /**
+     * Get the list of files matching Configuration::get('log.file')
+     * with some number appended to the file name. Order them by that
+     * number in desc order.
+     *
+     * @return array
+     */
+    public static function getExistingNumberedLogFilesArrayDesc()
+    {
+        $logFileBaseName = Configuration::get('log.file');
+        $files = glob("$logFileBaseName.?");
+        natsort($files);
+        $files = array_reverse($files);
+        return $files;
+    }
+
+    /**
+     *
+     * @param string $highestFileName
+     */
+    private static function getOldestLogFileNameIncrementedByOne($highestFileName)
+    {
+        $logFileBaseName = Configuration::get('log.file');
+        $next = intval(substr($highestFileName, -1)) + 1;
+        return "$logFileBaseName.$next";
+    }
+
+    public static function data()
+    {
         return self::$data;
     }
 
-    public static function getLastLogs($offset = null) {
+    public static function getLastLogs($offset = null)
+    {
         $file = Configuration::get('log.file');
         if(! file_exists($file)) {
             return 'No log yet !';
diff --git a/tests/Utils/Logger/LoggerTest.php b/tests/Utils/Logger/LoggerTest.php
new file mode 100644
index 0000000..4f3275d
--- /dev/null
+++ b/tests/Utils/Logger/LoggerTest.php
@@ -0,0 +1,166 @@
+<?php
+namespace BSR\Utils\Logger;
+
+use PHPUnit\Framework\TestCase;
+
+class LoggerTest extends TestCase{
+    const QUIET = 0;
+    const NORMAL = 1;
+    const VERBOSE = 2;
+
+    private static $start;
+    private static $data = array();
+    private static $log = '';
+
+    /**
+     * Get the ip address from server variables if applicable
+     * @return string
+     */
+    private static function ip()
+    {
+        $ip = '(n-a)';
+
+        if (isset($_SERVER['HTTP_X_FORWARDED_FOR'])) {
+            $ip = array_shift(
+                array_map('trim', explode(',', $_SERVER['HTTP_X_FORWARDED_FOR']))
+            );
+        } else if (isset($_SERVER['REMOTE_ADDR'])) {
+            $ip = $_SERVER['REMOTE_ADDR'];
+        }
+
+        return $ip;
+    }
+
+    public static function start($data = array())
+    {
+        self::$start = microtime(true);
+
+        self::$data = $data + array(
+            'ip' => self::ip(),
+            'date' => date('d.m.Y H:i:s'),
+            'func' => '(none)',
+            'version' => '(none)',
+            'error' => ''
+        );
+    }
+
+    public static function info($info, $key = null)
+    {
+        if(is_null($key)) {
+            self::$data = array_merge(self::$data, $info);
+        } else {
+            self::$data[$key] = $info;
+        }
+    }
+
+    /**
+     * Log a message that will be displayed in the logs if the configuration
+     * says so.
+     *
+     * @param string $message
+     * @param int $verbosity
+     */
+    public static function log($message, $verbosity = Logger::VERBOSE) {
+        if(Configuration::get('log.verbosity') < $verbosity) {
+            return;
+        }
+
+        self::$log .= $message."\n";
+    }
+
+    public static function stop($data = null) {
+        if(! is_null($data)) {
+            self::info($data);
+        }
+
+        $time = (microtime(true) - self::$start) * 1000;
+        self::$data['time'] = round($time, 2).'ms';
+
+        if(Configuration::get('log.verbosity') > Logger::QUIET) {
+            $format = Configuration::get('log.format');
+
+            $patterns = array_map(function($p) { return "%$p%"; }, array_keys(self::$data));
+            $msg = str_replace($patterns, array_values(self::$data), $format)."\n";
+
+            if(strlen(self::$log) > 0) {
+                $msg .= self::$log;
+            }
+
+            $file = Configuration::get('log.file');
+            if(! file_exists($file)) {
+                mkdir(dirname($file), 0777, true);
+                touch($file);
+            } else {
+                $mtime = filemtime($file);
+                // start of the current day
+                $start = strtotime("midnight");
+
+                // log rotate if the last entry in the log is from yesterday
+                if($mtime < $start) {
+                    $files = glob($file.'.?');
+                    natsort($files);
+                    $files = array_reverse($files);
+                    $files[] = $file;
+
+                    // we count before adding the next file
+                    $len = count($files);
+
+                    $next = intval(substr($files[0], -1)) + 1;
+                    $next = $next == 1 ? "$file.1" : substr($files[0], 0, -1).$next;
+
+                    array_unshift($files, $next);
+                    for($i = 0; $i < $len; ++$i) {
+                        // move all the log files to the next name
+                        rename($files[$i + 1], $files[$i]);
+                    }
+
+                    // delete all files with a number bigger than 9
+                    $files = glob($file.'.??');
+                    array_map('unlink', $files);
+
+                    // recreate the new log file
+                    touch($file);
+                }
+            }
+            file_put_contents($file, $msg, FILE_APPEND | LOCK_EX);
+        }
+    }
+
+    public static function data() {
+        return self::$data;
+    }
+
+    public static function getLastLogs($offset = null) {
+        $file = Configuration::get('log.file');
+        if(! file_exists($file)) {
+            return 'No log yet !';
+        }
+
+        $f = fopen($file, 'r');
+
+        $len = 8192;
+
+        fseek($f, 0, SEEK_END);
+        $size = ftell($f);
+        if(is_null($offset) || $offset > $size) {
+            $offset = $size - $len;
+        }
+        $offset = max(0, $offset);
+
+        fseek($f, $offset);
+
+        // remove the first line that may be incomplete
+        $buffer = fread($f, $len);
+        $buffer = explode("\n", $buffer);
+        array_shift($buffer);
+        $buffer = implode("\n", $buffer);
+        // continue reading until the end of the file
+        while(! feof($f)) {
+            $buffer .= fread($f, $len);
+        }
+
+        fclose($f);
+
+        return $buffer;
+    }
+}