HEP sender: every dropped message logs its own error once the send queue is full

Open
  • Is something wrong?
#2,236 0 comments 0 reactions 0 assignees View on GitHub

Maintainers usually reply within 3 days

Nobody has claimed this yet.

Assessment

Difficulty
3/5
Estimated time
1-2 days
Newbie friendliness
55/100
Issue type
Bug
Clarity
Clearly specified
Activity status
Active
Tech stack
c
Domain
backend

Research direction

Start with daemon/homer.c at the homer_send() queue limit check cited in the issue, then inspect how the project’s logging limiters are keyed. Reproduce with a TCP HEP collector that accepts but never reads and send NG queries as described. Done means queue overflow logs are bounded across calls while dropped messages remain counted or otherwise understandable.

Written by the indexing model from the issue text.

Description

rtpengine version the issue has been seen with

mr26.3.1.3 (abc98192d77ebadd57bef9f7387f16be2e53d5b9), built from the tag, userspace only. homer_send() is the same on master.

Used distribution and its version

Debian 13 (container)

Linux kernel version used

6.8.0-117-generic (kernel module not used)

CPU architecture issue was seen on

aarch64

Expected behaviour you didn't see

When the HEP collector stops reading, homer_send() drops new messages once the queue holds SEND_QUEUE_LIMIT (200). Dropping is fine, but the error should be logged at a bounded rate.

Unexpected behaviour you saw

Every dropped message logs its own LOG_ERR line (daemon/homer.c#L229-L234). With a TCP collector that accepts the connection but never reads, 20,000 NG commands (40,000 HEP messages with --homer-enable-ng) produced 28,742 identical error lines in 1.4 s. On a busy relay a slow or stuck collector fills the log at that rate.

Steps to reproduce the problem

  1. Listen on TCP 127.0.0.1:9060, accept the connection and never read from it (a small SO_RCVBUF makes it quicker).

  2. Start rtpengine:

    rtpengine --foreground --log-stderr --table=-1 --interface=127.0.0.1 --listen-ng=127.0.0.1:2223 --homer=127.0.0.1:9060 --homer-protocol=tcp --homer-id=2001 --homer-enable-ng --port-min=30000 --port-max=30100

  3. Send 20,000 NG query commands for an unknown call-id over UDP to 127.0.0.1:2223, each waiting for its reply.

  4. Count Send queue length limit lines in the log.

Additional program output to the terminal or logs illustrating the issue

[no-such-]: [core] Send queue length limit (200) reached, dropping Homer message
[core] Send queue length limit (200) reached, dropping Homer message
[no-such-]: [core] Send queue length limit (200) reached, dropping Homer message
... 28,742 lines in 1.4 s

Anything else?

The per-message line dates from the 2016 queue limit (d45f928c98), when HEP carried only RTCP stats; NG tracing (7905811c53, 2024) adds two HEP messages per NG command, which is what makes the rate this high.

LOG_FLAG_LIMIT would be the usual way to bound this, but its limiter keys on the log prefix, which includes the call-id, so with many concurrent calls it would still log once per call every 15 s. A single limit for the sender (for example one line per 15 s, perhaps with the number of messages dropped since the last line) would keep the log readable.

Dominant language
Perl
Stars
992
Forks
459
No merged PRs in 30d

Getting set up

This project ships no dev container, Dockerfile or contributing guide, so setting up is up to you: start from its README, and see our first-contribution guide for the general steps.

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

More from sipwise/rtpengine

All issues in sipwise/rtpengine

Similar issues

More Perl issues

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.