Job run failing. connection timeout

[gentges]

Every time I start my server the job that is supposed to start immediately is failing with the error:
[ ERROR ] Job run failed: RedisConnectionPoolError(baseError: RediStack.RedisConnectionPoolError.BaseError.timedOutWaitingForConnection) (Queues/QueuesCommand.swift:122)

When I enable debug logging the error is surrounded by endless messages like this one:

[ DEBUG ] sending command [rdstk_args: [vapor_queues[default], vapor_queues[default]-processing], rdstk_command: RPOPLPUSH, rdstk_conn_id: 65F8B004-C293-4D82-A169-00A743F90973, rdstk_conpool_id: 7CEE7851-B2D5-4633-A7CD-EB562023F067] (RediStack/RedisConnection.swift:245)
[ DEBUG ] sending command [rdstk_args: [vapor_queues[default], vapor_queues[default]-processing], rdstk_command: RPOPLPUSH, rdstk_conn_id: 5048909A-DB80-4824-BAF5-D2CA120C4541, rdstk_conpool_id: 7CEE7851-B2D5-4633-A7CD-EB562023F067] (RediStack/RedisConnection.swift:245)
[ DEBUG ] command succeeded [rdstk_conn_id: 5048909A-DB80-4824-BAF5-D2CA120C4541, rdstk_conpool_id: 7CEE7851-B2D5-4633-A7CD-EB562023F067, rdstk_result: NULL] (RediStack/RedisConnection.swift:272)

I initialised queues like this:

let redisConf = try RedisConfiguration(
    hostname: Environment.get("REDIS_HOST") ?? "localhost",
    port: Environment.get("REDIS_PORT").flatMap(Int.init(_:)) ?? RedisConnection.Configuration.defaultPort,
    password: app.getSecret(with: "REDIS").wait(),
    database: Environment.get("REDIS_DB").flatMap(Int.init(_:))
)
app.queues.use(.redis(redisConf))

Afterwards I added my jobs and then dispatched one job that should start immediately at the end of my configure.swift file:

try app.queues.queue.dispatch(SomeJob.self, .init()).wait()

Has anyone an idea why the job is failing or what the error means exactly?

Environment

• Vapor Framework version: 4.53.0

• Vapor Toolbox version: 18.3.3

• OS version: MacOS 12.1

• Redis: 5.0.5

• Queues: 1.8.1

• Queues Redis Driver: 1.0.3

[jdmcd]

Hi @macintosh-HD! This error means that the server cannot access your Redis host. Please ensure that you have allowed your server's IP through the Redis firewall.

[gentges]

Hey @jdmcd thanks for the fast response.
I was running Redis locally on my Mac. I installed it with brew. Shouldn't Redis always allow localhost traffic?

[jdmcd]

@macintosh-HD hmm yeah it definitely should. Can you try 127.0.0.1 instead?

[gentges]

Ok @jdmcd I now changed the queues provider like this:

try app.queues.use(.redis(url: "redis://127.0.0.1"))

In my logs of both Vapor and Redis I can detect that there is some initial traffic between the two:
Vapor:

[ DEBUG ] command succeeded [rdstk_conn_id: 8B56B4F7-91C2-4470-9F62-9D494C4CE441, rdstk_conpool_id: EA4964C6-9382-4DC9-93E6-9451D8341756, rdstk_result: NULL] (RediStack/RedisConnection.swift:272)
[ DEBUG ] command succeeded [rdstk_conn_id: 5FD6F3FD-230B-4A06-B5A8-26F72BC5A68D, rdstk_conpool_id: EA4964C6-9382-4DC9-93E6-9451D8341756, rdstk_result: NULL] (RediStack/RedisConnection.swift:272)

Redis:

1640191778.993503 [0 127.0.0.1:60906] "RPOPLPUSH" "vapor_queues[default]" "vapor_queues[default]-processing"
1640191778.995201 [0 127.0.0.1:60907] "RPOPLPUSH" "vapor_queues[default]" "vapor_queues[default]-processing"

But then I receive a top-level error in Vapor:

