Updates to Logging

- Logging Level DEBUG introduced
- Logging Level FINE deprecated to INFO
- Logging Level restricted to INFO in live environments
- Warning on using DEBUG in live environments
- Fixes #215. Not Entirely, but one step ahead

lib/PayPal/Core/PayPalHttpConnection.php

@@ -36,7 +36,7 @@ class PayPalHttpConnection
      * Default Constructor
      *
      * @param PayPalHttpConfig $httpConfig
-     * @param array $config
+     * @param array            $config
      * @throws PayPalConfigurationException
      */
     public function __construct(PayPalHttpConfig $httpConfig, array $config)
@@ -85,8 +85,10 @@ class PayPalHttpConnection
         $ch = curl_init($this->httpConfig->getUrl());
         curl_setopt_array($ch, $this->httpConfig->getCurlOptions());
         curl_setopt($ch, CURLOPT_URL, $this->httpConfig->getUrl());
-        curl_setopt($ch, CURLOPT_HEADER, false);
+        curl_setopt($ch, CURLOPT_HEADER, true);
+        curl_setopt($ch, CURLINFO_HEADER_OUT, true);
         curl_setopt($ch, CURLOPT_HTTPHEADER, $this->getHttpHeaders());
+
         //Determine Curl Options based on Method
         switch ($this->httpConfig->getMethod()) {
             case 'POST':
@@ -96,6 +98,7 @@ class PayPalHttpConnection
                 curl_setopt($ch, CURLOPT_POSTFIELDS, $data);
                 break;
         }
+
         //Default Option if Method not of given types in switch case
         if ($this->httpConfig->getMethod() != NULL) {
             curl_setopt($ch, CURLOPT_CUSTOMREQUEST, $this->httpConfig->getMethod());
@@ -104,30 +107,30 @@ class PayPalHttpConnection
         //Logging Each Headers for debugging purposes
         foreach ($this->getHttpHeaders() as $header) {
             //TODO: Strip out credentials and other secure info when logging.
-            $this->logger->fine($header);
+            // $this->logger->debug($header);
         }
 
-        $this->logger->fine(($data && $data != '' ? "Payload : " . $data : "No Request Payload") . "\n");
         //Execute Curl Request
         $result = curl_exec($ch);
-
+        //Retrieve Response Status
+        $httpStatus = curl_getinfo($ch, CURLINFO_HTTP_CODE);
 
         //Retry if Certificate Exception
         if (curl_errno($ch) == 60) {
             $this->logger->info("Invalid or no certificate authority found - Retrying using bundled CA certs file");
             curl_setopt($ch, CURLOPT_CAINFO, dirname(__FILE__) . '/cacert.pem');
             $result = curl_exec($ch);
+            //Retrieve Response Status
+            $httpStatus = curl_getinfo($ch, CURLINFO_HTTP_CODE);
         }
 
-        //Retrieve Response Status
-        $httpStatus = curl_getinfo($ch, CURLINFO_HTTP_CODE);
-
         //Retry if Failing
         $retries = 0;
         if (in_array($httpStatus, self::$retryCodes) && $this->httpConfig->getHttpRetryCount() != null) {
             $this->logger->info("Got $httpStatus response from server. Retrying");
             do {
                 $result = curl_exec($ch);
+                //Retrieve Response Status
                 $httpStatus = curl_getinfo($ch, CURLINFO_HTTP_CODE);
             } while (in_array($httpStatus, self::$retryCodes) && (++$retries < $this->httpConfig->getHttpRetryCount()));
         }
@@ -142,10 +145,21 @@ class PayPalHttpConnection
             curl_close($ch);
             throw $ex;
         }
+
+        // Get Request and Response Headers
+        $requestHeaders = curl_getinfo($ch, CURLINFO_HEADER_OUT);
+        $responseHeaderSize = curl_getinfo($ch, CURLINFO_HEADER_SIZE);
+        $responseHeaders = substr($result, 0, $responseHeaderSize);
+        $result = substr($result, $responseHeaderSize);
+
+        $this->logger->debug("Request Headers \t: " . str_replace("\r\n", ", ", $requestHeaders));
+        $this->logger->debug(($data && $data != '' ? "Request Data\t\t: " . $data : "No Request Payload") . "\n" . str_repeat('-', 128) . "\n");
+        $this->logger->info("Response Status \t: " . $httpStatus);
+        $this->logger->debug("Response Headers\t: " . str_replace("\r\n", ", ", $responseHeaders));
+
         //Close the curl request
         curl_close($ch);
 
-        $this->logger->fine(($result && $result != '' ? "Response : " . $result : "No Response Body") . "\n\n");
         //More Exceptions based on HttpStatus Code
         if (in_array($httpStatus, self::$retryCodes)) {
             $ex = new PayPalConnectionException(
@@ -154,6 +168,9 @@ class PayPalHttpConnection
                 "Retried $retries times."
             );
             $ex->setData($result);
+            $this->logger->error("Got Http response code $httpStatus when accessing {$this->httpConfig->getUrl()}. " .
+                "Retried $retries times." . $result);
+            $this->logger->debug("\n\n" . str_repeat('=', 128) . "\n");
             throw $ex;
         } else if ($httpStatus < 200 || $httpStatus >= 300) {
             $ex = new PayPalConnectionException(
@@ -162,9 +179,12 @@ class PayPalHttpConnection
                 $httpStatus
             );
             $ex->setData($result);
+            $this->logger->error("Got Http response code $httpStatus when accessing {$this->httpConfig->getUrl()}. " . $result );
+            $this->logger->debug("\n\n" . str_repeat('=', 128) . "\n");
             throw $ex;
         }
 
