Merge pull request #257 from cleverage/157

#157 - Configure the level of the end of process logs

Author: njoubert-cleverage

CHANGELOG.md

@@ -9,6 +9,7 @@ Latest
 * [#117](https://github.com/cleverage/process-bundle/issues/117) MappingTransformer: writing a target property that is a nested path (e.g. `address.city`) on an array destination, which silently created an `address.city` literal key, is deprecated and will throw an `\UnexpectedValueException` in v6.0. Use `[address.city]` for a literal key or `[address][city]` for a nested array; a simple property name (e.g. `name`) is still added as a key. Update documentation, add tests.
 * [#258](https://github.com/cleverage/process-bundle/issues/258) Add XmlStreamReaderTask: iterable task reading an XML file element by element with `\XMLReader` (constant memory), outputting each element named `node_name` as a `\DOMElement` in its own `\DOMDocument`, ready for XpathEvaluatorTransformer. The file path is set in the `file_path` option or given as input. Add documentation and tests.
 * [#259](https://github.com/cleverage/process-bundle/issues/259) JsonStreamWriterTask: add a `mode` option (default `wb`, e.g. `ab` to append to an existing JSON Lines file), and release the file on `finalize()`. Update documentation, add tests.
+* [#157](https://github.com/cleverage/process-bundle/issues/157) Configure the level of the logs written at the end of each process with the new `logs` option, globally (`clever_age_process.logs`) or per process (`configurations.<code>.logs`): `success_level` (default `info`) for `Process <code> succeed`, and `failed_level` (default `debug`) for the new `Process <code> failed` log, written when a process fails, with or without exception. Update documentation, add tests.
 
 ## Fixes
 * [#143](https://github.com/cleverage/process-bundle/issues/143) Fix InputIteratorTask: an `\IteratorAggregate` input whose `getIterator()` does not return an `\Iterator` (e.g. another `\IteratorAggregate`) is iterated instead of failing with a `TypeError`. Update documentation, add tests.

config/services/registry.yaml

@@ -5,6 +5,7 @@ services:
         arguments:
             - ~
             - ~
+            - ~
 
     cleverage_process.registry.transformer:
         class: CleverAge\ProcessBundle\Registry\TransformerRegistry

docs/01-quick_start.md

@@ -51,12 +51,14 @@ framework:
 
 You can use `./bin/console config:dump-reference clever_age_process` to have a summary of current configuration.
 
-The configuration has three root keys:
+The configuration has four root keys:
 - `configurations`: your processes (see [process definition](reference/01-process_definition.md))
 - `generic_transformers`: reusable transformers built from configuration (see
   [generic transformers definition](reference/03-generic_transformers_definition.md))
 - `default_error_strategy`: the behavior of a task that encounters an error when it does not define its own
   `error_strategy`. Allowed values are `stop` (the default) and `skip`.
+- `logs`: the levels of the logs written at the end of each process, `success_level` (`info` by default) and
+  `failed_level` (`debug` by default), see [process definition](reference/01-process_definition.md#global-attributes)
 
 We recommend keeping the `stop` default, and then specify task by task which one can be skipped:
 

docs/cookbooks/performances_monitoring.md

@@ -52,8 +52,10 @@ SQL             n/a     n/a
 ## Built-in timing information
 
 Before profiling, the process logs already give some timing information:
-- on success, the process manager logs `Process <process_code> succeed` (level `info`, channel `cleverage_process`)
-  with the total `duration` of the process, in seconds, in the record context
+- at the end, the process manager logs `Process <process_code> succeed` (level `info` by default, channel
+  `cleverage_process`) or `Process <process_code> failed` (level `debug` by default), with the total `duration` of
+  the process, in seconds, in the record context. Both levels can be configured, see the `logs` option of the
+  [process definition](../reference/01-process_definition.md)
 - at `debug` level, the same channel logs each task execution (`Processing task <task_code>`, `Proceeding task ...`,
   `Flushing task ...`): with a formatter displaying milliseconds, it shows where the time is spent. With the Monolog
   console handler of the Symfony recipe, `-vvv` displays debug records in the console:

docs/reference/01-process_definition.md

@@ -7,6 +7,9 @@ YAML Configuration
 ```yaml
 clever_age_process:
     default_error_strategy: <stop|skip>
+    logs:
+        success_level: <emergency|alert|critical|error|warning|notice|info|debug>
+        failed_level: <emergency|alert|critical|error|warning|notice|info|debug>
     configurations:
         <process_code>:
             description: <string>
@@ -15,6 +18,9 @@ clever_age_process:
             end_point: <task_code>
             public: <true|false>
             options: <array>
+            logs:
+                success_level: <emergency|alert|critical|error|warning|notice|info|debug>
+                failed_level: <emergency|alert|critical|error|warning|notice|info|debug>
             tasks:
                 <task_code>: <task_definition>
 ```
@@ -25,6 +31,16 @@ Global attributes
 **default_error_strategy**: optional, either *stop* (default) or *skip*. Error strategy used by every task that does
 not define its own `error_strategy` (see [task definition](02-task_definition.md)).
 
+**logs**: optional [RFC 5424](https://datatracker.ietf.org/doc/html/rfc5424) severities of the logs written at the end
+of each process (channel `cleverage_process`, with the `duration` of the process in seconds in the record context):
+* `success_level` (default *info*): level of the `Process <process_code> succeed` log
+* `failed_level` (default *debug*): level of the `Process <process_code> failed` log, written when the process fails,
+  either with an exception (in addition to the `Critical process failure` log) or when it is stopped without exception
+  (e.g. by a [StopTask](tasks/stop_task.md))
+
+Without UI, the success log is the only trace of a succeeded process: lower its level (e.g. *debug*) only if processes
+are followed by other means.
+
 Process attributes
 ------------------
 
@@ -51,6 +67,9 @@ from the process list (unless `--all` is used) but execution is still allowed.
 through `ProcessConfiguration::getOptions()`, e.g. [cleverage/ui-process-bundle](https://github.com/cleverage/ui-process-bundle)
 reads its `ui` key to configure the launch form.
 
+**logs**: optional `success_level` and `failed_level` overriding, for this process only, the global
+[`logs`](#global-attributes) levels (e.g. a scheduled process that often has nothing to do).
+
 **tasks**: list of task definitions contained in the process, indexed by task code. See
 [task definition](02-task_definition.md).
 

src/Configuration/ProcessConfiguration.php

@@ -15,6 +15,7 @@
 
 use CleverAge\ProcessBundle\Exception\CircularProcessException;
 use CleverAge\ProcessBundle\Exception\MissingTaskConfigurationException;
+use Psr\Log\LogLevel;
 
 /**
  * Holds the processes configuration to launch a task.
@@ -44,6 +45,8 @@ public function __construct(
         protected string $description = '',
         protected string $help = '',
         protected bool $public = true,
+        protected string $successLogLevel = LogLevel::INFO,
+        protected string $failedLogLevel = LogLevel::DEBUG,
     ) {
     }
 
@@ -93,6 +96,22 @@ public function isPublic(): bool
         return $this->public;
     }
 
+    /**
+     * Level of the "Process <code> succeed" log.
+     */
+    public function getSuccessLogLevel(): string
+    {
+        return $this->successLogLevel;
+    }
+
+    /**
+     * Level of the "Process <code> failed" log.
+     */
+    public function getFailedLogLevel(): string
+    {
+        return $this->failedLogLevel;
+    }
+
     public function isPrivate(): bool
     {
         return !$this->public;

src/DependencyInjection/CleverAgeProcessExtension.php

@@ -40,6 +40,7 @@ public function load(array $configs, ContainerBuilder $container): void
         $processConfigurationRegistry = $container->getDefinition('cleverage_process.registry.process_configuration');
         $processConfigurationRegistry->replaceArgument(0, $config['configurations']);
         $processConfigurationRegistry->replaceArgument(1, $config['default_error_strategy']);
+        $processConfigurationRegistry->replaceArgument(2, $config['logs']);
 
         // Automatic transformer creation from config
         foreach ($config['generic_transformers'] as $transformerCode => $transformerConfig) {

src/DependencyInjection/Configuration.php

@@ -27,6 +27,17 @@
  */
 class Configuration implements ConfigurationInterface
 {
+    protected const LOG_LEVELS = [
+        LogLevel::EMERGENCY,
+        LogLevel::ALERT,
+        LogLevel::CRITICAL,
+        LogLevel::ERROR,
+        LogLevel::WARNING,
+        LogLevel::NOTICE,
+        LogLevel::INFO,
+        LogLevel::DEBUG,
+    ];
+
     public function __construct(
         protected string $root = 'clever_age_process',
     ) {
@@ -42,6 +53,19 @@ public function getConfigTreeBuilder(): TreeBuilder
             ->values([TaskConfiguration::STRATEGY_SKIP, TaskConfiguration::STRATEGY_STOP])
             ->defaultValue(TaskConfiguration::STRATEGY_STOP);
 
+        // Default log levels of the end of the processes
+        $logsDefinition = $definition->arrayNode('logs')
+            ->addDefaultsIfNotSet()
+            ->children();
+        $logsDefinition->enumNode('success_level')
+            ->values(self::LOG_LEVELS)
+            ->defaultValue(LogLevel::INFO)
+            ->info('Level of the "Process <code> succeed" log');
+        $logsDefinition->enumNode('failed_level')
+            ->values(self::LOG_LEVELS)
+            ->defaultValue(LogLevel::DEBUG)
+            ->info('Level of the "Process <code> failed" log');
+
         $this->appendRootProcessConfigDefinition($definition);
         $this->appendRootTransformersConfigDefinition($definition);
 
@@ -125,6 +149,20 @@ protected function appendProcessConfigDefinition(NodeBuilder $definition): void
             ->arrayNode('options')
             ->prototype('variable')
             ->end()
+            ->end()
+            ->arrayNode('logs')
+            ->info('Override the default log levels of the end of the process')
+            ->addDefaultsIfNotSet()
+            ->children()
+            ->enumNode('success_level')
+            ->values([...self::LOG_LEVELS, null])
+            ->defaultNull()
+            ->end()
+            ->enumNode('failed_level')
+            ->values([...self::LOG_LEVELS, null])
+            ->defaultNull()
+            ->end()
+            ->end()
             ->end();
 
         /** @var ArrayNodeDefinition $tasksArrayDefinition */
@@ -145,17 +183,6 @@ protected function appendProcessConfigDefinition(NodeBuilder $definition): void
 
     protected function appendTaskConfigDefinition(NodeBuilder $definition): void
     {
-        $logLevels = [
-            LogLevel::EMERGENCY,
-            LogLevel::ALERT,
-            LogLevel::CRITICAL,
-            LogLevel::ERROR,
-            LogLevel::WARNING,
-            LogLevel::NOTICE,
-            LogLevel::INFO,
-            LogLevel::DEBUG,
-        ];
-
         $definition->scalarNode('service')
             ->isRequired();
         $definition->scalarNode('description')
@@ -168,7 +195,7 @@ protected function appendTaskConfigDefinition(NodeBuilder $definition): void
         $definition->scalarNode('error_strategy')
             ->defaultNull();
         $definition->enumNode('log_level')
-            ->values($logLevels)
+            ->values(self::LOG_LEVELS)
             ->defaultValue(LogLevel::CRITICAL);
 
         foreach (['outputs', 'errors', 'error_outputs'] as $nodeName) {

src/Manager/ProcessManager.php

@@ -129,44 +129,54 @@ protected function doExecute(string $processCode, mixed $input = null, array $co
         $processConfiguration = $this->processConfigurationRegistry->getProcessConfiguration($processCode);
         $processHistory = $this->initializeStates($processConfiguration, $context);
         $this->processHistory = $processHistory;
-        $this->checkProcess($processConfiguration);
 
-        // First initialize the whole stack in a linear way, tasks are initialized in the order they are configured
-        foreach ($processConfiguration->getTaskConfigurations() as $taskConfiguration) {
-            $this->initialize($taskConfiguration);
-        }
+        try {
+            $this->checkProcess($processConfiguration);
 
-        // If defined, set the input of a task
-        if ($processConfiguration->getEntryPoint() instanceof TaskConfiguration) {
-            $processConfiguration->getEntryPoint()
-                ->getState()
-                ->setInput($input);
-        } elseif (null !== $input) {
-            $this->processLogger->warning('Process has no entry point for input');
-        }
+            // First initialize the whole stack in a linear way, tasks are initialized in the order they are configured
+            foreach ($processConfiguration->getTaskConfigurations() as $taskConfiguration) {
+                $this->initialize($taskConfiguration);
+            }
 
-        // Resolve task from main branch, starting by the end
-        $taskList = array_reverse($processConfiguration->getTaskConfigurations());
-        $allowedTasks = $processConfiguration->getMainTaskGroup();
-        foreach ($taskList as $taskConfiguration) {
-            if (\in_array($taskConfiguration->getCode(), $allowedTasks, true)) {
-                $this->resolve($taskConfiguration);
+            // If defined, set the input of a task
+            if ($processConfiguration->getEntryPoint() instanceof TaskConfiguration) {
+                $processConfiguration->getEntryPoint()
+                    ->getState()
+                    ->setInput($input);
+            } elseif (null !== $input) {
+                $this->processLogger->warning('Process has no entry point for input');
             }
-        }
 
-        // Finalize the process in a linear way
-        foreach ($processConfiguration->getTaskConfigurations() as $taskConfiguration) {
-            $this->finalize($taskConfiguration);
-        }
+            // Resolve task from main branch, starting by the end
+            $taskList = array_reverse($processConfiguration->getTaskConfigurations());
+            $allowedTasks = $processConfiguration->getMainTaskGroup();
+            foreach ($taskList as $taskConfiguration) {
+                if (\in_array($taskConfiguration->getCode(), $allowedTasks, true)) {
+                    $this->resolve($taskConfiguration);
+                }
+            }
 
-        $this->endProcess($processHistory);
+            // Finalize the process in a linear way
+            foreach ($processConfiguration->getTaskConfigurations() as $taskConfiguration) {
+                $this->finalize($taskConfiguration);
+            }
 
-        // If defined, return the output of a task
-        $returnValue = null;
-        if ($processConfiguration->getEndPoint() instanceof TaskConfiguration) {
-            $returnValue = $processConfiguration->getEndPoint()
-                ->getState()
-                ->getOutput();
+            $this->endProcess($processHistory);
+
+            // If defined, return the output of a task
+            $returnValue = null;
+            if ($processConfiguration->getEndPoint() instanceof TaskConfiguration) {
+                $returnValue = $processConfiguration->getEndPoint()
+                    ->getState()
+                    ->getOutput();
+            }
+        } catch (\Throwable $error) {
+            if ($processHistory->isStarted()) {
+                $processHistory->setFailed();
+            }
+            $this->endProcess($processHistory);
+
+            throw $error;
         }
 
         $this->processHistory = $parentProcessHistory;
@@ -519,16 +529,27 @@ protected function handleState(ProcessState $state): void
 
     protected function endProcess(ProcessHistory $history): void
     {
+        $processConfiguration = $this->processConfigurationRegistry->getProcessConfiguration($history->getProcessCode());
+
         // Do not change state if already set
         if ($history->isStarted()) {
             $history->setSuccess();
 
-            $this->processLogger->info(
+            $this->processLogger->log(
+                $processConfiguration->getSuccessLogLevel(),
                 "Process {$history->getProcessCode()} succeed",
                 [
                     'duration' => $history->getDuration(),
                 ]
             );
+        } elseif ($history->isFailed()) {
+            $this->processLogger->log(
+                $processConfiguration->getFailedLogLevel(),
+                "Process {$history->getProcessCode()} failed",
+                [
+                    'duration' => $history->getDuration(),
+                ]
+            );
         }
     }
 

src/Registry/ProcessConfigurationRegistry.php

@@ -30,11 +30,13 @@ class ProcessConfigurationRegistry
     protected array $processConfigurations = [];
 
     /**
-     * @param array<string, array<string, mixed>> $rawConfiguration
+     * @param array<string, array<string, mixed>>                  $rawConfiguration
+     * @param array{success_level?: string, failed_level?: string} $defaultLogLevels
      */
     public function __construct(
         protected array $rawConfiguration,
         protected string $defaultErrorStrategy,
+        protected array $defaultLogLevels = [],
     ) {
     }
 
@@ -105,7 +107,9 @@ protected function resolveConfiguration(string $processCode): void
             $rawProcessConfiguration['end_point'],
             $rawProcessConfiguration['description'],
             $rawProcessConfiguration['help'],
-            $rawProcessConfiguration['public']
+            $rawProcessConfiguration['public'],
+            $rawProcessConfiguration['logs']['success_level'] ?? $this->defaultLogLevels['success_level'] ?? LogLevel::INFO,
+            $rawProcessConfiguration['logs']['failed_level'] ?? $this->defaultLogLevels['failed_level'] ?? LogLevel::DEBUG
         );
 
         // Set links between tasks