Flushing buffers on request about monolog

[Seldaek]

If you want the email to be sent when the error occurs, use a fingerscrossed handler insteead without a buffer handler. That way you get the mail sent whenever you get an error, there is a constructor option in fingerscrossed to start buffering again (set $stopBuffering to false).

[Seldaek]

You can obviously call ->close() on them manually to trigger the flush. If you do it at the end of your script this should be safe enough. An alternative/more generic way would be to get the logger and do:

while ($logger->popHandler()) {}

That should ideally lose all refs to the handlers, triggering a destruct/GC of the objects. For more safety you can check whether the current handler is a BufferHandler and close it if it is.

Is this workable or did you envision something else?

[vmattila]

Well, ->close() approach seems to suit my needs at Handler level (should have checked out the code before my question).

Anyway, I am not sure about the semantics of close(). Is it supposed that I can still continue using the handler object after close() is called?

I was thinking something like $logger->flush() that in turn calls each handler's close()... or maybe something more complex like FlushableHandlerInterface and flush() function in handlers that support intermediate flush()... In any case, I think that this logic be at Logger level, so application can just request flushing the logs without need to know what handlers are behind.

[Seldaek]

The thing is that with email handlers, you really should send only one mail. In theory after close() you shouldn't use the handler, and some of them won't be usable after but it's not really enforced. Anyway a flush() on the logger is a bit strange because the only handler that needs flushing is the BufferHandler. The FingersCrossedHandler is the only other one that buffers, but while it buffers it's not one you want to trigger on flush().

[sandvige]

This feature would also help to reduce the log size when crashing while processing a huge batch. Flushing at the end of a cycle, or define a check point at the start of a cycle could remove buffered logs, unrelated with the next cycle.

[Seldaek]

@sandvige I think what you want there is rather a clear() method on the BufferHandler and not a flush?

[sandvige]

Indeed :)

[vmattila]

I started to re-think my original issue and well, flush() might not be something that is really needed. I originally thought something like in long-running CLI process, we could with flush() call ensure that email logs are sent even the process itself is not ended (and handlers closed):

    $logger = $this->get('logger'); // Symfony2 style
    while (true) {
        // (...)
        if ($success) {
            $logger->info('Task iteration succeeded.');
        } else {
            $logger->err('Task iteration failed.');
            $logger->flush(); // To ensure that possible email handlers are triggered immediately
        }
    }

In the example above, the process continues after an erroneous situation. Without flush(), emails are not sent before the whole process ends.

Even that was my original idea, I find it problematic. The buffers are never flushed if the worker keeps running without errors, with a nice memory leak as a consequence. Maybe a better setup would be:

    $workerLogger = $this->get('logger'); // Symfony2 style
    while (true) {
        $iterationLogger = new Monolog(); // via service definition with ready handler stack
        // (...)
        if ($success) {
            $iterationLogger->info('Task iteration succeeded.');
        } else {
            $iterationLogger ->err('Task iteration failed.');
        }
        $iterationLogger->close();
    }

In this way, the iteration logs are flushed at the end of each iteration.

[Seldaek]

I think that #120 might actually be a good solution for this.. You would set a limit on the buffer handler, and a new option to flush when it's full, then whenever the memory usage hits a threshold, the buffer is flushed, and then starts filling up again.

[vmattila]

Yes, that solves the memory leak problem very well.

But still, in the "email me if error happens" setup (with FingersCrossedHandler, BufferedHandler and SwiftHandler) the original problem persists. The email message is not sent when the error occurs but after the logger is closed (never in my example code #1).

[benjamindulau]

@Seldaek setting stopBuffering to either true or false does not seem to have an effect when having a long-running process. We use Rollbar for logging and when running queue consumers (infinite loop) we absolutely need to get errors on Rollbar as soon as they occur. I just can't make it work like I want. Errors are sent when I end the CLI

Do you have any recommandation?

[benjamindulau]

With some more digging I found out that because of the way it is implemented their is no way to properly force a close(). (due to register_shutdown_function(array($this, 'close'));)

We could have an option on buffered handlers so they always close() the wrapped handler every time they activate, but I'm not sure you'd want something like that.

For now, I manually invoke close on the RollbarHandler at every loop iteration.