topology_hiding: do not warn per request on a non-local send socket

[Lt-Flash]

What

Two problems in topo_no_dlg_seq_handling(), in the branch that restores the send socket recorded in the encoded topology-hiding state: a log line that fires on every sequential request in any multi-node deployment, and — in the same branch — the unusable socket being assigned anyway, clearing whatever the script had already chosen.

1. A WARN per sequential request

When dialog-less topology hiding decodes the state of a sequential request, it looks up the socket the state was created on:

sock = grep_sock_info(&host, (unsigned short)port, proto);
if (!sock) {
    LM_WARN("non-local socket <%.*s>...ignoring\n", bind_buf.len, bind_buf.s);
}

A node not owning that socket is routine, not exceptional: any anycast or load-balanced tier can land a sequential request on a different node than the one that handled the initial request, and a node whose listening set has simply changed hits it too. The result is one WARN per sequential request, per call — on a busy presence deployment that is the bulk of the log.

Dropped to LM_DBG. The R-URI has already been restored by this point, so the request still routes; only the send socket is affected.

2. The failed lookup was not actually ignored

The message says "ignoring", but the assignment sat outside the check:

if (!sock) {
    LM_WARN(... "ignoring" ...);
}
msg->force_send_socket = sock;      /* <-- runs even when sock == NULL */

So on the failure path it stored NULL — wiping any socket the script had already selected (e.g. an earlier force_send_socket() in the route) rather than leaving it alone. The fix only assigns when a local socket was actually found:

if (!sock) {
    LM_DBG("non-local socket <%.*s> - leaving the send socket to the caller\n", ...);
} else {
    msg->force_send_socket = sock;
}

Impact

Log volume on multi-node topology-hiding deployments, and — for scripts that set a send socket before topology_hiding_match() — a silently discarded choice on any request whose state came from another node.

[Lt-Flash]

A note on why the force_send_socket half of this fix matters beyond the WARN-spam it silences: in follow-up work already implemented on a development branch, topology_hiding can fetch a hidden-dialog state from another cluster node when a sequential request lands on the wrong machine (failover / re-hash behind a load balancer). A state created on node A and restored on node B may name a send socket that only exists on A — so the restore path depends on exactly the socket-handling discipline this PR establishes: respect the stored socket when it resolves locally, fall back cleanly to a local socket of the matching protocol when it doesn't, and never let a stale value clobber a route-set decision. This PR is a prerequisite for that work landing, which is one more reason to keep it a small standalone fix.

[bogdan-iancu]

Thank you @Lt-Flash for the worker here. I still consider that the logs should stay as a warning, as it is an indicator if something in wrong with the traffic or the setup.
Now, in your particular case, have you tried to the tags for the sockets, to logically bind sockets (even with different IPs) from different servers ? (see https://docs.opensips.org/manual/devel/script-coreparameters/#socket)

[Lt-Flash]

Thanks for taking a look, @bogdan-iancu.

On the socket tags question — good prompt, I went and checked both the code and our actual deployment.

Our environment (3-node anycast SBC tier, sockets from opensips.cfg on each node, public IP redacted):

# Node A (private IP shown, real value differs per node)
socket=udp:10.22.23.X:5060  use_workers 2  use_auto_scaling_profile PROFILE_UDP_PRIV  tag udp_priv

# identical on every node in the tier - same tag, different real IP per node
socket=udp:10.22.23.Y:5060  use_workers 2  use_auto_scaling_profile PROFILE_UDP_PRIV  tag udp_priv
socket=udp:10.22.23.Z:5060  use_workers 2  use_auto_scaling_profile PROFILE_UDP_PRIV  tag udp_priv

# public/anycast side - literally the SAME IP bound on all three nodes
socket=udp:<PUBLIC-VIP-IP>:7060  use_workers 2  use_auto_scaling_profile PROFILE_UDP_PUB  tag udp_pub anycast
socket=tcp:<PUBLIC-VIP-IP>:7060  tag vip
socket=tls:<PUBLIC-VIP-IP>:7061  tag vip
socket=wss:<PUBLIC-VIP-IP>:7069  tag vip

The public/anycast leg never hits this bug in the first place - every node binds the identical literal IP, so the existing plain grep_sock_info() IP match already succeeds everywhere. The bug is specifically the private leg, where each node's socket is a genuinely different IP - and as you can see, we already tag it identically (udp_priv) across every node, precisely because we think of it as one logical role, not three distinct addresses.

So I checked whether that tag is actually usable today, and it isn't - not because tags don't work, but because topology_hiding doesn't use the mechanism on either side:

• The encode path (topo_no_dlg_encode_contact) serializes msg->rcv.bind_address->sock_str directly - the literal address, not get_socket_internal_name() (which returns tag_sock_str, the tag-based "tag:port" representation, when a tag is configured).
• The restore path this PR touches calls the plain grep_sock_info() macro - grep_sock_info_ext(..., check_tags=0) - so tag matching is off here regardless of config. Even the tag-aware variant only checks tags when port==0, which this call site never passes (it always parses a real port out of the stored socket string).

Given we already tag our private sockets exactly the way this would need, wiring topo_hiding_logic.c to encode/decode via the tag-aware path seems like a genuinely worthwhile follow-up - on our own tier it would let the restore succeed via the tag instead of falling back to the caller's socket at all. Happy to take that on separately if there's interest, but it's a real code change to the module (both encode and decode sides), not something achievable by this PR alone.

On the log level - I hear the concern, and agree it's a legitimate signal in cases where it indicates a real setup problem. The case this PR targets is specifically the routine one shown above: state legitimately created on one node, restored on another, as expected behavior in an anycast/LB tier - not a misconfiguration. In that topology it fires on every single sequential request of every such call, which is what made it unusable as a signal for us. Since the R-URI has already been correctly restored by this point and only the send socket falls back to the caller's choice, would you be open to something in between - e.g. rate-limiting the line, or only escalating to WARN after N occurrences for the same state - rather than either "always WARN" or "always DBG"? Open to whatever level best preserves the signal without the per-request flood.

[Lt-Flash]

Update, since a lot happened to this file since I opened this PR - the underlying code moved into th_no_dlg_logic.c via the "no dialog"/refactor work, and it turns out something more concrete than the WARN-level question surfaced along the way.

On the tags question specifically: someone already added a socket-tag fallback here independently (th_external_socket_tag, documented for exactly this "encoded on a different node" case). But both restore paths that need it were actually calling th_internal_trusted_tag instead - a different modparam entirely, meant for one-way-hiding trust decisions, not socket resolution. The one place in the file that does use th_external_socket_tag correctly (topo_no_dlg_match_uri()'s auto-Route matching) shows the intended pattern - try the tag only after a direct match fails, and only then decide what to log.

The wrong-variable bug also broke the log condition itself: the else in both broken sites fired on any case other than "not found and tag configured" - which includes the socket resolving successfully with no problem at all, and stayed completely silent in the genuine unresolvable case. So the log wasn't just too loud, it was firing on the wrong condition entirely.

I've rewritten both sites to: try the tag fallback only after a direct miss, and only log once neither resolves it - which is also where I kept the DBG (down from WARN) for the reasons in my last comment. Rebased onto current master and force-pushed since the file changed too much for a normal rebase to apply cleanly.

Still very open to whatever log level you think is right for the "genuinely couldn't resolve it" case now that it's gated correctly - happy to bump it back to WARN, or the rate-limit idea, whatever you'd prefer.