Framework: Cant listen to illuminate.log, Event Dispatcher Should check if Object is clonable

[JFossey]

Problem Description:

I have an event listener setup to listen to the event _illuminate.log_. Everything works for normal logging using the Log interface as expected.

When an exception is thrown the page crashes rather than the normal stack trace and in nginx logs you get a "PHP message: PHP Fatal error: Trying to clone an uncloneable object of class".

After some stepping through the code I worked out that Exceptions are not clonable making the listen event illuminate.log useless.

Workaround:

Change App\Exceptions\Handler::report()

    public function report(Exception $e)
    {
        // Because the event dispatcher tries to clone any object that is a
        // parameter before passing it to the listener and Exceptions are not
        // cloneable we have to handle the Exception logging separates from the
        // event firing and only pass the message to the event dispatcher but
        // the full Exception to Logger.
        if ($this->shouldReport($e)) {
            // Fire Event
            if ($dispatcher = $this->log->getEventDispatcher()) {
                $level = 'error';
                $message = $e->getMessage();
                $context = [];
                $dispatcher->fire('illuminate.log', compact('level', 'message', 'context'));
            }
            // Log Exception
            if ($log = $this->log->getMonolog()) {
                $log->{$level}($e, []);
            }
        }
    }

Suggested fix:

Change Illuminate\Events\Dispatcher::cloneArgumentsForQueueing() to use the reflectionclass::iscloneable() method, keeping in mind the Exceptions also cant seem to be serializabe either and createQueuedHandlerCallable() serializes the event arguments.

    protected function cloneArgumentsForQueueing(array $arguments)
    {
        return array_map(function ($a) {
            if (is_object($a)) {
                $reflection = new ReflectionClass($a);
                if ($reflection->isCloneable()) {
                    return clone $a;
                }
                else {
                    return (string)$a;
                }
            }
            return $a;
        }, $arguments);
    }

Additional

By converting any argument that is not clonable there could be other unforeseen consequence.

Any listener listening to _illuminate.log_ will get a full stack trace in string format rather than just the message.

[GrahamCampbell]

This is a bug in your code.

[GrahamCampbell]

The framework makes no assumptions you want to serialize something.

[JFossey]

@GrahamCampbell - I think you were a little quick to dismiss this issue and I would like to reopen this issue.

I am not the one serializing anything, the Laravel Event Dispatcher is using both the clone and serialize functions when a Listener implements the ShouldQueue interface causing the Listener and the all its arguments to be cloned and serialized and if one of those arguments is an object that is not clonable or serializable like an Exception or a Closure then everything crashes causing a fatal error.

How to reproduce from a fresh empty install of Laravel

1. Create a test case by adding a route with a simple Exception

Route::get('/', function () {
    throw new Exception('Event testing...');
    return view('welcome');
});

2. Add a listener that does nothing but implements the ShouldQueue interface

<?php

namespace App\Listeners;

use Illuminate\Contracts\Queue\ShouldQueue;

class LogTesting implements ShouldQueue
{
    public function handle()
    {
        // Do nothing
    }
}

3. Add the listener to _App\Providers\EventServiceProvider_ for the event _illuminate.log_

    protected $listen = [
        'illuminate.log' => [
            'App\Listeners\LogTesting',
        ],
    ];

4. Run $ artisan clear-compiled

Description of the problem

The problem only takes place when two conditions are meet:

1. Listener is setup that gets queued by implementing the _Illuminate\Contracts\Queue\ShouldQueue_ interface.
2. Listner is setup to listen to _illuminate.log_ or any other event that will pass arguments that are not clone able or serializable.

Laravel code triggering the errors in _Illuminate\Events\Dispatcher_

1. createClassCallable() is called to create the listener with agreements as a callback.
2. handlerShouldBeQueued() is called to check if listener should be queued.
3. If true, createQueuedHandlerCallable() is called that first clones all arguments that are objects using the cloneArgumentsForQueueing() method and then if a queue method does not exist then the default handling is called and the arguments are serialized.

    protected function createClassCallable($listener, $container)
    {
        list($class, $method) = $this->parseClassCallable($listener);

        if ($this->handlerShouldBeQueued($class)) {
            return $this->createQueuedHandlerCallable($class, $method);
        } else {
            return [$container->make($class), $method];
        }
    }

    protected function createQueuedHandlerCallable($class, $method)
    {
        return function () use ($class, $method) {
            $arguments = $this->cloneArgumentsForQueueing(func_get_args());

            if (method_exists($class, 'queue')) {
                $this->callQueueMethodOnHandler($class, $method, $arguments);
            } else {
                $this->resolveQueue()->push('Illuminate\Events\CallQueuedHandler@call', [
                    'class' => $class, 'method' => $method, 'data' => serialize($arguments),
                ]);
            }
        };
    }

    protected function cloneArgumentsForQueueing(array $arguments)
    {
        return array_map(function ($a) {
            return is_object($a) ? clone $a : $a;
        }, $arguments);
    }

Workaround

My original workaround still applies.

Suggested fix

I changed my mind on my suggested fix and I think the event dispatcher should be left to error, and I think the log writer should be updated to not pass an Exception object but rather just the error message.

    protected function fireLogEvent($level, $message, array $context = [])
    {
        // If the event dispatcher is set, we will pass along the parameters to the
        // log listeners. These are useful for building profilers or other tools
        // that aggregate all of the log messages for a given "request" cycle.
        if (isset($this->dispatcher)) {
-            $this->dispatcher->fire('illuminate.log', compact('level', 'message', 'context'));
+            $eventMessage = is_object($message) && $message instanceof \Exception ? $message->getMessage() : $message;
+            $this->dispatcher->fire('illuminate.log', compact('level', 'eventMessage', 'context'));
        }
    }

[GrahamCampbell]

This is a not a framework bug. Your code is just broken. You cannot have queued handlers for such things.

[JFossey]

@GrahamCampbell
How is my code broken, are you even reading my issue description or supplied code. I am using a documented feature in the form of Queued Event Listeners to listen to a existing framework event _illuminate.log_, doing something that is even suggested in the documentation in comments. The only problem is that the Laravel writer that fires the event is not checking the arguments it is passing through.

Quote from the Laravel Writer:

If the event dispatcher is set, we will pass along the parameters to the
log listeners. These are useful for building profilers or other tools
that aggregate all of the log messages for a given "request" cycle.

This is a real issue and I would like you to please re-open the issue and stop dismissing it so quickly.

[JFossey]

@GrahamCampbell
I just want to know where I stand with this issue, are you ignoring my argument or evidence as to the bug or willing to discuss further. I have spent a lot of time researching this issue and providing a clear documented way of reproducing the error as well as a proposed solution.

I am happy to discuss the merits or technical correctness if the log writer should be allowed to send both text messages and Exception objects to the Event Dispatcher.