iTranslated by AI

The content below is an AI-generated translation. This is an experimental feature, and may contain errors. View original article
🚨

Laravel Deprecation Logger: Why LOG_DEPRECATIONS_CHANNEL=null Fails

に公開

🎭 Prologue: Encountering the Mysterious EMERGENCY Log

While working on an upgrade to PHP 8.5, an unexpected log appeared.

[2025-12-25 09:34:53] laravel.EMERGENCY: Unable to create configured logger. Using emergency logger.

"I configured it... so why?"

I had set LOG_DEPRECATIONS_CHANNEL=null in the .env file, intending to disable deprecation warnings in the production environment. However, it continued to spit out deprecation warnings into laravel.log.

🔍 Discovering the Problem

After upgrading to PHP 8.5, I noticed that Symfony deprecation warnings were being output.

[2025-12-25 09:34:53] laravel.WARNING: Since symfony/http-foundation 7.4: 
Request::get() is deprecated, use properties ->attributes, query or request directly instead.

I want to record these in the development environment, but they are unnecessary in production. Therefore, I configured it according to the Laravel documentation.

What I Configured

.env

LOG_DEPRECATIONS_CHANNEL=null

Expected Behavior

  • Deprecation warnings are not recorded in the log.

Actual Behavior

  • Warnings are output to laravel.log.
  • Additionally, a mysterious EMERGENCY log appears.

"Something is wrong..."


🤔 Initial Hypothesis: Is the Environment Variable Not Being Read?

First, I suspected whether the environment variable was being read correctly.

sail artisan tinker
> echo env('LOG_DEPRECATIONS_CHANNEL');
// Output: (Nothing displayed = null)

The environment variable is correctly set to null. So, why isn't it working?

Possibility of Laravel's Configuration Cache

sail artisan config:clear
sail artisan config:cache

However, the result remained the same. It was the same even after restarting the container.

"The settings are being read, so why aren't they taking effect?"


📚 Understanding the Structure of the Configuration File

Let's check config/logging.php again.

return [
    'default' => env('LOG_CHANNEL', 'stack'),
    
    // Top-level deprecations configuration
    'deprecations' => [
        'channel' => env('LOG_DEPRECATIONS_CHANNEL', 'null'),
        'trace' => env('LOG_DEPRECATIONS_TRACE', false),
    ],
    
    'channels' => [
        'stack' => [...],
        'single' => [...],
        'null' => [
            'driver' => 'monolog',
            'handler' => NullHandler::class,
        ],
        // 🤔 The deprecations channel is not defined!
    ],
];

Important discoveries here:

  • There is a deprecations configuration at the top level.
  • deprecations is not defined within channels.

According to the Laravel documentation, it should work by setting the top-level deprecations.channel... and yet.


🕵️ A Dive into Laravel Internal Code

Now for the main event. Let's decipher the Laravel source code.

1. Entry Point: HandleExceptions.php

When a deprecation error occurs, handleDeprecationError() is called.

// vendor/laravel/framework/src/Illuminate/Foundation/Bootstrap/HandleExceptions.php

public function handleDeprecationError($message, $file, $line, $level = E_DEPRECATED)
{
    // ...
    
    $this->ensureDeprecationLoggerIsConfigured();  // 👈 Check configuration
    
    $options = static::$app['config']->get('logging.deprecations') ?? [];
    
    with($logger->channel('deprecations'), function ($log) use (...) {  // 👈 Exception occurs here!
        $log->warning($message);
    });
}

2. Checking Configuration: ensureDeprecationLoggerIsConfigured()

protected function ensureDeprecationLoggerIsConfigured()
{
    $config = static::$app['config'];
    
    // Skip if already defined
    if ($config->get('logging.channels.deprecations')) {
        return;
    }
    
    // Get from top-level deprecations configuration
    if (is_array($options = $config->get('logging.deprecations'))) {
        $driver = $options['channel'] ?? 'null';  // 👈 Get 'null'
    } else {
        $driver = $options ?? 'null';
    }
    
    // Dynamically copy configuration
    $config->set('logging.channels.deprecations', 
                 $config->get("logging.channels.{$driver}"));  // 👈 Copy the null channel
}

Up to this point, it should be working normally...

3. Retrieving the Log Channel: LogManager.php

The problem occurs in the next line.

$logger->channel('deprecations')

What is happening internally?

// vendor/laravel/framework/src/Illuminate/Log/LogManager.php

protected function get($name, ?array $config = null)
{
    try {
        return $this->channels[$name] ?? with($this->resolve($name, $config), function ($logger) use ($name) {
            // ...
            return $this->channels[$name] = $loggerWithContext;
        });
    } catch (Throwable $e) {
        // 👈 Catch exception here!
        return tap($this->createEmergencyLogger(), function ($logger) use ($e) {
            $logger->emergency('Unable to create configured logger. Using emergency logger.', [
                'exception' => $e,
            ]);
        });
    }
}

