Scheduled Tasks should be able to output to STDOUT - currently forced to /dev/null or file

[kingIZZZY]

Laravel Version

9.29.0

PHP Version

8.1.20

Database Driver & Version

No response

Description

Scheduled Tasks seem to force output to /dev/null unless a local disk file is provided to write output to.

On Docker-based or similar deploy-code / spin-up-instances hosting services like heroku.com or fly.io etc. local files are usually ephemeral and thus local log files are quite useless.
These hosts usually offer a live scrolling app output console log that can be monitored, very useful to catch live exceptions or view logged notices/warnings etc.

It would seem very desirable and necessary to have the option to let schedule:run allow laravel Schedule Events' output to proceed on to STDOUT along with all other app output. Suppressing it to /dev/null with no option to allow it through to STDOUT seems like blocking useful options for many deployment environments.

Steps To Reproduce

• Create some Artisan commands or console kernel callback schedules
• Have these tasks/commands produce useful / informative / debugging output, whether laravel Log output, or artisan command ->line() or ->table() or whatnot
• Have these tasks/commands run as a Scheduled Task
• Never see your important output because the output has either been forced down the /dev/null chute, or into a local file that might not be there when you try to log in and read it

Some relevant links

• https://stackoverflow.com/questions/46586916/how-can-i-redirect-output-to-stdout-with-laravel-scheduler-command
• Echoing to /dev/stdout does not appear in 'docker logs' moby/moby#19616 (comment)

[kingIZZZY]

Workaround

If your laravel deployment with docker is doing things the supervisord way like my project, here's how to get commands & scheduled tasks to show up in docker container output:

• Create a named pipe (fifo) somewhere in the web directory, ex. mkfifo /path/to/laravel/storage/logs/stdout.fifo
• chown this fifo it to the web user, so commands invoked from web or web-user cron can output to it
• Add a supervisord config to simply cat /path/to/the/fifo. It will literally continuously follow the fifo waiting for data and simply outputting to its stdout which goes to container stdout. Edit: OK no it will cat once when there's some data and then exit. So just put it in a 1-liner while true; do cat /path/to/the/fifo; sleep 1; done loop for good measure
• Have artisan commands output to the fifo. ex. $schedule->command('dosomething:foo --option=1')->sendOutputTo(storage_path('logs/stdout.fifo'))

[willrowe]

@kingIZZZY you could use tail instead of cat: tail --follow --lines=0 --quiet /path/to/the/fifo

[5n00p4eg]

Totally agree with the proposal. Current implementation breaks 12-factor methodology.

[henzeb]

While I think it's a good thing it's directed to a file or /dev/null by default, I too think we should be able to direct it to anywhere we want it too. Not just files or stdout...

[malsatin]

Previously that issue was mentioned in #38429
And discussion appeared in laravel/ideas#126

Also, one of the solutions is to extend comand description like

$schedule->command(TestLogCommand::class)->everyMinute()->thenWithOutput(function (Stringable $output) {
    echo $output;
});

[kingIZZZY]

I don't believe this solution works (I might even have tried it)
echo just outputs to the forced hardcoded /dev/null no?

Or maybe I misunderstand what you mean by "solution to extend command description like ..."

[malsatin]

echo just outputs to the forced hardcoded /dev/null no?

No, it writes to something like /dev/stdout, that is default PHP behavior.

The reason, why current Laravel logger implementation writes logs either to /dev/null or to the specified file is not because Laravel overwrites standard PHP echo target from /dev/stdout to dev/null, but because Laravel don't try to echo the log line and they write the file directly to some file.

By adding thenWithOutput you force Laravel handler to provide you all log lines and you can then write them to stdout by yourself.
In our case it works as expected and solves the issue (although not in the most elegant way).

[kingIZZZY]

No I don't think that's correct... whatever you do with thenWithOutput ends up being redirected to either /dev/null or to the supplied file path, blocked from outputting to PHP standard output.

[malsatin]

Can you provide examples, which variants of thenWithOutput usage have you tried and to what results it led to?

We use the solution, provided in the comment in production and right now it works fine.
More particular example may be (this is a piece of code from my current project):

protected function schedule(Schedule $schedule): void
{
    $showOutput = static function (Stringable $output): void {
        echo $output;
    };
    $schedule->command(RotateStorefrontsCommand::class)->everyTenMinutes()->thenWithOutput($showOutput);
}

[phpguru]

This is a challenge to understand when deploying to k8s - my schedule:run is on its own pod, but the commands its running don't log output because

php artisan schedule:run

becomes

  2023-09-20 16:15:00 Running ['artisan' app:my-command] . 142ms DONE
  ⇂ '/usr/local/bin/php' 'artisan' app:my-command > '/dev/null' 2>&1

so Datadog and K8s have no way to get the command's logs.

[ghost]

Run in background scheduled task is not compatible with stdout logging in laravel. See #50085 (comment)

[p1ratrulezzz]

Instead of building a bicycle with macroses I've ended up using the patch for laravel/framework

scheduler_dont_truncate_output.patch

