[11.x] Add --json flag to queue:work command for structured logging

[josecl]

This PR introduces a new --json flag for the queue:work command, enabling structured JSON output for enhanced observability.

Motivation

• Improves monitoring capabilities in cloud and Kubernetes environments without disrupting existing functionality.
• Provides contextual information about job execution, facilitating processing by log analysis tools.
• Standardizes log format, enabling community sharing of tooling (e.g., Grafana Loki dashboards).
• Aligns with recent JSON support additions to other Artisan commands.
• I’m ready to create a test if this PR is approved.

Why not?

• Introduces changes to a core command. My sense of smell tells me that I am proposing changes in a place where unnecessary changes are not welcome.
• Similar functionality could be achieved using custom queue event listeners and logging with Monolog\Formatter\JsonFormatter.

JSON output format

The JSON output continues to include two log entries per job: one at the start and another at completion.

Key fields include:

• timestamp: Datetime in ISO 8601 format.
• level: PSR-3 log level info or warning. It helps monitoring tools.
• status: Current execution status of queue:work command: starting, success, released_after_exception or failed.
• result: Outcome of completed jobs: deleted, released or failed.
• duration: In seconds.
• exception: FQCN of the Exception.
• message: Exception message.

Sucessful Job

{ "timestamp": "2024-09-23T13:47:37.347077+00:00", "level": "info", "job": "App\\Jobs\\NotificarJob", "id": "9af01732-609a-4418-86f3-904f928fd8cc", "uuid": "88098a41-4a1e-4ea6-a4f0-58511f91e915", "connection": "rabbitmq", "queue": "default", "status": "success", "result": "deleted", "attempts": 1, "duration": 0.014354 }

Failed Job

{ "timestamp": "2024-09-23T13:44:57.393616+00:00", "level": "warning", "job": "App\\Jobs\\TestJob", "id": "12c2916c-6a04-40d7-b0d8-c48897c425a0", "uuid": "7e719912-f6c2-4018-a1c2-c7254992f182", "connection": "rabbitmq", "queue": "default", "status": "failed", "result": "deleted", "attempts": 3, "exception": "App\\Exceptions\\TestException", "message": "I have failed you.", "duration": 0.001601 }

Job Starting

{ "timestamp": "2024-09-23T13:48:37.593466+00:00", "level": "info", "job": "App\\Jobs\\ConsultarEnvioDocumentoAReguladorJob", "id": "e600e9dd-474b-4e18-ad5e-a3cadd3b04c9", "uuid": "e76cd7c8-1754-48e7-9b45-5a7ea8664d53", "connection": "rabbitmq", "queue": "regulador", "status": "starting", "attempts": 2 }

Open Questions

• Is the "Job Starting" log entry necessary, or should we only log job completion?
• Should we use the -v argument to control the verbosity of the JSON output?
• Are there any additional fields that would be valuable to include in the JSON output?

[josecl]

Proposed Improvements

Would you like me to update the PR with these suggestions?

1. Introduce JSON_PRETTY_PRINT Option

Currently, the JSON log is correctly formatted as a single line. However, for improved readability, I propose adding an option to use JSON_PRETTY_PRINT when APP_DEBUG=true.

2. Include Log Contextual Information

I suggest incorporating the logger's contextual information. This will allow users to add custom information and reduce the need for future pull requests. The feature should be configurable as an opt-in option in the queue.php config file, maybe accepting either a boolean flag or a specific channel name for flexibility.

Example:

{ "level": "info", "id": "44d41635-8f54-4fa0-b121-03408624176c", "uuid": "c1a054e8-f0aa-4220-b325-78843135e621", "connection": "rabbitmq", "queue": "contraparte", "job": "App\\Jobs\\EnviarDocumentoAContraparteJob", "status": "success", "result": "released", "attempts": 2, "context": { "documento_id": "01j8kzztykzxqmmmccqc146jnm", "institucion_id": 1, "action": "App\\Actions\\FirmarXmlAction" }, "timestamp": "2024-09-25T07:09:44.223718+00:00", "duration": 0.343553 }

To implement this, I believe we will need to add a context() method to the Illuminate\Log\Logger class:

public function context(): array { return $this->context; }

[josecl]

3. Add Exception to JobReleasedAfterException event

When a Job finishes with released_after_exception status, there's no Exception context. I propose adding a third parameter to the event's constructor, similar to JobFailed.

Is this a potential breaking change? The JobReleasedAfterException event is only dispatched in Illuminate\Queue\Worker. To avoid potential breaking changes, we could make it null by default.

[aromka]

This throws errors when running php artisan horizon.

The "json" option does not exist.

The "json" option does not exist. {"exception":"[object] (Symfony\\Component\\Console\\Exception\\InvalidArgumentException(code: 0): The \"json\" option does not exist. at /vendor/symfony/console/Input/Input.php:127) 

Also reported in #53071

[NiroDeveloper]

I think Laravel Horizon is missing an option to enable JSON logging.
Or can we already customize all worker options?