PHP 8.2 Migration Prep: Logging Changes to support latest version of Monolog (#2086)

* Logging Updates to prepare for PHP 8.2

These updates are to prepare for the PHP 8.2 updates / Symfony Migration as the
new version of Monolog we're updating to no longer allows us to provide arrays
as messages. Thankfully the new version of Monolog does allow for classes that
implement `\Stringable` to be provided as a message. To take advantage of this I
created a new class called `LogOutput` that implements `\Stringable` and takes /
provides as a public member variable an array. This array is used when
`__toString()` is called and outputs information as we expect when logging to
the console. When logging to the database we instead expect to output
json_encoded data. To accomplish this I've added a new "Processor" ( right now
this is just an anonymous function, in the Symfony Migration they have a class
for these ) to the `CCRDBHandler` that will "enrich" the record being logged by
setting a new property called 'formatted' (for the new version of Monolog)
prior to CCRDBHandler writing the record to the db.

The changes were originally included in the Symfony Migration PR
but they don't actually require Symfony to function and will make the Symfony
PR smaller.

---------

Co-authored-by: Joe White <[email protected]>

Author: ryanrath

background_scripts/batch_export_manager.php

@@ -83,12 +83,12 @@
     $logger = Log::factory('batch-export', $logConf);
     $logger->info('Command: ' . implode(' ', array_map('escapeshellarg', $argv)));
     // NOTE: "process_start_time" is needed for the log summary.
-    $logger->notice(['message' => 'batch_export_manager start', 'process_start_time' => date('Y-m-d H:i:s')]);
+    $logger->notice('batch_export_manager start', ['process_start_time' => date('Y-m-d H:i:s')]);
     $batchProcessor = new BatchProcessor($logger);
     $batchProcessor->setDryRun($dryRun);
     $batchProcessor->processRequests();
     // NOTE: "process_end_time" is needed for the log summary.
-    $logger->notice(['message' => 'batch_export_manager end', 'process_end_time' => date('Y-m-d H:i:s')]);
+    $logger->notice('batch_export_manager end', ['process_end_time' => date('Y-m-d H:i:s')]);
     @flock($lockFileHandle, LOCK_UN);
     @fclose($lockFileHandle);
     @unlink($lockFile);

background_scripts/report_schedule_manager.php

@@ -66,10 +66,7 @@
 // =====================================================================
 
 // NOTE: "process_start_time" is needed for log summary.
-$logger->notice(array(
-    'message'            => 'Report scheduler start',
-    'process_start_time' => date('Y-m-d H:i:s'),
-));
+$logger->notice('Report scheduler start', ['process_start_time' => date('Y-m-d H:i:s')]);
 
 $active_frequencies = getActiveFrequencies(true);
 
@@ -90,10 +87,7 @@
         } catch (Exception $e) {
             $msg = "Failed to get user for id = {$details['user_id']}: "
                 . $e->getMessage();
-            $logger->err(array(
-                'message'    => $msg,
-                'stacktrace' => $e->getTraceAsString(),
-            ));
+            $logger->error($msg, ['stacktrace' => $e->getTraceAsString()]);
             continue;
         }
 
@@ -121,10 +115,7 @@
             } catch(Exception $e) {
                 $msg = "Error Preparing report on " . gethostname() . " {$details['report_id']}: "
                     . $e->getMessage();
-                $logger->err(array(
-                    'message'    => $msg,
-                    'stacktrace' => $e->getTraceAsString(),
-                ));
+                $logger->error($msg, ['stacktrace' => $e->getTraceAsString()]);
             }
 
             if (isset($working_dir) && $working_dir != '/' && $working_dir != getcwd()) {
@@ -135,10 +126,7 @@
 }
 
 // NOTE: "process_end_time" is needed for log summary.
-$logger->notice(array(
-    'message'          => 'Report scheduler end',
-    'process_end_time' => date('Y-m-d H:i:s'),
-));
+$logger->notice('Report scheduler end', ['process_end_time' => date('Y-m-d H:i:s')]);
 
 exit;
 

bin/acl-config

@@ -246,7 +246,7 @@ function main()
 
     $log->debug("*** Conducting Database Verification...");
     if (!verifyDatabase()) {
-        $log->err("Unable to connect to the database, please check the following: \n\t - settings for 'database' in portal_settings.ini are correct.\n\t - the database identified by the 'database' section of portal_settings.ini is running, accepting connections, and that the user specified has connection privileges.");
+        $log->error("Unable to connect to the database, please check the following: \n\t - settings for 'database' in portal_settings.ini are correct.\n\t - the database identified by the 'database' section of portal_settings.ini is running, accepting connections, and that the user specified has connection privileges.");
         exit(1);
     }
     $log->debug("*** Database Verification Passed!");
@@ -519,7 +519,7 @@ function processResult(iDatabase $db, $module, $moduleData, $modules)
     }
 
     if ($modules === null) {
-        $log->err("Unable to process $module, missing module information. Is there a $module.json file in CONF_DIR/datawarehouse.d?");
+        $log->error("Unable to process $module, missing module information. Is there a $module.json file in CONF_DIR/datawarehouse.d?");
         return;
     }
 
@@ -758,7 +758,7 @@ SQL;
     if ($updated === 1) {
         $log->info("[SUCCESS] Associated Module and Module Version.");
     } else {
-        $log->err("[FAILURE] Unable to associate Module and Module Version.");
+        $log->error("[FAILURE] Unable to associate Module and Module Version.");
     }
 }
 