Swift/ErrorType.swift:200: Fatal error: Error raised at top level: RediStack.RedisConnectionPoolError(baseError: RediStack.RedisConnectionPoolError.BaseError.timedOutWaitingForConnection)
2021-12-22 17:49:39.007708+0100 Run[50737:3974520] Swift/ErrorType.swift:200: Fatal error: Error raised at top level: RediStack.RedisConnectionPoolError(baseError: RediStack.RedisConnectionPoolError.BaseError.timedOutWaitingForConnection)

[maximedegreve]

I'm having the same issue. 😢

[jdmcd]

@maximedegreve @macintosh-HD unfortunately that error is unrelated to the Queues package, it's generated by RediStack while attempting to connect to your Redis instance

[johnil]

This bug started from release 1.0.0-rc.4.1.
please check it.

[jdmcd]

Hi @johnil - this error is unrelated to anything in the queues package and means that it cannot connect to your Redis instance.

[saroar]

any one fixed this issue I have same issue I have connected look in WARNING MSG please

[ WARNING ] No scheduled jobs exist, exiting scheduled jobs worker.
[ NOTICE ] Server starting on http://0.0.0.0:7070
2022-10-21 16:07:37.258604+0300 Main[32764:3293055] [si_destination_compare] send failed: Invalid argument
2022-10-21 16:07:37.258846+0300 Main[32764:3293055] [si_destination_compare] send failed: Undefined error: 0
[ ERROR ] Job run failed: RedisConnectionPoolError(baseError: RediStack.RedisConnectionPoolError.BaseError.timedOutWaitingForConnection)
[ ERROR ] Job run failed: RedisConnectionPoolError(baseError: RediStack.RedisConnectionPoolError.BaseError.timedOutWaitingForConnection)

[JetForMe]

This seems to be due to a very short default timeout in RediStack (10ms!!). You can specify a longer timeout (thanks to Mads for that suggestion):

try app.queues.use(
    .redis(.init(url: redisURL ?? "redis://127.0.0.1:6379",
                   pool: .init(connectionRetryTimeout: .seconds(60))))

[lorenalexm]

@JetForMe I appreciate you sharing this! Was tearing my hair out trying to figure out why I couldn't connect to my Redis instance. Thanks!

[ihamadfuad]

Thank you @JetForMe I was about losing my hair LOL

[0xTim]

Since this seems to be related to the short timeout, I'm going to close this. Feel free to reopen if it's still an issue

[JetForMe]

@0xTim is the default timeout going to be changed? I just had to increase it again in my newest project.

[0xTim]

@JetForMe thats a RediStack issue I believe - worth creating an issue on that repo for discussion

[JetForMe]

I've submitted an issue against RediStack and a PR to fix it, but if they don’t think it’s a bug, then the Vapor driver or wrapper will have to change. It’s passing nil down to RediStack, which interprets that as 10 ms. But if it passed nothing at all, RediStack would default to 60 s.

[0xTim]

@JetForMe I'm happy to accept a PR to here as well to default to 60s

[JetForMe]

It would be a helluva design choice, so hopefully it’s considered a bug. I hope they accept the PR, although it’s been two days without any feedback, a month since the last commit. There are three open PRs, mine and two from mid-2023. I don't know how to tell who's in charge of a repo on Github.

[0xTim]

@JetForMe feel free to PR a fix into this library

[Jeehut]

I just came across this issue myself, and I would love to contribute a different default value to the Vapor code. But before I do so, I wonder why you chose 60 seconds? Isn't that a lot? I'm using 2 seconds now which also fixes this bug for me:

   try app.queues.use(
      .redis(
         RedisConfiguration(
            url: Environment.get("REDIS_TLS_URL")!,
            pool: .init(connectionRetryTimeout: .seconds(2))
         )
      )
   )

I wonder what the reasoning is behind 60 seconds. If connecting to a database takes longer than a second (both in development and production), I'd already be concerned and would love to see a warning. But 10ms seems a bit too low, at least during development, which is where I ran into this…

[JetForMe]

No idea what an appropriate timeout should be. But RediStack has both 60 seconds and 10 ms (which I think is an error in the way default parameters are set up).