+        $this->logger->debug(($result && $result != '' ? "Response Data \t: " . $result : "No Response Body") . "\n\n" . str_repeat('=', 128) . "\n");
 
         //Return result object
         return $result;

lib/PayPal/Core/PayPalLoggingLevel.php

@@ -9,6 +9,9 @@ namespace PayPal\Core;
 class PayPalLoggingLevel
 {
 
+    // DEBUG Logging Level
+    const DEBUG = 4;
+
     // FINE Logging Level
     const FINE = 3;
 

lib/PayPal/Core/PayPalLoggingManager.php

@@ -97,8 +97,24 @@ class PayPalLoggingManager
      */
     private function log($message, $level = PayPalLoggingLevel::INFO)
     {
-        if ($this->isLoggingEnabled && ($level <= $this->loggingLevel)) {
+        if ($this->isLoggingEnabled) {
-            error_log("[" .  date('d-m-Y h:i:s') . "] " . $this->loggerName . ": $message\n", 3, $this->loggerFile);
+            $config = PayPalConfigManager::getInstance()->getConfigHashmap();
+            // Check if logging in live
+            if ($config['mode'] == 'live') {
+                // Live should not have logging level above INFO.
+                if ($this->loggingLevel >= PayPalLoggingLevel::INFO) {
+                    // If it is at Debug Level, throw an warning in the log.
+                    if ($this->loggingLevel == PayPalLoggingLevel::DEBUG) {
+                        error_log("[" . date('d-m-Y h:i:s') . "] " . $this->loggerName . ": ERROR\t: Not allowed to keep 'Debug' level for Live Environments. Reduced to 'INFO'\n", 3, $this->loggerFile);
+                    }
+                    // Reducing it to info level
+                    $this->loggingLevel = PayPalLoggingLevel::INFO;
+                }
+            }
+
+            if ($level <= $this->loggingLevel) {
+                error_log("[" . date('d-m-Y h:i:s') . "] " . $this->loggerName . ": $message\n", 3, $this->loggerFile);
+            }
         }
     }
 
@@ -109,7 +125,7 @@ class PayPalLoggingManager
      */
     public function error($message)
     {
-        $this->log('ERROR: ' . $message, PayPalLoggingLevel::ERROR);
+        $this->log("ERROR\t: " . $message, PayPalLoggingLevel::ERROR);
     }
 
     /**
@@ -119,7 +135,7 @@ class PayPalLoggingManager
      */
     public function warning($message)
     {
-        $this->log('WARNING: ' . $message, PayPalLoggingLevel::WARN);
+        $this->log("WARNING\t: " . $message, PayPalLoggingLevel::WARN);
     }
 
     /**
@@ -129,7 +145,7 @@ class PayPalLoggingManager
      */
     public function info($message)
     {
-        $this->log('INFO: ' . $message, PayPalLoggingLevel::INFO);
+        $this->log("INFO\t: " . $message, PayPalLoggingLevel::INFO);
     }
 
     /**
@@ -139,7 +155,17 @@ class PayPalLoggingManager
      */
     public function fine($message)
     {
-        $this->log('FINE: ' . $message, PayPalLoggingLevel::FINE);
+        $this->log("FINE\t: " . $message, PayPalLoggingLevel::FINE);
+    }
+
+    /**
+     * Log Fine
+     *
+     * @param string $message
+     */
+    public function debug($message)
+    {
+        $this->log("DEBUG\t: " . $message, PayPalLoggingLevel::DEBUG);
     }
 
 }

sample/bootstrap.php

@@ -74,7 +74,7 @@ function getApiContext($clientId, $clientSecret)
             'mode' => 'sandbox',
             'log.LogEnabled' => true,
             'log.FileName' => '../PayPal.log',
-            'log.LogLevel' => 'FINE',
+            'log.LogLevel' => 'DEBUG', // PLEASE USE `FINE` LEVEL FOR LOGGING IN LIVE ENVIRONMENTS
             'validation.level' => 'log',
             'cache.enabled' => true,
             // 'http.CURLOPT_CONNECTTIMEOUT' => 30

sample/sdk_config.ini

@@ -33,10 +33,15 @@ log.LogEnabled=true
 ; path here
 log.FileName=../PayPal.log
 
-; Logging level can be one of FINE, INFO, WARN or ERROR
+; Logging level can be one of
-; Logging is most verbose in the 'FINE' level and
+; Sandbox Environments: DEBUG, INFO, WARN, ERROR
+; Live Environments: INFO, WARN, ERROR
+; Logging is most verbose in the 'DEBUG' level and
 ; decreases as you proceed towards ERROR
-log.LogLevel=FINE
+; DEBUG level is disabled for live, to not log sensitive information.
+; If the level is set to DEBUG, it will be reduced to FINE automatically,
+; with a warning message
+log.LogLevel=INFO
 
 ;Validation Configuration
 [validation]