starred/monolog

Fork 0

mirror of https://github.com/Seldaek/monolog.git synced 2026-04-27 08:35:53 +03:00

[GH-ISSUE #794] RotatingFileHandler fails to call rotate() when used in a short-lived process #303

New issue

Closed

opened 2026-03-04 02:13:57 +03:00 by kerem · 5 comments

kerem commented

2026-03-04 02:13:57 +03:00

Owner

Originally created by @mberkowski on GitHub (May 23, 2016).
Original GitHub issue: https://github.com/Seldaek/monolog/issues/794

When integrating Monolog into a Drupal site on Apache/mod_php, we found that RotatingFileHandler fails to call rotate() in its GC routine. New date-stamped logfiles are created, but old ones never disposed. This seems due to the fact that RotatingFileHandler::$nextRotation is initialized to tomorrow's date, and later compared less than the logged item's date stamp.

In a short-lived process like an HTTP request under mod_php the initialized nextRotation will always be greater than the logged item's timestamp preventing RotatingFileHandler::close() and consequently RotatingFileHandler::rotate() from being called when depending on this implicit call to close().

In RotatingFileHandlerTest::testRotation(), an explicit call is made to $handler->close() causing the garbage collection to take place and test to pass. An explicit call to RotatingFileHandler::close() is therefore a possible workaround.

github.com/Seldaek/monolog@6d2cfa63c9/src/Monolog/Handler/RotatingFileHandler.php (L47-L53)

public function __construct($filename, $maxFiles = 0, $level = Logger::DEBUG, $bubble = true, $filePermission = null, $useLocking = false)
{
    $this->filename = $filename;
    $this->maxFiles = (int) $maxFiles;

    // nextRotation is always tomorrow's date
    $this->nextRotation = new \DateTime('tomorrow');
    $this->filenameFormat = '{filename}-{date}';

github.com/Seldaek/monolog@6d2cfa63c9/src/Monolog/Handler/RotatingFileHandler.php (L100-L103)

// This condition is probably never true
if ($this->nextRotation < $record['datetime']) {
    $this->mustRotate = true;
    $this->close();
}

Originally created by @mberkowski on GitHub (May 23, 2016). Original GitHub issue: https://github.com/Seldaek/monolog/issues/794 When integrating Monolog into a Drupal site on Apache/mod_php, we found that RotatingFileHandler fails to call `rotate()` in its GC routine. New date-stamped logfiles are created, but old ones never disposed. This seems due to the fact that `RotatingFileHandler::$nextRotation` is initialized to tomorrow's date, and later compared less than the logged item's date stamp. In a short-lived process like an HTTP request under mod_php the initialized `nextRotation` will always be greater than the logged item's timestamp preventing `RotatingFileHandler::close()` and consequently `RotatingFileHandler::rotate()` from being called when depending on this implicit call to `close()`. In `RotatingFileHandlerTest::testRotation()`, an explicit call is made to `$handler->close()` causing the garbage collection to take place and test to pass. An explicit call to `RotatingFileHandler::close()` is therefore a possible workaround. https://github.com/Seldaek/monolog/blob/6d2cfa63c9d7c03abd1284c2c4e8a9b310cd5062/src/Monolog/Handler/RotatingFileHandler.php#L47-L53 ``` php public function __construct($filename, $maxFiles = 0, $level = Logger::DEBUG, $bubble = true, $filePermission = null, $useLocking = false) { $this->filename = $filename; $this->maxFiles = (int) $maxFiles; // nextRotation is always tomorrow's date $this->nextRotation = new \DateTime('tomorrow'); $this->filenameFormat = '{filename}-{date}'; ``` https://github.com/Seldaek/monolog/blob/6d2cfa63c9d7c03abd1284c2c4e8a9b310cd5062/src/Monolog/Handler/RotatingFileHandler.php#L100-L103 ``` php // This condition is probably never true if ($this->nextRotation < $record['datetime']) { $this->mustRotate = true; $this->close(); } ```

kerem closed this issue

2026-03-04 02:13:58 +03:00

kerem commented

2026-03-04 02:13:58 +03:00

Author

Owner

@Seldaek commented on GitHub (May 26, 2016):

Normally all handler's close method is called by __destruct, so I am not sure why you don't get a rotation triggered?

@Seldaek commented on GitHub (May 26, 2016): Normally all handler's close method is called by __destruct, so I am not sure why you don't get a rotation triggered?

kerem commented

2026-03-04 02:13:58 +03:00

Author

Owner

@mberkowski commented on GitHub (May 26, 2016):

Yes, I see that way up in Monolog\Handler\Handler::__destruct(). My guess is that since it's inside Drupal, any number of things could be interfering with normal shutdown & GC to prevent __destruct() executing. I find that if I comment out the explicit close() in the test but still explicitly unset($handler) the test passes because __destruct() cleans up. So Monolog is probably working as intended.

@mberkowski commented on GitHub (May 26, 2016): Yes, I see that way up in `Monolog\Handler\Handler::__destruct()`. My guess is that since it's inside Drupal, any number of things could be interfering with normal shutdown & GC to prevent `__destruct()` executing. I find that if I comment out the explicit `close()` in the test but still explicitly `unset($handler)` the test passes because `__destruct()` cleans up. So Monolog is probably working as intended.

kerem commented

2026-03-04 02:13:59 +03:00

Author

Owner

@Seldaek commented on GitHub (May 26, 2016):

Yup I am pretty sure this works, but I'm quite curious to see what interferes with that in Drupal..

@Seldaek commented on GitHub (May 26, 2016): Yup I am pretty sure this works, but I'm quite curious to see what interferes with that in Drupal..

kerem commented

2026-03-04 02:13:59 +03:00

Author

Owner

@mberkowski commented on GitHub (May 27, 2016):

This turned out to be due to a strange set of local circumstances and a faulty directory ACL I might have discovered sooner had I noticed the base class __destruct() calling close(). Apologies for the noise.

@mberkowski commented on GitHub (May 27, 2016): This turned out to be due to a strange set of local circumstances and a faulty directory ACL I might have discovered sooner had I noticed the base class `__destruct()` calling `close()`. Apologies for the noise.

kerem commented

2026-03-04 02:13:59 +03:00

Author

Owner

@attisan commented on GitHub (Nov 8, 2018):

sorry for excavating this issue, but I'm experiencing a very similar behaviour with monolog and drupal 8 using RotatingFileHandler. Although close() gets called, $this->mustRotate is either NULL or FALSE for the same reasons as @mberkowski described.

As a result the check if (true === $this->mustRotate) { in close() gates off $this->rotate();.

@attisan commented on GitHub (Nov 8, 2018): sorry for excavating this issue, but I'm experiencing a very similar behaviour with monolog and drupal 8 using RotatingFileHandler. Although `close()` gets called, `$this->mustRotate` is either `NULL` or `FALSE` for the same reasons as @mberkowski described. As a result the check `if (true === $this->mustRotate) {` in `close()` gates off `$this->rotate();`.

kerem referenced this issue

2026-03-04 03:04:40 +03:00

[PR #303] [MERGED] Add BrowserConsoleHandler #1067