@@ -1836,7 +1836,7 @@ function verifyAclSetup()
     $invalidSetupSections += ( ! verifyConfigData() ? 1 : 0);
 
     if ($invalidSetupSections > 0) {
-        $log->err("*** Verification Failed!");
+        $log->error("*** Verification Failed!");
     } else {
         $log->notice("*** All Configuration File Verification Steps Passed!");
     }
@@ -1871,7 +1871,7 @@ function verifyJsonSyntax()
             $fileJson = Json::loadFile($primaryFilePath);
 
             if (null === $fileJson) {
-                $log->err("[FAIL] $primaryFile in an invalid json file");
+                $log->error("[FAIL] $primaryFile in an invalid json file");
                 $inalid [] = $primaryFile;
             } else {
                 $log->info("[SUCCESS] $primaryFile is a valid json file.");
@@ -1899,7 +1899,7 @@ function verifyJsonSyntax()
                         $log->info("[SUCCESS] $fileId is a valid json file.");
                     } catch (Exception $e) {
                         $reason = $e->getMessage();
-                        $log->err("[FAIL] $fileId is not a valid json file. Reason:\n $reason");
+                        $log->error("[FAIL] $fileId is not a valid json file. Reason:\n $reason");
                         $invalid [] = $filePath;
                     }
                 }
@@ -1909,7 +1909,7 @@ function verifyJsonSyntax()
 
     $invalidCount = count($invalid);
     if ($invalidCount > 0) {
-        $log->err("[FAIL] $invalidCount invalid files found");
+        $log->error("[FAIL] $invalidCount invalid files found");
         return false;
     } else {
         $log->info("[SUCCESS] all files valid");
@@ -1957,7 +1957,7 @@ function syncTableData(iDatabase $db, array $tables)
 
     $committed = $db->commit();
     if ($committed === false) {
-        $log->crit("[FAIL] Attempt to commit staging data to production tables has failed. Rollback has been initiated");
+        $log->critical("[FAIL] Attempt to commit staging data to production tables has failed. Rollback has been initiated");
         $rolledBack = $db->rollBack();
 
         // We throw an Exception so that we do not leave the db in an inconsistent state.
@@ -1992,14 +1992,14 @@ function verifyConfigData()
             \Configuration\XdmodConfiguration::assocArrayFactory("$section.json", CONFIG_DIR);
             $log->info("[SUCCESS] $section loaded successfully.");
         } catch (Exception $e) {
-            $log->err(sprintf('[FAIL] Unable to load section %s: %s', $section, $e->getMessage()));
+            $log->error(sprintf('[FAIL] Unable to load section %s: %s', $section, $e->getMessage()));
             $invalid[] = $section;
         }
     }
 
     $invalidCount = count($invalid);
     if ($invalidCount > 0) {
-        $log->err("[FAIL] $invalidCount invalid sections found");
+        $log->error("[FAIL] $invalidCount invalid sections found");
         return false;
     } else {
         $log->info("[SUCCESS] all sections valid");

bin/xdmod-admin

@@ -157,12 +157,12 @@ function main()
     $logger->info("Command: $cmd");
 
     if ($entity === null) {
-        $logger->crit('No entity type specified');
+        $logger->critical('No entity type specified');
         exit(1);
     }
 
     if ($action === null) {
-        $logger->crit('No action specified');
+        $logger->critical('No action specified');
         exit(1);
     }
 
@@ -173,7 +173,7 @@ function main()
                     listResources();
                     break;
                 default:
-                    $logger->crit("Cannot perform '$action' on '$entity'");
+                    $logger->critical("Cannot perform '$action' on '$entity'");
                     exit(1);
                     break;
             }
@@ -184,13 +184,13 @@ function main()
                     truncateJobs();
                     break;
                 default:
-                    $logger->crit("Cannot perform '$action' on '$entity'");
+                    $logger->critical("Cannot perform '$action' on '$entity'");
                     exit(1);
                     break;
             }
             break;
         default:
-            $logger->crit("Unknown entity type '$entity'");
+            $logger->critical("Unknown entity type '$entity'");
             exit(1);
             break;
     }

bin/xdmod-build-filter-lists

@@ -96,10 +96,7 @@ function build($realms, $logger){
             $filterListBuilder->buildAllLists();
         }
     } catch (Exception $e) {
-        $logger->crit(array(
-            'message'    => 'Filter list building failed: ' . $e->getMessage(),
-            'stacktrace' => $e->getTraceAsString(),
-        ));
+        $logger->critical('Filter list building failed: ' . $e->getMessage(), ['stacktrace' => $e->getTraceAsString()]);
         exit(1);
     }
 }

bin/xdmod-convert-innodb-fpt

@@ -208,7 +208,7 @@ function export_innodb_tables() {
     global $logger, $db, $directory, $file_suffix;
 
     if ( $directory === null) {
-        $logger->crit("You must specify the directory export the tables too using the ---dir flag");
+        $logger->critical("You must specify the directory export the tables too using the ---dir flag");
         return;
     }
 
@@ -286,7 +286,7 @@ function import_innodb_tables() {
     global $logger, $db, $directory, $file_suffix, $file_suffix_length;
 
     if ( $directory === null) {
-        $logger->crit("You must specify the directory export the tables too using the ---dir flag");
+        $logger->critical("You must specify the directory export the tables too using the ---dir flag");
         return;
     }