[OpenSIPS-Users] Problems passing BYE signal in v3.7
Alistair Cleminson
alistair.cleminson at wifinity.co.uk
Fri Jan 30 16:54:26 UTC 2026
Thanks for the tip, it turns out I'd completely misunderstood the process. This configuration doesn't generate the errors & passes calls:
if (is_method("INVITE")) {
$acc_extra(si) = $si;
$acc_extra(fU) = $fU;
$acc_extra(fd) = $fd;
$acc_extra(rU) = $rU;
$acc_extra(rd) = $rd;
do_accounting("log|db","cdr|missed|failed");
if (get_source_group($var(si))) {
if (!alias_db_lookup("dbaliases")) {
xlog("L_ERR", "LOG: DDI Alias not found, time=[$Ts] from uri=[$fu] to uri=[$ru]");
sl_send_reply(404, "Not Found");
};
$avp(site)=$(ruri.user{s.substr,0,5});
route(ALLOW);
exit;
}
else {
log(1, "Permissions RECORD FAIL\n");
sl_send_reply(403, "Forbidden");
exit;
};
};
I'm still not passing BYE packets successfully though. I'll dig a little more before I ask again.
thanks
a.
From: johan de clercq <johan at democon.be>
Date: Thursday, 29 January 2026 at 9:41 am
To: Alistair Cleminson <alistair.cleminson at wifinity.co.uk>
Subject: Re: [OpenSIPS-Users] Problems passing BYE signal in v3.7
You don't often get email from johan at democon.be. Learn why this is important<https://aka.ms/LearnAboutSenderIdentification>
[CAUTION] This email is from an external sender - Please be cautious, particularly with any links and attachments. If you suspect a phishing email, please report it to IT.
maybe changing the 2 vars to avp's will fix the issue.
On 1/27/26 17:27, Alistair Cleminson wrote:
Hi,
I've nearly completed the process of upgrading our ancient v1.7 deployment to v3.6. The new deployment is installed on Ubuntu 24.04 from the OpenSIPS repos. These servers are our inbound hand-off from our upstream supplier, they take a call, inspect the called number element against the database, and then pass it on to the target system with the internal reference or decline the call.
I've never been a programmer and am much more familiar with Asterisk, having inherited the platform & 'maintained' these hosts for about ten years I'm far from fluent in the configuration syntax but also much less terrified than I was when I first opened the opensips.cfg file. Having said that, I've updated most of the configuration and database backend to successfully accept, process & pass on a call to our core voice platform with 2-way audio.
Unfortunately, when a call is terminated by either the called or calling party the BYE signal is not passed to the other party leaving the call hanging until they also hang up or an intermediate system decides the call is in a stale state & drops it.
From what I can tell, this is the v1.7 code which would capture the session related traffic and associate a BYE with a particular call.
I think the problem is related to my attempt to convert the depreciated allow_source_address_group() function:
--- v1.7 code ---
if(is_method("INVITE")) {
setflag("1");
setflag("2");
>> $var(group) = allow_source_address_group();
xlog("L_ERR", "LOG: The value of var(group) = [$var(group)]");
if ($var(group) != -1) {
if(!alias_db_lookup("dbaliases")) {
xlog("L_ERR", "LOG: Alias not found time=[$Ts] from uri=[$fu] to uri=[$ru]");
sl_send_reply("404", "Not Found");
};
$avp(s:site)=$(ruri.user{s.substr,0,5});
route(3);
exit;
}
else if ($var(group) == -1) {
log(1, "Permissions RECORD FAIL\n");
sl_send_reply("403", "Forbidden");
exit;
};
};
--- v3.6 code ---
if (is_method("INVITE")) {
$acc_extra(si) = $si;
$acc_extra(fU) = $fU;
$acc_extra(fd) = $fd;
$acc_extra(rU) = $rU;
$acc_extra(rd) = $rd;
do_accounting("log|db","cdr|missed");
xlog("L_ERR", "LOG: The value of si = [$si]");
>> $var(srcgrp) = get_source_group($si);
xlog("L_ERR", "LOG: The value of var(srcgrp) = [$var(srcgrp)]");
>> $var(group) = check_source_address($var(srcgrp));
xlog("L_ERR", "LOG: The value of var(group) = [$var(group)]");
if ($var(group) != -1) {
if (!alias_db_lookup("dbaliases")) {
xlog("L_ERR", "LOG: DDI Alias not found, time=[$Ts] from uri=[$fu] to uri=[$ru]");
sl_send_reply(404, "Not Found");
};
$avp(site)=$(ruri.user{s.substr,0,5});
route(ALLOW);
exit;
}
else if ($var(group) == -1) {
log(1, "Permissions RECORD FAIL\n");
sl_send_reply(403, "Forbidden");
exit;
};
};
The logging on the hosts indicates that my substitution isn't working.
--- v1.7 log ---
Jan 26 17:28:28 routing-1 /../opensips[1956]: --== SIP message body - INVITE ==-- v=0#015#012o=Sonus_UAC 828539 387688 IN IP4 <UPSTREAM_PEER>#015#012s=SIP Media Capabilities#015#012c=IN IP4 141.170.50.21#015#012t=0 0#015#012m=audio 25014 RTP/AVP 8 98#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:98 telephone-event/8000#015#012a=fmtp:98 0-15#015#012a=sendrecv#015#012a=maxptime:20#015
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:permissions:allow_source_address_group: looking for <8460ef6d, 5060> in address table
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:permissions:allow_source_address_group: Found <-1>
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:permissions:allow_source_address_group: looking for <8460ef6d, 5060> in subnet table
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:permissions:allow_source_address_group: Found <1>
Jan 26 17:28:28 routing-1 /../opensips[1956]: LOG: The value of var(group) = [1]
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:core:comp_scriptvar: int 29 : 1 / -1
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:db_mysql:has_stmt_ctx: ctx found for dbaliases
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:db_mysql:db_mysql_do_prepared_query: conn=0x787e70 (tail=7895720) MC=0x786208
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:db_mysql:db_mysql_val2bind: added val (0): len=12; type=254; is_null=0
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:db_mysql:db_mysql_do_prepared_query: prepared statement has 2 columns in result
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:core:db_new_result: allocate 48 bytes for result set at 0x789bf0
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:db_mysql:db_mysql_get_columns: 2 columns returned from the query
Jan 26 17:28:28 routing-1 /../opensips[1956]: DBG:core:db_allocate_columns: allocate 56 bytes for result columns at 0x789618
--- v 3.7 log ---
01-26 17:43:30.891281 a /../opensips[4010750]: ERROR:--== SIP message body - INVITE ==-- v=0#015#012o=Sonus_UAC 565884 3698 IN IP4 <UPSTREAM_PEER>#015#012s=SIP Media Capabilities#015#012c=IN IP4 <UPSTREAM_PEER>#015#012t=0 0#015#012m=audio 27052 RTP/AVP 8 96#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:96 telephone-event/8000#015#012a=fmtp:96 0-15#015#012a=sendrecv#015#012a=maxptime:20#015
01-26 17:43:30.891298 a /../opensips[4010750]: DBG:core:parse_to_param: tag=gK085d4ab6
01-26 17:43:30.891313 a /../opensips[4010750]: DBG:core:parse_to_param: end of header reached, state=11
01-26 17:43:30.891327 a /../opensips[4010750]: DBG:core:_parse_to: end of header reached, state=29
01-26 17:43:30.891342 a /../opensips[4010750]: DBG:core:_parse_to: display={}, ruri={sip:<CALLER_DDI>@<UPSTREAM_PEER>;user=phone}
01-26 17:43:30.891425 a /../opensips[4010750]: DBG:core:parse_headers_aux: flags=78
01-26 17:43:30.891441 a /../opensips[4010750]: DBG:core:has_totag: no totag
01-26 17:43:30.891459 a /../opensips[4010750]: DBG:dialog:build_new_dlg: new dialog 0x71cbfe3b64b0 (c=352862312_66830718@<UPSTREAM_PEER>,f=sip:<CALLER_DDI>@<UPSTREAM_PEER>;user=phone,t=sip:<OUR_DDI>@<UPSTREAM_PEER>;user=phone,ft=gK085d4ab6) on hash 3981
01-26 17:43:30.891481 a /../opensips[4010750]: DBG:core:parse_headers_aux: flags=ffffffffffffffff
01-26 17:43:30.891502 a /../opensips[4010750]: DBG:core:print_rr_body: current rr is <sip:<UPSTREAM_PEER>;lr;ftag=gK085d4ab6;did=d8f.40748994>
01-26 17:43:30.891517 a /../opensips[4010750]: DBG:core:print_rr_body: skipping 0 route records
01-26 17:43:30.891533 a /../opensips[4010750]: DBG:core:print_rr_body: out rr [<sip:<UPSTREAM_PEER>;lr;ftag=gK085d4ab6;did=d8f.40748994>]
01-26 17:43:30.891546 a /../opensips[4010750]: DBG:core:print_rr_body: we have 1 records
01-26 17:43:30.891562 a /../opensips[4010750]: DBG:dialog:update_leg_info: route_set <sip:<UPSTREAM_PEER>;lr;ftag=gK085d4ab6;did=d8f.40748994>, contact sip:<CALLER_DDI>@<UPSTREAM_PEER>:5060, cseq 494280 and bind_addr udp:<THIS_HOST>:5060
01-26 17:43:30.891582 a /../opensips[4010750]: DBG:core:parse_headers_aux: flags=ffffffffffffffff
01-26 17:43:30.891594 a /../opensips[4010750]: DBG:dialog:dlg_update_leg_info: set leg 0 for 0x71cbfe3b64b0: tag=<gK085d4ab6> rcseq=<0>
01-26 17:43:30.891610 a /../opensips[4010750]: DBG:dialog:link_dlg: ref dlg 0x71cbfe3b64b0 with 3 -> 3 in h_entry 0x71cbfe377c08 - 3981
01-26 17:43:30.891627 a /../opensips[4010750]: DBG:rr:add_rr_param: adding (;did=d8f.57669b46)
01-26 17:43:30.891643 a /../opensips[4010750]: DBG:rr:add_rr_param: second RR lump found
01-26 17:43:30.891660 a /../opensips[4010750]: DBG:rr:add_rr_param: second RR lump found
01-26 17:43:30.891772 a /../opensips[4010750]: ERROR:LOG: The value of si = [<UPSTREAM_PEER>]
01-26 17:43:30.891784 a /../opensips[4010750]: DBG:permissions:get_source_group: Looking for <<UPSTREAM_PEER>, 5060> in address table
01-26 17:43:30.891799 a /../opensips[4010750]: DBG:permissions:get_source_group: Found <1>
>> 01-26 17:43:30.891814 a /../opensips[4010750]: ERROR:core:pv_set_value: bad parameters
>> 01-26 17:43:30.891832 a /../opensips[4010750]: ERROR:permissions:get_source_group: setting of pvar failed
01-26 17:43:30.891849 a /../opensips[4010750]: ERROR:LOG: The value of var(srcgrp) = [-1]
01-26 17:43:30.891861 a /../opensips[4010750]: DBG:permissions:check_src_addr: Looking for : <default:-1, <UPSTREAM_PEER>, 1, 5060, >
01-26 17:43:30.891879 a /../opensips[4010750]: DBG:permissions:pm_hash_match: specified group '4294967295' does not exist in hash table
01-26 17:43:30.891895 a /../opensips[4010750]: ERROR:LOG: The value of var(group) = [-2]
01-26 17:43:30.891907 a /../opensips[4010750]: DBG:core:comp_scriptvar: int 29: -2 / -1
01-26 17:43:30.893310 a /../opensips[4010750]: DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected
01-26 17:43:30.893349 a /../opensips[4010750]: DBG:core:db_new_result: allocate 48 bytes for result set at 0x71cc020e4730
01-26 17:43:30.893367 a /../opensips[4010750]: DBG:db_mysql:db_mysql_get_columns: 2 columns returned from the query
01-26 17:43:30.893382 a /../opensips[4010750]: DBG:core:db_allocate_columns: allocate 56 bytes for result columns at 0x71cc020e4798
As I've been looking through the logs I've noticed that following the OK reply once a call is answered the v3.7 host does some accounting to the database & then sends OK messages related to the INVITE, after four packets the transaction is destroyed. Seven more OK messages are sent with tm logging that 'no matching transaction exists' before it gives up.
Any help would be gratefully received.
Many thanks,
Al Cleminson.
_______________________________________________
Users mailing list
Users at lists.opensips.org<mailto:Users at lists.opensips.org>
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20260130/1353bdef/attachment-0001.html>
More information about the Users
mailing list