Problem/Motivation

Spotted while understanding #3254307: [PP-1] Make clearer that classes in contributed modules should not generally add the LoggerChannelTrait trait

Core does not consistently use logger services. Many modules create logger.channel.[module] and then inject the channel directly, e.g. logger.channel.user or logger.channel.layout_builder.

However in other places we inject the logger factory instead and the module retrieves the channel in the constructor, for example Drupal\media\OEmbed\ProviderRepository - there is no logger.channel.media defined:

    $this->logger = $logger_factory->get('media');

We are even inconsistent within modules, e.g. rest.module declares a channel service:

  logger.channel.rest:
    parent: logger.channel_base
    arguments: ['rest']

But then some plugins use the factory instead:

core/modules/user/src/Plugin/rest/resource/UserRegistrationResource.php:      $container->get('logger.factory')->get('rest'),
core/modules/rest/src/Plugin/ResourceBase.php:      $container->get('logger.factory')->get('rest')
core/modules/rest/src/Plugin/rest/resource/EntityResource.php:      $container->get('logger.factory')->get('rest'),
core/modules/file/src/Plugin/rest/resource/FileUploadResource.php:      $container->get('logger.factory')->get('rest'),

This mixture of patterns is not a good example for contrib or custom code to follow.

Steps to reproduce

Proposed resolution

Consistently use the logger.channel.[module] format everywhere, declaring new services where appropriate.

Consider if we can make logger.factory private so it can only be injected into logger channel services but not retrieved from the container.

Remaining tasks

User interface changes

API changes

Data model changes

Release notes snippet

Issue fork drupal-3295542

Command icon Show commands

Start within a Git clone of the project using the version control instructions.

Or, if you do not have SSH keys set up on git.drupalcode.org:

Comments

longwave created an issue. See original summary.

larowlan’s picture

How would you have a dynamic channel in that case?

I have some generic services for dealing with migrations and I have one channel per migration, fetched dynamically from the factory. This lets me present migration specific logs in the UI.

If we had to declare the services ahead of time that would mean I'd need my own factory, which feels awkward when core already has

Perhaps we should document when to use one pattern over the other?

longwave’s picture

So maybe making the factory private is a step too far, but we should document that modules should only use the factory if they want dynamic logger channels, and should declare a channel service and use that directly otherwise?

My longer-term thinking on this also ties into autowiring. We can't autowire loggers directly because different services want to use different channels. But eventually we can use argument binding like this in e.g. user.services.yml:

services:
  _defaults:
    autowire: true
    bind:
      Psr\Log\LoggerInterface: '@logger.channel.user'

This would then mean that any service declared in this file that accepts a LoggerInterface will automatically get the user channel injected.

larowlan’s picture

Sounds good to me

longwave’s picture

Status: Active » Needs review

Had a first pass at this, fixing up all services that won't require BC - places that currently accept the factory will need a BC dance if they are to accept a channel instead.

alexpott’s picture

I postponed #3254307: [PP-1] Make clearer that classes in contributed modules should not generally add the LoggerChannelTrait trait on this because I think that however we change the documentation it should reflect the best practices implemented here.

Version: 9.5.x-dev » 10.1.x-dev

Drupal 9.5.0-beta2 and Drupal 10.0.0-beta2 were released on September 29, 2022, which means new developments and disruptive changes should now be targeted for the 10.1.x-dev branch. For more information see the Drupal core minor version schedule and the Allowed changes during the Drupal core release cycle.

smustgrave’s picture

Status: Needs review » Needs work

Reran the tests and appears to be 1 failure.

longwave’s picture

Status: Needs work » Needs review

Fixed the test; AutowireTest now thinks the base logger service should be autowired, but in fact it's abstract and cannot be autowired, so modified the test to account for this.

Had an idea for a followup: why don't we automatically create a logger channel service for each enabled module, given that they all follow a pattern. Then autowiring can inject the correct logger channel for a module, anywhere that LoggerInterface is used in a service? The developer has to do nothing except declare LoggerInterface in a constructor.

smustgrave’s picture

Status: Needs review » Reviewed & tested by the community

Sweet!

Seeing all green and the changes look good to me. Really need a better phrase but all I got right now haha.

longwave’s picture

Fixed a bug in the test which meant it effectively skipped all services, corrected that here but left it RTBC.

xjm’s picture

Is there any assertion we could add that would prevent the coverage issue from #12 from regressing?

xjm’s picture

Status: Reviewed & tested by the community » Needs review

I grepped the remaining calls to get('logger.factory'). Most look unrelated, or are getting a channel dynamically, or are looping over N channels, or doing other stuff for tests. However, there is this:

core/lib/Drupal/Core/DrupalKernel.php:      $this->container->get('logger.factory')->get('DrupalKernel')->error('Container cannot be saved to cache.');

