Timer Methods

.gitignore

@@ -1,4 +1,6 @@
-src/test.php
-test/
-test/*
-test.php
+.DS_Store
+src/.DS_Store
+example/.DS_Store
+example/*.txt
+src/*.txt
+*.txt

example/example.php

@@ -6,10 +6,15 @@
 $log = KLogger::instance(dirname(__FILE__), KLogger::DEBUG);
 
 $log->logInfo('Info Test');
-$log->logNotice('Notice Test');
-$log->logWarn('Warn Test');
-$log->logError('Error Test');
-$log->logFatal('Fatal Test');
-$log->logAlert('Alert Test');
+$log->logNotice('Notice Testssss');
+$log->logWarn('Warn Testssss');
+$log->logError('Error sss');
+$log->logFatal('Fatal ss');
+$log->logAlert('Alert ssss');
 $log->logCrit('Crit test');
 $log->logEmerg('Emerg Test');
+$log->logInfo("HI!");
+
+$log->logStartTime('Sleeping');
+sleep(1);
+$log->logEndTime('Sleeping'); //notice that the task names match

src/KLogger.php

@@ -10,6 +10,8 @@
  * $log->logInfo('Returned a million search results'); //Prints to the log file
  * $log->logFatal('Oh dear.'); //Prints to the log file
  * $log->logDebug('x = 5'); //Prints nothing due to current severity threshhold
+ * $log->logStartTime('big loop'); // starts timing task
+ * $log->logEndTime('big loop'); // ends timing task and prints out elapsed time
  *
  * @author  Kenny Katzgrau <[email protected]>
  * @since   July 26, 2008
@@ -34,12 +36,13 @@ class KLogger
     const NOTICE = 5;  // Notice: normal but significant condition
     const INFO   = 6;  // Informational: informational messages
     const DEBUG  = 7;  // Debug: debug messages
-
+    const TIMER  = 8;  // Timer: timing of code (only displays when logEndTime is called)
+
     //custom logging level
     /**
      * Log nothing at all
      */
-    const OFF    = 8;
+    const OFF    = 9;
     /**
      * Alias for CRIT
      * @deprecated
@@ -68,6 +71,11 @@ class KLogger
      * @var string
      */
     private $_logFilePath       = null;
+    /**
+    * Assoc array of tasks and their respective start times.
+    * @var array
+    */
+	private $_timingTasks;
     /**
      * Current minimum logging threshold
      * @var integer
@@ -151,8 +159,9 @@ public static function instance($logDirectory = false, $severity = false)
      */
     public function __construct($logDirectory, $severity)
     {
+
         $logDirectory = rtrim($logDirectory, '\\/');
-
+        
         if ($severity === self::OFF) {
             return;
         }
@@ -162,9 +171,9 @@ public function __construct($logDirectory, $severity)
             . 'log_'
             . date('Y-m-d')
             . '.txt';
-
         $this->_severityThreshold = $severity;
         if (!file_exists($logDirectory)) {
+            print "Making directory: <br>";
             mkdir($logDirectory, self::$_defaultPermissions, true);
         }
 
@@ -173,7 +182,7 @@ public function __construct($logDirectory, $severity)
             $this->_messageQueue[] = $this->_messages['writefail'];
             return;
         }
-
+        
         if (($this->_fileHandle = fopen($this->_logFilePath, 'a'))) {
             $this->_logStatus = self::STATUS_LOG_OPEN;
             $this->_messageQueue[] = $this->_messages['opensuccess'];
@@ -240,6 +249,42 @@ public static function setDateFormat($dateFormat)
         self::$_dateFormat = $dateFormat;
     }
 