If an exception occurs, it falls back to the Emergency Logger!

4. What exception is occurring?

protected function resolve($name, ?array $config = null)
{
    $config ??= $this->configurationFor($name);  // 👈 Get configuration here
    
    if (is_null($config)) {
        throw new InvalidArgumentException("Log [{$name}] is not defined.");  // 👈 This is it!
    }
    // ...
}

protected function configurationFor($name)
{
    return $this->app['config']["logging.channels.{$name}"];  // 👈 Returns null
}

5. The True Identity of the Emergency Logger

protected function createEmergencyLogger()
{
    $config = $this->configurationFor('emergency');
    
    $handler = new StreamHandler(
        $config['path'] ?? $this->app->storagePath().'/logs/laravel.log',  // 👈 laravel.log!
        $this->level(['level' => 'debug'])
    );
    
    return new Logger(
        new Monolog('laravel', $this->prepareHandlers([$handler])),
        $this->app['events']
    );
}

The truth has been revealed!


💡 Identifying the Real Culprit: A Timing Issue

Let's organize the flow of the problem:

  1. Line 101: ensureDeprecationLoggerIsConfigured() is executed.
  2. Line 149: The configuration is dynamically set via $config->set('logging.channels.deprecations', ...).
  3. Line 105: $logger->channel('deprecations') is called.
  4. Inside LogManager: configurationFor('deprecations') is executed.
  5. However: null is returned before the configuration is reflected.
  6. Result: An InvalidArgumentException is thrown.
  7. Fallback: The Emergency Logger (laravel.log) is used.

In other words, a Race Condition exists between the dynamic addition of the configuration and the internal processing of the LogManager!

Why does the race condition occur?

While $config->set() is a dynamic runtime configuration, it is referenced before being reflected due to internal caching or the order of processing within the LogManager.


✅ The Solution and Why It Works

Solution: Explicitly Define channels.deprecations

// config/logging.php

'channels' => [
    // ... other channels
    
    'deprecations' => [
        'driver' => env('LOG_DEPRECATIONS_CHANNEL') === null ? 'monolog' : 'single',
        'handler' => env('LOG_DEPRECATIONS_CHANNEL') === null ? NullHandler::class : null,
        'path' => env('LOG_DIR', storage_path('logs')) . '/deprecations.log',
        'level' => 'warning',
        'replace_placeholders' => true,
        'permission' => 0660,
    ],
],

Why Does This Solve It?

Take a look at the first check in ensureDeprecationLoggerIsConfigured():

if ($config->get('logging.channels.deprecations')) {
    return;  // 👈 If already defined, do nothing
}

By defining it explicitly:

  • The dynamic configuration addition is skipped.
  • LogManager can reference the configuration directly.
  • The timing issue is avoided.

Control Based on Environment

Development Environment (.env)

LOG_DEPRECATIONS_CHANNEL=deprecations

→ Recorded in deprecations.log using the single driver.

Production Environment (.env.production)

# Set LOG_DEPRECATIONS_CHANNEL to null, or remove it
LOG_DEPRECATIONS_CHANNEL=null

env() returns null, and it is disabled via NullHandler.


🎯 Conclusion: A Laravel Bug, or Something Else?

Is This a Bug?

Technically: Yes, it is a defect caused by a timing issue.

Practically: A workaround exists.

Should It Be Reported to the Laravel Community?

  • Worth reporting: Other developers are likely encountering the same issue.
  • But fixing it is difficult: It would require major changes to the internal architecture.
  • Realistic response: Explicitly define channels.deprecations.

Example Commit Message for a Merge Request

fix: Add explicit deprecations channel configuration

Explicitly defined logging.channels.deprecations to avoid a timing issue
during Laravel's deprecation logger initialization.

This allows controlling the output of deprecation warnings using the
LOG_DEPRECATIONS_CHANNEL environment variable.

- Development: Log warnings by setting LOG_DEPRECATIONS_CHANNEL=deprecations
- Production: Disable logs by leaving the environment variable unset

🎓 Lessons Learned

  1. Laravel's configuration has a two-layer structure

    • Top-level settings (logging.deprecations)
    • Channel settings (logging.channels.*)
  2. Dynamic configuration has its limits

    • config->set() is not a silver bullet
    • Timing issues must be taken into account
  3. The existence of the Emergency Logger

    • If log configuration fails, it falls back to laravel.log
    • Check EMERGENCY logs as clues for debugging
  4. The value of reading framework source code

    • There are problems that cannot be understood through documentation alone
    • Root causes can be identified by understanding internal implementations

📚 References


Discussion