Framework: Strange behavior of emailOutputOnFailure() and runInBackground()

[izayoi256]

• Laravel Version: 5.8.23
• PHP Version: 7.2.16

Steps To Reproduce:

        $schedule
            ->command(Commands\ThrowsExceptionCommand::class)
            ->cron('* * * * *')
            ->description('foo')
            ->emailOutputOnFailure('[email protected]')
        ;

        $schedule
            ->command(Commands\DoSomethingCommand::class)
            ->cron('* * * * *')
            ->description('bar')
            ->emailOutputOnFailure('[email protected]')
        ;

        // This sends an email to [email protected] with exception.
        // This is an correct behavior IMO.

        $schedule
            ->command(Commands\ThrowsExceptionCommand::class)
            ->cron('* * * * *')
            ->description('foo')
            ->emailOutputOnFailure('[email protected]')
            ->runInBackground() // <- New Line
        ;

        $schedule
            ->command(Commands\DoSomethingCommand::class)
            ->cron('* * * * *')
            ->description('bar')
            ->emailOutputOnFailure('[email protected]')
        ;

        // This works correctly too.

        $schedule
            ->command(Commands\ThrowsExceptionCommand::class)
            ->cron('* * * * *')
            ->description('foo')
            ->emailOutputOnFailure('[email protected]')
        ;

        $schedule
            ->command(Commands\DoSomethingCommand::class)
            ->cron('* * * * *')
            ->description('bar')
            ->emailOutputOnFailure('[email protected]')
            ->runInBackground() // <- New Line
        ;

        // Not only [email protected] receives email with exception,
        // but also [email protected] receives email with output of DoSomethingCommand.

        $schedule
            ->call(function () {echo 1;})
            ->cron('* * * * *')
            ->description('baz')
            ->emailOutputOnFailure('[email protected]')
        ;

        // This ALWAYS sends an email to [email protected] with empty body.

        $schedule
            ->call(function () {echo 1; throw new \Exception();})
            ->cron('* * * * *')
            ->description('baz')
            ->emailOutputOnFailure('[email protected]')
        ;

        $schedule
            ->call(function () {echo 1; throw new \Exception();})
            ->cron('* * * * *')
            ->description('baz')
            ->emailOutputOnFailure('[email protected]')
            ->runInBackground()
        ;

        // They work as same as the previous one.

[mfn]

Please specify exactly what the _strange behaviour_ is. You provided lots of examples but not exactly what your issue here.

Btw, I think the last example with ->call() and ->runInBackground will not work as expected: runInBackground only works with commands, not with closures.

[izayoi256]

@mfn
Thanks for your response. And I'm sorry for my lack of description.

It makes sense why ->call() won't work as I think.

Why the third one works like that? Of course the ThrowsExceptionCommand should be reported with its error detail. But the DoSomethingCommand reports its output even if it had been done without any error. Is this an expected behavior?

If so, the DoSomethingCommand in first and second ones should report too, shouldn't they?

[driesvints]

Hey @izayoi256, this is documented in the docs:

The runInBackground method may only be used when scheduling tasks via the command and exec methods.

https://laravel.com/docs/5.8/scheduling#background-tasks

[izayoi256]

@driesvints

        $schedule
            ->command(Commands\ThrowsExceptionCommand::class)
            ->cron('* * * * *')
            ->description('foo')
            ->emailOutputOnFailure('[email protected]')
        ;

        $schedule
            ->command(Commands\DoSomethingCommand::class)
            ->cron('* * * * *')
            ->description('bar')
            ->emailOutputOnFailure('[email protected]')
            ->runInBackground() // <- New Line
        ;

        // Not only [email protected] receives email with exception,
        // but also [email protected] receives email with output of DoSomethingCommand.

Isn't it when scheduling tasks via the command and exec methods?

Or are you talking about the case with ->call()? @Mfn already told me why that doesn't work.

[driesvints]

@izayoi256 that seems to be the expected behavior? What exactly are you expecting? It's not very clear from your description.

[izayoi256]

@driesvints okay give me a chance to explain again.

