Update to Kombu 5.5.0 stopped processing SQS messages

[mdrachuk]

Hello.

Tbh I'm confused about the debug steps for this, because we didn't have any alerts or error logs. Only the actual usage showed that the tasks from the SQS weren't processing anymore.

Downgrade to 5.4.2 solved the issue for now.

Leaving this here for anybody having similar issues to see and maybe comment on details they can find.

[mgorven]

I'm seeing the same thing. It's not completely broken, but processing is extremely slow.

[Nusnus]

Can you please share a reproduction script or steps to reproduce, I'd like to solve this ASAP.

Thank you.

[mgorven]

Our workers process tasks from four standard SQS queues. Task execution time is fast (~50ms) and we use task_acks_late=True. We run with concurrency of eight and worker_prefetch_multiplier=16. With Kombu 5.4.2 one instance can process ~100 tasks per second, with 5.5.0 it drops to ~3/s. CPU usage remains low.

[Nusnus]

Ok, found it.

Throughput: 0.99 tasks per second with urllib3

python stress_test.py
Processed 50 tasks in 50.68 seconds
Throughput: 0.99 tasks per second

Throughput: 55.25 tasks per second with pycurl

python stress_test.py
Processed 50 tasks in 0.90 seconds
Throughput: 55.25 tasks per second

In PR #2134 we have migrated from pycurl to urllib3, by @spawn-guy.
Following this change, we’ve also removed pycurl from celery in PR celery/celery#9526 by @jmsmkn.

@mgorven

Our workers process tasks from four standard SQS queues. Task execution time is fast (~50ms) and we use task_acks_late=True. We run with concurrency of eight and worker_prefetch_multiplier=16. With Kombu 5.4.2 one instance can process ~100 tasks per second, with 5.5.0 it drops to ~3/s. CPU usage remains low.

By creating a quick stress_test.py to reproduce your case, I could easily see the problem using the latest version.
Reverting Commit 07c8852 from kombu and Commit 9bf0546 from celery was enough to fix the performance, as can be seen in the logs above.

Celery Worker

export AWS_DEFAULT_REGION=us-east-1
export AWS_ACCESS_KEY_ID=test
export AWS_SECRET_ACCESS_KEY=test
export AWS_ENDPOINT_URL=http://localhost:4566
celery -A myapp worker -l INFO

myapp.py

from celery import Celery
import time

app = Celery(
    "myapp",
    broker="sqs://",
    result_backend="redis://",
    task_acks_late=True,
    worker_prefetch_multiplier=16,
)


@app.task
def add(x, y):
    time.sleep(0.05)  # Simulate 50ms task execution time
    return x + y


if __name__ == "__main__":
    app.start()

stress_test.py

export AWS_DEFAULT_REGION=us-east-1
export AWS_ACCESS_KEY_ID=test
export AWS_SECRET_ACCESS_KEY=test
export AWS_ENDPOINT_URL=http://localhost:4566
python stress_test.py

from myapp import add
from celery import group
import time

num_tasks = 50
tasks = [add.s(1, 2) for _ in range(num_tasks)]
g = group(tasks)
start_time = time.time()
result = g.apply_async()
result.get()
end_time = time.time()
total_time = end_time - start_time
throughput = num_tasks / total_time
print(f"Processed {num_tasks} tasks in {total_time:.2f} seconds")
print(f"Throughput: {throughput:.2f} tasks per second")

We have had multiple pre-releases, both in Celery and Kombu, and this is the first time we have received such a report.

—

@spawn-guy, I wonder if there’s anything we can tweak to fix this instead of reverting back to pycurl.
As this was discovered after the final v5.5.0 release, this issue is a bit urgent.
Would you mind giving it a look please?
If you’re unavailable, please let me know so I can revert the changes and issue a new release, although this is the least wanted outcome.

@auvipy I’d be glad to hear your feedback as well. Thanks.

Note to self: How come we didn’t fall on this in the CI 🤔
I might need to enable SQS in pytest-celery and add a smoke test to the CI to reproduce this case and detect performance failures.
The issue is that SQS support is currently experimental in pytest-celery, and I don’t have the capacity to fix any problems that may arise (IIRC there are issues when using SQS/Redis in the CI, potentially due to a genuine bug).

[auvipy]

the performance regressions are hard to address in short notice to be honest

[auvipy]

I think we have to stick to special implementation of pycurl until we have our homegrown faster or equal alternative of pycurl. some previous attempts also faced the serious performance regressions

[auvipy]

If we can't figure out by next 1 or 2 weeks, we should revert this #2261

[Nusnus]

@auvipy

If we can't figure out by next 1 or 2 weeks, we should revert this #2261

Unfortunately we don't have the luxury of time my friend. I will take care of everything and release a fixed version on Monday.

I just want to give it a few days for @spawn-guy to check this out, but per my script above we can confirm the issue is only due to the dep changes.

[Nusnus]

the performance regressions are hard to address in short notice to be honest

I released it before the weekend knowing it might have issues. I am prepared to respond quickly.

I take responsibility, please don't stress yourself over the weekend 🙏

[Nusnus]

I think we have to stick to special implementation of pycurl until we have our homegrown faster or equal alternative of pycurl. some previous attempts also faced the serious performance regressions

Any recommendation?

[auvipy]

the performance regressions are hard to address in short notice to be honest

I released it before the weekend knowing it might have issues. I am prepared to respond quickly.

I take responsibility, please don't stress yourself over the weekend 🙏

there is no need to feel guilty. celery code base is hard.

[auvipy]

I think we have to stick to special implementation of pycurl until we have our homegrown faster or equal alternative of pycurl. some previous attempts also faced the serious performance regressions

Any recommendation?

I have to test alternatives, right now I think we should revert back to pycurl as it was working fine as far as I know.