+    /**
+    * Starts timing your code. if you choose to specify a task it will log something otherwise it simply starts the timer.
+    *
+    * @param string $task the task we are timing
+    * @return void
+    */
+    public function logStartTime($task = "default") {
+		$this->_timingTasks[$task] = microtime(true);
+
+        if ($task != "default") {
+            $this->log(sprintf("Started timing %s", $task), self::TIMER);
+        }
+    }
+
+    /**
+    * Stops timing your code and prints out the specified task.
+    *
+    * @param string $task the task you're finished time
+    * @return void
+    */
+    public function logEndTime($task = "default") {
+		$startTime = $this->_timingTasks[$task];
+		if (isset($startTime)) {
+			$end_time = microtime(true) - $startTime;
+	        //convert to millseconds (most common)
+	        $end_time *= 1000;
+
+			if ($task != "default") {
+	        	$this->log(sprintf("Finished %s in %.3f milliseconds", $task, $end_time), self::TIMER);
+			} else {
+				$this->log(sprintf("Finished in %.3f milliseconds", $end_time), self::TIMER);
+			}
+		}
+
+    }
+
     /**
      * Writes a $line to the log with a severity level of INFO. Any information
      * can be used here, or it could be used with E_STRICT errors
@@ -386,10 +431,12 @@ private function _getTimeLine($level)
                 return "$time - WARN -->";
             case self::DEBUG:
                 return "$time - DEBUG -->";
+            case self::TIMER:
+                return "$time - TIMER --> ";
             case self::ERR:
                 return "$time - ERROR -->";
             default:
                 return "$time - LOG -->";
         }
     }
-}
+}

src/KProfiler.php

@@ -0,0 +1,83 @@
+<?php
+/**
+* KProfiler is a simple application which parses the time logs from KLogger. It then displays them via a web interface. This interface
+* has the option to enable realtime polling so that the stats are updated in realtime. It also can display log messages to the console.
+* KProfiler's goal is to allow you to find the bottleneck in your applications and with little overhead. It also has a simple REST (like) API.
+* Thus, when you call display() it will either display a REST response or output the main console (if no parameters)
+* @todo Introduce some sort of file locking to ensure we don't have race conditions.
+* 
+* Usage:
+* $kprofiler = new KProfiler([log file directory]);
+* $kprofiler->display();
+* @author Sam Stewart <[email protected]>
+* @since September 7, 2010
+* @link samstewartapps.com
+* @version 0.2
+*/
+
+/**
+* Simple class which represents a log entry.
+*/
+class KLogEntry {
+    public $time;
+    public $type;
+    public $message; //or "task" if timer entry
+    //properties specific to timer logs
+    public $elapsed_time;
+
+    public function __construct($time, $type, $message, $elapsed_time) {
+        $this->time = $time;
+        $this->type = $type;
+        $this->message = $message;
+        $this->elapsed_time = $elapsed_time;
+    }
+}
+/**
+* Actual profiler class. Reads the log in and creates stats.
+*/
+class KProfiler 
+{
+    /**
+    * @var string the log directory. We'll use this to display the most current log.
+    */
+    private $_logDir;
+
+    /**
+    * @var array the list of KLogEntrys from the log file.
+    */
+    private $_logEntries;
+
+    public function __construct($log_dir) {
+        $this->_logDir = $log_dir;
+    }
+
+    /** 
+    * Filters and returns only the log entries with the specified type.
+    * @param type the log type we're filtering for
+    * @return array a filtered array containing only log entries that have the type specified.
+    */
+    private function filterEntries($type) {
+
+    }
+
+    /**
+    * Function which opens the specified file and reads in all the page entries.
+    * @param log_file the log file path
+    * @return array The array of KLogEntrys from the file
+    */
+    private function readEntries($log_file) {
+
+    }
+
+    /**
+    * Function which looks at all time entries, combines identical tasks, then sorts them in descending order
+    * so that we can tell which tasks are taking the longest.
+    * @param entries The log entries we're combining. They should all be TIMER entries (prefiltered)
+    * @return array An array of KLogEntry items. However, there are no two entries with the same task (they're all combined). They're
+    * also sorted in descending order (based on milliseconds)
+    */
+    private function totalEntries($entries) {
+
+    }
+}
+?>