I realize the Drupal kernel is not a module, but could we use the same pattern there?

Also in non-module instances, the entity reference field formatter: EntityReferenceEntityFormatter:

        $this->loggerFactory->get('entity')->error('Recursive rendering detected when rendering entity %entity_type: %entity_id, using the %field_name field on the %parent_entity_type:%parent_bundle %parent_entity_id entity. Aborting rendering.', [
          '%entity_type' => $entity->getEntityTypeId(),
          '%entity_id' => $entity->id(),
          '%field_name' => $items->getName(),
          '%parent_entity_type' => $items->getFieldDefinition()->getTargetEntityTypeId(),
          '%parent_bundle' => $items->getFieldDefinition()->getTargetBundle(),
          '%parent_entity_id' => $items->getEntity()->id(),
        ]);

Then there are a couple usages in media still where the logger factory is injected as a service. In MediaEmbed:

    if (static::$recursiveRenderDepth[$recursive_render_id] > EntityReferenceEntityFormatter::RECURSIVE_RENDER_LIMIT) {
      $this->loggerFactory->get('media')->error('During rendering of embedded media: recursive rendering detected for %entity_id. Aborting rendering.', [
        '%entity_id' => $media->id(),
      ]);
      return [];
    }
  }

In OEmbedResourceConstraintValidator:

  /**                                                                           
   * Constructs a new OEmbedResourceConstraintValidator.                        
   *                                                                            
   * @param \Drupal\media\OEmbed\UrlResolverInterface $url_resolver             
   *   The oEmbed URL resolver service.                                         
   * @param \Drupal\media\OEmbed\ResourceFetcherInterface $resource_fetcher     
   *   The resource fetcher service.                                            
   * @param \Drupal\Core\Logger\LoggerChannelFactoryInterface $logger_factory   
   *   The logger service.                                                      
   */
  public function __construct(UrlResolverInterface $url_resolver, ResourceFetcherInterface $resource_fetcher, LoggerChannelFactoryInterface $logger_factory) {
    $this->urlResolver = $url_resolver;
    $this->resourceFetcher = $resource_fetcher;
    $this->logger = $logger_factory->get('media');
  }
longwave’s picture

Status: Needs review » Needs work

As stated in #6 I only changed the cases that don't require BC, but I suppose we should do them all in one go.

Unsure if we can prevent this from regressing, as dynamic channels need to use the factory directly, and I'm not sure we can tell the difference.

donquixote’s picture

@longwave (#3)

My longer-term thinking on this also ties into autowiring. We can't autowire loggers directly because different services want to use different channels. But eventually we can use argument binding like this in e.g. user.services.yml:

services:
  _defaults:
    autowire: true
    bind:
      Psr\Log\LoggerInterface: '@logger.channel.user'

I would love to see this!
Do we have any issue where plan to add support for 'bind' in '_defaults'?
I did not find any. I only saw that in #3021898-18: Support _defaults key in service.yml files for public, tags and autowire settings it was removed from the PR of that issue.

longwave’s picture

Issue tags: +Needs change record

Deprecated some uses of logger.factory and converted them to individual logger channels, but there are a few more to go.

This needs a generic change record explaining what is happening in this issue.

Version: 10.1.x-dev » 11.x-dev

Drupal core is moving towards using a “main” branch. As an interim step, a new 11.x branch has been opened, as Drupal.org infrastructure cannot currently fully support a branch named main. New developments and disruptive changes should now be targeted for the 11.x branch, which currently accepts only minor-version allowed changes. For more information, see the Drupal core minor version schedule and the Allowed changes during the Drupal core release cycle.

voleger’s picture

What would be the equivalent logger channel service to \Drupal::logger('file system') ?

UPD: I think it has to be declared with a proper name and keep using space within an argument.
See #3073684: [pp-1] Deprecate system_check_directory() where introduced logger.channel.file_system channel service.

berdir’s picture

The reason I prefer injecting the factory is performance, instantiating a channel that isn't used (and log channels are very often not used, only when something goes wrong) is fairly expensive last time I checked, Or at least the first time it happens it's expensive.

It's similar to entity storages and config objects although definitely not that expensive. We changed core to not create entity storages in __construct() and it's generally discouraged to instantiate config objects in __construct() too and store the factory instead.

longwave’s picture

If instantiation is a problem then loggers should be lightweight lazy wrappers that do the work only when something needs to be logged - but it would be good to profile this first to prove whether or not it's a problem. The idea of this issue is to improve DX to make it both easy and consistent when using different logger channels.

catch’s picture

Can we not use service closures for this problem per https://www.drupal.org/node/3451855 ?

Version: 11.x-dev » main

Drupal core is now using the main branch as the primary development branch. New developments and disruptive changes should now be targeted to the main branch.

Read more in the announcement.