--- a/src/Illuminate/Console/Scheduling/CommandBuilder.php
+++ b/src/Illuminate/Console/Scheduling/CommandBuilder.php
@@ -33,7 +33,7 @@
         $output = ProcessUtils::escapeArgument($event->output);

         return $this->ensureCorrectUser(
-            $event, $event->command.($event->shouldAppendOutput ? ' >> ' : ' > ').$output.' 2>&1'
+            $event, $event->command.' 2>&1'
         );
     }

@@ -56,7 +56,7 @@
         }

         return $this->ensureCorrectUser($event,
-            '('.$event->command.$redirect.$output.' 2>&1 ; '.$finished.' "$?") > '
+            '('.$event->command.' 2>&1 ; '.$finished.' "$?") > '
             .ProcessUtils::escapeArgument($event->getDefaultOutput()).' 2>&1 &'
         );
     }

--- a/src/Illuminate/Console/Scheduling/ScheduleRunCommand.php
+++ b/src/Illuminate/Console/Scheduling/ScheduleRunCommand.php
@@ -132,6 +132,8 @@
             }

             $this->eventsRan = true;
+
+            $this->handleEventOutput($event);
         }

         if ($events->contains->isRepeatable()) {
@@ -145,6 +147,18 @@
         }
     }

+    protected function handleEventOutput(Event $event): void
+    {
+        if (!empty($event->outputBufferStdout)) {
+            $this->components->info($event->outputBufferStdout);
+            $this->newLine();
+        }
+
+        if (!empty($event->outputBufferStderr)) {
+            $this->components->error($event->outputBufferStderr);
+        }
+    }
+
     /**
      * Run the given single server event.
      *
@@ -252,6 +266,8 @@
                 }

                 $this->eventsRan = true;
+
+                $this->handleEventOutput($event);
             }

             Sleep::usleep(100000);

--- a/src/Illuminate/Console/Scheduling/Event.php
+++ b/src/Illuminate/Console/Scheduling/Event.php
@@ -128,6 +128,16 @@
      */
     public $shouldAppendOutput = false;

+    /**
+     * @var string The output buffer for stdout.
+     */
+    public $outputBufferStdout = '';
+
+    /**
+     * @var string The output buffer for stderr.
+     */
+    public $outputBufferStderr = '';
+
     /**
      * The array of callbacks to be run before the event is started.
      *
@@ -289,7 +299,13 @@
     {
         return Process::fromShellCommandline(
             $this->buildCommand(), base_path(), null, null, null
-        )->run();
+        )->run(function($type, $buffer) {
+            if ($type === Process::ERR) {
+                $this->outputBufferStderr .= $buffer;
+            } else {
+                $this->outputBufferStdout .= $buffer;
+            }
+        });
     }

     /**

To add patch automatically while composer install I've used the composer package cweagans/composer-patches

Here is my patch definition in

composer.json

  ...
 "extra": {
        "laravel": {
            "dont-discover": []
        },
        "patches": {
            "laravel/framework": {
                "scheduler_dont_truncate_output": "./patches/scheduler_dont_truncate_output.patch"
            }
        },
        "enable-patching": true
    },

 ...

Maybe only stdout matter since it used 2>&1 directive. But I hope this might help someone.

The scheduler run command is really stupidly written. Logging to a file breaks 12factor app conseption. I hope in a newer version of the framework something good will be done with it.

[macropay-solutions]

@p1ratrulezzz we also had this issue and we adopted this solution #50085 (comment) because even if we don't send them to /dev/null, the stdout is not catching anything.

Is your solution bringing something new (you managed to print to stdout from a bg proc_open process) or just the patch vs macros?

[abodnar]

Looks like whoever was working on Laravel Cloud realized that people might want to actually see the output from commands. So they made this change.

framework/src/Illuminate/Console/Scheduling/Event.php

Lines 198 to 207 in 94c2696

	protected function execute($container)
	{
	return Process::fromShellCommandline(
	$this->buildCommand(), base_path(), null, null, null
	)->run(
	laravel_cloud()
	? fn ($type, $line) => fwrite($type === 'out' ? STDOUT : STDERR, $line)
	: fn () => true
	);
	}

Now I get that sometimes it takes encountering the situation yourself to realize that the way it is set up, doesn't work. But tying this to only for Laravel Cloud seems like a very narrow solution and really should be broadened to support those that are running Laravel in other environments.

[macropay-solutions]

Very interesting.
So Laravel is stepping on nextJs's footprints like Vercel. #55533

[davidharting]

Agreed that this is odd, but I'm assuming good intent here.

I hope to see this as a generic configuration option in the near future. Every containerized environment I've worked in wanted logs for everything to stdout to get picked up by a log ingestion process.

[macropay-solutions]

Update for laravel 9-12 https://medium.com/p/06d5db84f6e6

[phpguru]

whoever was working on Laravel Cloud

It was @taylorotwell in #53623 actually, and from the looks of it, simply setting LARAVEL_CLOUD=1 in your environment would start spewing logs from job runners to STDOUT, if I am reading that right.

Now the question is, can we format all the output as JSON or are we still forced to get unstructured text intermixed in them?

[abodnar]

Yeah, I don't remember why I didn't write Taylor. Might have been cause I wasn't sure if it was him just merging the code or if he had implemented it.

It does seem like that's all you would need to do. I haven't had a chance to test it out.

I would imagine that if output wasn't coming through fully as JSON then there might be additional changes? 🤷