Skip to content

[Messenger] Log when worker should stop and when SIGTERM is received #42723

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
Oct 7, 2021

Conversation

ruudk
Copy link
Contributor

@ruudk ruudk commented Aug 25, 2021

Q A
Branch? 5.4
Bug fix? no
New feature? yes
Deprecations? no
Tickets
License MIT
Doc PR

These two small log lines can help debugging crashing workers. Sometimes it's hard to tell if the worker crashed or is shutting down. Also, when working on gracefully shutdown problems, it's helpful to know when a SIGTERM was received and the worker is about to stop.

@ruudk
Copy link
Contributor Author

ruudk commented Aug 26, 2021

@OskarStark Applied your feedback.

@ruudk
Copy link
Contributor Author

ruudk commented Aug 27, 2021

@Nyholm @jderusse I checked and psr/log is already a dependency for Messenger. Is there anything left for me to change/add? Or is it Ok like this?

@okwinza
Copy link
Contributor

okwinza commented Aug 31, 2021

I think this PR could really benefit from #42335 once that is merged to provide additional context about the worker in the logs.

@ruudk
Copy link
Contributor Author

ruudk commented Aug 31, 2021

@okwinza That's a nice improvement for a future PR indeed :)

Can we get this merged?

@OskarStark
Copy link
Contributor

Could you add a testcase for this new feature? Thank you

@okwinza
Copy link
Contributor

okwinza commented Aug 31, 2021

I would suggest merging #42335 first and then rebasing and refactoring this PR on top of it since this PR loses a significant part of it's value without the worker context data IMO.

@ruudk
Copy link
Contributor Author

ruudk commented Aug 31, 2021

@okwinza I'm sorry but why would it loose value? This adds value so that it's known that the signal is received and that your signaling works. If it's so important that you know which worker was signaled, then you can already use separate logs. In my case, we run in Kubernetes and all workers are separated and identifiable. If your PR is merged, please improve this further. Let's not creating blocks that are not needed.

@OskarStark I added a test case for stopping the worker. I couldn't add a test for the pcntl_signal callback as I don't know how to test that. I can move the callback to a separate public method just for the sake of testing but that also feels wrong. What do you think?

@chalasr chalasr added this to the 5.4 milestone Sep 1, 2021
lyrixx added a commit that referenced this pull request Sep 22, 2021
…kwinza)

This PR was merged into the 5.4 branch.

Discussion
----------

[Messenger] Add `WorkerMetadata` to `Worker` class.

| Q             | A
| ------------- | ---
| Branch?       | 5.4
| Bug fix?      | no
| New feature?  | yes
| Deprecations? | no
| Tickets       | Fixes #37736
| License       | MIT
| Doc PR        | -

At the moment, there is no clean way to access the values of `transportNames` or recently introduced `queueNames` that the worker was configured with, although such data might be quite useful for logging/monitoring or other tasks.

This PR attempts to fix that by adding a new and extensible way to provide additional information about a particular `Worker` object.

So far, the following PRs could benefit from this change:

- #43133
- #42723

**Use case example:**
----

- As I developer
- When a message was consumed from transport with name `async`.
- And the worker state is `idle`.
- Then I want to reset services.

**Before this PR**, the only solution not relying on using Reflection API would look like this:
```php
    private $servicesResetter;
    private $receiversName;
    private $actualReceiverName = null;

    public function __construct(ServicesResetter $servicesResetter, array $receiversName)
    {
        $this->servicesResetter = $servicesResetter;
        $this->receiversName = $receiversName;
    }

    public function saveReceiverName(AbstractWorkerMessageEvent $event): void
    {
        $this->actualReceiverName = $event->getReceiverName();
    }

    public function resetServices(WorkerRunningEvent $event): void
    {
        if (!$event->isWorkerIdle() && \in_array($this->actualReceiverName, $this->receiversName, true)) {
            $this->servicesResetter->reset();
        }

        $this->actualReceiverName = null;
    }

    public static function getSubscribedEvents(): array
    {
        return [
            WorkerMessageHandledEvent::class => ['saveReceiverName'],
            WorkerMessageFailedEvent::class => ['saveReceiverName'],
            WorkerRunningEvent::class => ['resetServices'],
        ];
    }
```
**With this PR**, one could simply use this to retrieve the transport name.
```php
$event->getWorker()->getWorkerMetadata()->getTransportName() === $this->transportName;
```
So the whole solution would look like this:
```php
    private $servicesResetter;
    private $receiversName;

    public function __construct(ServicesResetter $servicesResetter, array $receiversName)
    {
        $this->servicesResetter = $servicesResetter;
        $this->receiversName = $receiversName;
    }

    public function resetServices(WorkerRunningEvent $event): void
    {
        $actualTransportName = $event->getWorker()->getWorkerMetadata()->getTransportName();
        if (!$event->isWorkerIdle() || !in_array($actualTransportName, $this->receiversName, true)) {
            return;
        }

        $this->servicesResetter->reset();
    }

    public static function getSubscribedEvents(): array
    {
        return [
            WorkerRunningEvent::class => ['resetServices'],
        ];
    }
```

Commits
-------

583f85b [Messenger] Add WorkerMetadata to Worker class
@lyrixx
Copy link
Member

lyrixx commented Sep 23, 2021

Could you rebase? Thanks

@ruudk
Copy link
Contributor Author

ruudk commented Sep 27, 2021

@lyrixx Done :)

@ruudk
Copy link
Contributor Author

ruudk commented Oct 7, 2021

@lyrixx The PR keeps getting out of date when the changelog changes. Updated the PR again to make it mergeable. Is there anything left that prevents a merge?

Copy link
Member

@lyrixx lyrixx left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍🏼 Thanks

@fabpot
Copy link
Member

fabpot commented Oct 7, 2021

Thank you @ruudk.

@fabpot fabpot merged commit 7993530 into symfony:5.4 Oct 7, 2021
@ruudk ruudk deleted the logging branch October 7, 2021 11:41
fabpot added a commit that referenced this pull request Oct 7, 2021
…omie)

This PR was merged into the 5.4 branch.

Discussion
----------

[Messenger] Add worker metadata inside logs

| Q             | A
| ------------- | ---
| Branch?       | 5.4
| Bug fix?      | no
| New feature?  | .
| Deprecations? | no
| Tickets       | Improve #42723
| License       | MIT
| Doc PR        | .

Small PR related to one of my comment #42723 (comment) on the ticket PR: having this contextual info is valuable imho
cc `@ruudk` `@okwinza` `@fabpot`

Commits
-------

649cb10 [Messenger] Add worker metadata inside logs
This was referenced Nov 5, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

10 participants