sleep not working in horizon queue?

[ellermister]

Horizon Version

5.30.2

Laravel Version

10.10

PHP Version

8.2.22

Redis Driver

PhpRedis

Redis Version

6.0.2

Database Driver & Version

No response

Description

sleep 30s, actually executed in 2s.(many times)
sleep is invalid in horizon, but normal in queue:work.

Steps To Reproduce

TestLongTimeJob.php

<?php

namespace App\Jobs;

use Illuminate\Bus\Queueable;
use Illuminate\Contracts\Queue\ShouldQueue;
use Illuminate\Foundation\Bus\Dispatchable;
use Illuminate\Queue\InteractsWithQueue;
use Illuminate\Queue\SerializesModels;
use Illuminate\Support\Sleep;
use Log;

class TestLongTimeJob implements ShouldQueue
{
    use Dispatchable, InteractsWithQueue, Queueable, SerializesModels;

    /**
     * Create a new job instance.
     */
    public function __construct(public $type = 'default')
    {
    }

    /**
     * Execute the job.
     */
    public function handle(): void
    {
        Log::info('TestLongTimeJob start ' . $this->type);
        echo "TestLongTimeJob start " . $this->type . "\n";

        if ($this->type == 'default') {
            sleep(30);
        } else if ($this->type == 'redis') {
            redis()->blpop('test', 30);
        }

        echo 'TestLongTimeJob end ' . $this->type;
        Log::info('TestLongTimeJob end ' . $this->type);
    }
}

TestJob.php

<?php

namespace App\Console\Commands;

use App\Jobs\TestLongTimeJob;
use Illuminate\Console\Command;

class TestJob extends Command
{
    /**
     * The name and signature of the console command.
     *
     * @var string
     */
    protected $signature = 'test:job {type}';

    /**
     * The console command description.
     *
     * @var string
     */
    protected $description = 'Command description';

    /**
     * Execute the console command.
     */
    public function handle()
    {
        dispatch(new TestLongTimeJob($this->argument('type')));
    }
}

terminal 1, start horizon

php artisan horizon

terminal 2, dispatch sleep job, simulate long tasks.

php artisan test:job default
...

test output 1

root@1dbba1977a4d:/workspaces# php artisan horizon

   INFO  Horizon started successfully.  

  2025-01-22 14:26:04 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start default
TestLongTimeJob end default  2025-01-22 14:26:09 App\Jobs\TestLongTimeJob ....................... 5s DONE
^[[D^[[D^C

   INFO  Shutting down.  

root@1dbba1977a4d:/workspaces# php artisan horizon

   INFO  Horizon started successfully.  

  2025-01-22 14:26:22 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start default
TestLongTimeJob end default  2025-01-22 14:26:52 App\Jobs\TestLongTimeJob ...................... 30s DONE

^C

   INFO  Shutting down.  

root@1dbba1977a4d:/workspaces# php artisan horizon

   INFO  Horizon started successfully.  

  2025-01-22 14:27:09 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start default
TestLongTimeJob end default  2025-01-22 14:27:39 App\Jobs\TestLongTimeJob ...................... 30s DONE

  2025-01-22 14:27:45 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start default
TestLongTimeJob end default  2025-01-22 14:28:15 App\Jobs\TestLongTimeJob ...................... 30s DONE
  2025-01-22 14:28:21 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start default
TestLongTimeJob end default  2025-01-22 14:28:23 App\Jobs\TestLongTimeJob ....................... 2s DONE
  2025-01-22 14:28:30 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start default
TestLongTimeJob end default  2025-01-22 14:29:00 App\Jobs\TestLongTimeJob ...................... 30s DONE
  2025-01-22 14:30:42 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start default
TestLongTimeJob end default  2025-01-22 14:30:44 App\Jobs\TestLongTimeJob ....................... 1s DONE
  2025-01-22 14:30:52 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start default
TestLongTimeJob end default  2025-01-22 14:31:22 App\Jobs\TestLongTimeJob ...................... 30s DONE
^C

   INFO  Shutting down.  

test output 2

root@1dbba1977a4d:/workspaces# php artisan horizon

   INFO  Horizon started successfully.  

  2025-01-22 14:39:40 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start default
TestLongTimeJob end default  2025-01-22 14:39:42 App\Jobs\TestLongTimeJob ....................... 2s DONE
  2025-01-22 14:39:49 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start default
TestLongTimeJob end default  2025-01-22 14:39:51 App\Jobs\TestLongTimeJob ....................... 2s DONE
  2025-01-22 14:39:58 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start default
TestLongTimeJob end default  2025-01-22 14:40:00 App\Jobs\TestLongTimeJob ....................... 2s DONE
  2025-01-22 14:40:07 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start default
TestLongTimeJob end default  2025-01-22 14:40:37 App\Jobs\TestLongTimeJob ...................... 30s DONE
  2025-01-22 14:40:43 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start default
TestLongTimeJob end default  2025-01-22 14:41:13 App\Jobs\TestLongTimeJob ...................... 30s DONE
^C

   INFO  Shutting down.  

[crynobone]

Hey there, thanks for reporting this issue.

We'll need more info and/or code to debug this further. Can you please create a repository with the command below, commit the code that reproduces the issue as one separate commit on the main/master branch and share the repository here?

Please make sure that you have the latest version of the Laravel installer in order to run this command. Please also make sure you have both Git & the GitHub CLI tool properly set up.

laravel new bug-report --github="--public"

Do not amend and create a separate commit with your custom changes. After you've posted the repository, we'll try to reproduce the issue.

Thanks!

[ellermister]

@crynobone
code repository >
https://github.com/ellermister/laravel-horizon-bug-report-sleep

latest recurrence output, the problem is still there.

root@1dbba1977a4d:/workspaces/test-horizon/bug-report# php artisan horizon

   INFO  Horizon started successfully.  

  2025-01-22 07:44:15 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start 
TestLongTimeJob end   2025-01-22 07:44:45 App\Jobs\TestLongTimeJob ...................... 30s DONE
  2025-01-22 07:44:51 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start 
TestLongTimeJob end   2025-01-22 07:44:53 App\Jobs\TestLongTimeJob ....................... 2s DONE
  2025-01-22 07:45:03 App\Jobs\TestLongTimeJob ....................... RUNNING
TestLongTimeJob start 
TestLongTimeJob end   2025-01-22 07:45:33 App\Jobs\TestLongTimeJob ...................... 30s DONE
^C

   INFO  Shutting down.  

.env (only modified areas)

QUEUE_CONNECTION=redis
REDIS_HOST=192.168.1.220
REDIS_PASSWORD=null
REDIS_PORT=6379
REDIS_DB=1

php -m

php -m
[PHP Modules]
Core
ctype
curl
date
dom
fileinfo
filter
gd
hash
iconv
imagick
json
libxml
mbstring
mysqlnd
openssl
pcntl
pcre
PDO
pdo_mysql
pdo_sqlite
Phar
posix
random
readline
redis
Reflection
session
SimpleXML
sockets
sodium
SPL
sqlite3
standard
tokenizer
xml
xmlreader
xmlwriter
zlib

[Zend Modules]

php -v

PHP 8.2.22 (cli) (built: Aug 13 2024 02:22:25) (ZTS)
Copyright (c) The PHP Group
Zend Engine v4.2.22, Copyright (c) Zend Technologies

I'm running in docker.