Still issues with logging and loop on exceptions

[Bhoft]

Hi trntv
as mentioned in #12 id had issues with the log in queued background commands. The log was either only flushed after the default exportInterval of 1000.

And you have fixed it.
But this is still not working correctly or to be correct only works if the log target has set it´s exportInterval to 1 to export after each log.

Otherwise it also won't be exported directly.

I would prefer a function in the LoggingMiddleware which does the log and flush with final = true

    public function log($message, $level = null, $category = null)
    {
        // set default level if level isn't set
        if (!$level) {
            $level = $this->level;
        }

        // set default category if level isn't set
        if (!$category) {
            $category = $this->category;
        }

        // log
        $this->logger->log($message, $level, $category);

        // force with final = true so export is done afterwards
        if ($this->forceFlush) {
            $this->logger->flush($final = true);
        }
    }

    public function execute($command, callable $next)
    {
        $class = get_class($command);
        $this->log("Command execution started: {$class}", Logger::LEVEL_INFO);
        $result = $next($command);
        $this->log("Command execution ended: {$class}", Logger::LEVEL_INFO);
        return $result;
    }

With this code the log is done directly if forceFlush is set to true.
So at the start and end of a command the log is correctly exported.

My only problem is now I also wanted to have the log mechanism inside of the command.

I wanted to create a "live-log" to see which emails are already been sent out.

It would be cool if the running command could somehow call
$this->log("whatever") and it is automatically also exported to the log with the correct category through the LoggingMiddleware.
This was also why I have created a log function in the middleware.

Is it somehow possible to get to the LoggingMiddleware object from the Command and use the log function?

Also if I wanted to get all information of e.g. occurred errors of the QueueBusController those errors are only logged to the console output.
e.g. on actionListen console::error is used instead of log also to the Yii logger with Yii::error.

As far as i see it is also not possible to pause or abort a running background command by setting some flags.

Do you remember this issue #5 ?
There I wanted to log the onError, onSuccess etc. messages.

I still have the problem if my comand does this

  Yii::error('I am an error', 'command-bus');
  return false;

The console still outputs

Listening queue "some-queue-name"
New job ID#71
Job ID#71 was deleted from queue
Job ID#71 has been successfully done

and my Log from my LogginMiddleware

2016-09-08 15:20:54 [console][][info][command-bus] Command execution started: common\commands\SendQueuedEmailsCommand
2016-09-08 15:20:54 [console][][error][command-bus] i am an error
2016-09-08 15:20:54 [console][][info][command-bus] Command execution ended: common\commands\SendQueuedEmailsCommand

So I won't see that there was an error in my command "return was false" in the log created by LogginMiddleware.

And what`s more problematic if somehow a exception is throwed in the QueuedCommand (or the functions called) the command will be running in a loop and won't stop.
Just call in an QueuedCommand

 throw new Exception("Error Processing Request", 1);

And the process not ended or the command aborted.
I guess this is some issue in the CommandBus::createMiddlewareChain and could be fixed like below.

 protected function createMiddlewareChain($command, array $middlewareList) {

        $lastCallable = $this->createHandlerCallable($command);

        while ($middleware = array_pop($middlewareList)) {
            if (!$middleware instanceof Middleware) {
                throw new InvalidConfigException;
            }
            $lastCallable = function ($command) use ($middleware, $lastCallable) {
                try {
                    return $middleware->execute($command, $lastCallable);
                } catch (\Exception $e) {
                    yii\helpers\Console::error("Exception: ".$e->getMessage());
                    Yii::error("Exception: ".$e->getMessage(), 'command-bus');
                    Yii::getLogger()->flush($final = true);
                }
                //return $middleware->execute($command, $lastCallable);
            };
        }
        return $lastCallable;
    }

Also here it would be better if the LogginMiddleware could be called directly to directly flush the error message to the logs.

So why could the commandbus not log directly so he could log the on start/end/error/abort directly and the command should also be able to call this log function somehow through a reference to the commandbus.