I want the scheduled tasks to notify me by email ONLY when each of them fails in some reason. The task with ->command()->emailOutputOnFailure() works correctly in normal usage. But ->command()->emailOutputOnFailure()->runInBackground() ALWAYS notify me even if it ends without any errors.

I thought that is a strange behavior because it emails out put not only on failure, but also on success. But if you say that is an expected behavior, I understand that.

[driesvints]

I see. I think you're right and might know why this is happening. In the runCommandInBackground method the $this->exitCode isn't being filled but that's probably because the command hasn't finished processing yet. Because the value of the exitCode property is null, it doesn't equals 0 as expected in the onFailure method. Maybe there should be a null check there as well but not sure.

[dinoqqq]

After a little bit of debugging I found out the following. Not sure how to proceed for a PR, so I would like to discuss candidate solutions here.

When the command is run in the foreground, the following statement is produced:
/usr/bin/php7.3 artisan command:DoSomethingCommand > /laravel-app/storage/logs/schedule-74b308bf8da39f8388b3b239ba18bc7c271b27ce.log 2>&1 ;

When the command is run in the background, the following statement is produced:
(/usr/bin/php7.3 artisan command:DoSomethingCommand > /laravel-app/storage/logs/schedule-74b308bf8da39f8388b3b239ba18bc7c271b27ce.log 2>&1 ; /usr/bin/php7.3 artisan schedule:finish "framework/schedule-a8e77820d46769137937f0ac105633fff1c8da80") > /dev/null 2>&1 &

The foreground statement returns simply an exit code and that is processed (in the right way).
The background statement is a bit different. The last & in the background command let the statement be run in the background and immediately accepts another statement. This is beautiful, it can execute multiple statements in parallel. The second statement /usr/bin/php7.3 artisan schedule:finish "framework/schedule-a8e77820d46769137937f0ac105633fff1c8da80") > /dev/null 2>&1 will make sure that a callback is called when the first part is executed.

The foreground function catches $this->exitCode and runs callAfterCallbacks.
The background function doesn't catch $this->exitCode and doesn't run callAfterCallbacks. Alternatively the background statement executes it second part (/usr/bin/php7.3 artisan schedule:finish ...) where the callAfterCallbacks is run. Nothing is done with the exit code, it is not set, so when the onFailure callback is executed, $this->exitCode is null. We of course, would like to have the _right exit code of the first command_.

I thought of a solution where the artisan schedule:finish command is given a second parameter {exitCode}. This will be set on the event before the callAfterCallbacks is run, so the processing of $this->exitCode would succeed.
For UNIX systems the new statement to be executed would be (see the added "$?"):
(/usr/bin/php7.3 artisan command:DoSomethingCommand > /laravel-app/storage/logs/schedule-74b308bf8da39f8388b3b239ba18bc7c271b27ce.log 2>&1 ; /usr/bin/php7.3 artisan schedule:finish "framework/schedule-a8e77820d46769137937f0ac105633fff1c8da80" "$?") > /dev/null 2>&1 &. The problem is that Windows doesn't have this and it would become a bit of a mess to make it work.

Would there be a way to run multiple statements in parallel without using the callback at all?

What do you guys think?

[dinoqqq]

@driesvints any ideas?

[driesvints]

@dinoqqq no sorry, don't have time atm to deep dive into this.

[kohkimakimoto]

I have same problem.

[kohkimakimoto]

I inspected the laravel code about this issue. I 100% agree to @dinoqqq

https://github.com/laravel/framework/issues/28992#issuecomment-513305472

I think that the above description of this issue is right, and I wrote code to fix it. See the following commit.

https://github.com/kohkimakimoto/framework/commit/dfeb4c5304599140d1307bab4ec9754303d49799

It's just a suggestion. This code worked well in my MacOS machine. Unfortunatly I don't have any Windows environment. I can't support Windows.
But I found information about %errorlevel% variable at Windows. It's like $? at Unix environment. Can we use it for this issue?

[taylorotwell]

@kohkimakimoto's idea is basically correct but as he mentioned we would need to figure out and test Windows support.

[taylorotwell]

OK I was able to test on Windows that %errorlevel% does work as expected.

[taylorotwell]

Fixed.