http_async_query on carrierfailureroute changes rd back to carrieroute primary

List overview All Threads
Download

newer

older

app_python3 method not found or is...

Kamailio hang Issue

Maharaja Azhagiah

19 Mar 2024 19 Mar '24

12:21 a.m.

Hi I am running kamailio 5.4 on debian I have carrierfailureroute configured incase of primary service provider fails. I also have Stirshaken configured to add Identity header on outbound calls. Issue is when call fail overs to carrierfailureroute, http_async_query changes $ru to the primary carrier From the debug logs, when primary carrier sends a 488 (primary carrier expects SIP TLS but my call is UDP - to test the failover scenario) 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} tmx [t_var.c:561]: pv_get_tm_reply_code(): reply code is <488> 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:178]: set_next_domain_on_rule(): searching for matching routing rules39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:197]: set_next_domain_on_rule(): next_domain is 47987 Carrier route rewrites the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:706]: cr_do_route(): uri 14371234567 was rewritten to sip:14371234567@sip.primaryprovider.com, carrier 1, domain 47987 Before http_async_query rd and ru are still the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2976] - Debug testing ----- rd is sip.primaryprovider.com ----- ru is sip:14371234567@sip.primaryprovider.com 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:469]: async_send_query(): transaction suspended [5261:1830449764] 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:625]: async_push_query(): query sent [ https://authn-uat.ccid.neustar.biz/ccid/authn/v2/identity?apiKey=randomkey] (0x7fdcad097e60) to worker 1 However, when the route is being called after the http_async_query it changes to the primary one: 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) DEBUG: http_async_client [async_http.c:235]: async_http_cb(): resuming transaction (5261:1830449764) 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) INFO: <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2995] - Debug testing ----- rd is 1.2.3.4 ----- ru is sip:14371234567@1.2.3.4:5061;transport=TLS Due to this, call keeps going to the primary and it fails if ( http_async_query(STIRSHAKEN_AS_URL, "AS_RESPONSE") == -1 ) { xlog("L_ERR ", "[cfg:$cfg(line)] Failed to connect AS service for token $fu -> $tu \n"); return; } route[AS_RESPONSE] { xlog("L_INFO", "[callid: $ci] - [cfg:$cfg(line)] - Debug testing ----- rd is $rd ----- ru is $ru\n"); if ($http_ok) { xlog("L_INFO", "[cfg:$cfg(line)] Resuming outbound call transaction for $fu -> $tu Received - $http_rb \n"); # Add identity and Date headers if (jansson_get("identity", $http_rb, "$var(identity)")) { insert_hf("Identity: $var(identity)\n", "Content-Length"); } if (jansson_get("date", $http_rb, "$var(date)")) { if ($hdr(Date) != $null){ remove_hf("Date"); } insert_hf("Date: $var(date)\n", "Identity"); } } else { xlog("L_ERR", "[cfg:$cfg(line)] Resuming outbound call transaction. Error - $http_err)\n"); } route(RELAY); exit; } Please help to understand why rd / ru changes to primary carrier. Regards, Maharaja Azhagiah

Attachments:

attachment.html (text/html — 4.6 KB)

Show replies by date

Henning Westerholt

19 Mar 19 Mar

1:30 p.m.

Hello, Using http_async_query can change some script behaviour due to some side effects, I noticed this also e.g. on rtpengine functions. I did not looked into your cfg in details, but one easy option from your side would be to try a maintained Kamailio version (e.g. 5.7.x) and see if the problem also is observable there. Cheers, Henning From: Maharaja Azhagiah via sr-users <sr-users(a)lists.kamailio.org> Sent: Montag, 18. März 2024 22:21 To: Kamailio (SER) - Users Mailing List <sr-users(a)lists.kamailio.org> Cc: Maharaja Azhagiah <er.maharaja(a)gmail.com> Subject: [SR-Users] http_async_query on carrierfailureroute changes rd back to carrieroute primary Hi I am running kamailio 5.4 on debian I have carrierfailureroute configured incase of primary service provider fails. I also have Stirshaken configured to add Identity header on outbound calls. Issue is when call fail overs to carrierfailureroute, http_async_query changes $ru to the primary carrier From the debug logs, when primary carrier sends a 488 (primary carrier expects SIP TLS but my call is UDP - to test the failover scenario) 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} tmx [t_var.c:561]: pv_get_tm_reply_code(): reply code is <488> 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:178]: set_next_domain_on_rule(): searching for matching routing rules39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:197]: set_next_domain_on_rule(): next_domain is 47987 Carrier route rewrites the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:706]: cr_do_route(): uri 14371234567 was rewritten to sip:14371234567@sip.primaryprovider.com<mailto:sip%3A14371234567@sip.primaryprovider.com>, carrier 1, domain 47987 Before http_async_query rd and ru are still the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2976] - Debug testing ----- rd is sip.primaryprovider.com<http://sip.primaryprovider.com> ----- ru is sip:14371234567@sip.primaryprovider.com<mailto:sip%3A14371234567@sip.primaryprovider.com> 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:469]: async_send_query(): transaction suspended [5261:1830449764] 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:625]: async_push_query(): query sent [https://authn-uat.ccid.neustar.biz/ccid/authn/v2/identity?apiKey=randomkey] (0x7fdcad097e60) to worker 1 However, when the route is being called after the http_async_query it changes to the primary one: 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) DEBUG: http_async_client [async_http.c:235]: async_http_cb(): resuming transaction (5261:1830449764) 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) INFO: <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2995] - Debug testing ----- rd is 1.2.3.4 ----- ru is sip:14371234567@1.2.3.4:5061;transport=TLS Due to this, call keeps going to the primary and it fails if ( http_async_query(STIRSHAKEN_AS_URL, "AS_RESPONSE") == -1 ) { xlog("L_ERR ", "[cfg:$cfg(line)] Failed to connect AS service for token $fu -> $tu \n"); return; } route[AS_RESPONSE] { xlog("L_INFO", "[callid: $ci] - [cfg:$cfg(line)] - Debug testing ----- rd is $rd ----- ru is $ru\n"); if ($http_ok) { xlog("L_INFO", "[cfg:$cfg(line)] Resuming outbound call transaction for $fu -> $tu Received - $http_rb \n"); # Add identity and Date headers if (jansson_get("identity", $http_rb, "$var(identity)")) { insert_hf("Identity: $var(identity)\n", "Content-Length"); } if (jansson_get("date", $http_rb, "$var(date)")) { if ($hdr(Date) != $null){ remove_hf("Date"); } insert_hf("Date: $var(date)\n", "Identity"); } } else { xlog("L_ERR", "[cfg:$cfg(line)] Resuming outbound call transaction. Error - $http_err)\n"); } route(RELAY); exit; } Please help to understand why rd / ru changes to primary carrier. Regards, Maharaja Azhagiah

Maharaja Azhagiah

6 Aug 6 Aug

5:05 p.m.

Hi I have upgraded kamailio to 5.7.6 and I still see the issue when call failover to the provider configured carrierfailureroute, RURI changed back to the first / primary carrier Call fails due to 488 and rewrites to next carrier 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3] - [cfg:2624] (INVITE) RTF_CARRIERS (sip:14379892230@216.82.236.254:5061;transport=TLS) Called for outbound mazhagiah1test.sip.sandbox.com, RU: 14379892230, RD: 216.82.236.254, 488 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tm [t_lookup.c:1565]: t_check_msg(): msg (0x7ff946d395f8) id=0/160 global id=0/160 T start=0x7ff946d00f48 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tm [t_lookup.c:1641]: t_check_msg(): T (0x7ff946d00f48) already found for msg (0x7ff946d395f8)! 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tmx [t_var.c:554]: pv_get_tm_reply_code(): reply code is <488> 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:163]: set_next_domain_on_rule(): searching for matching routing rules36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:184]: set_next_domain_on_rule(): next_domain is 47987 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3] - [cfg:2633] (INVITE) r-uri (sip:14379892230@216.82.236.254:5061;transport=TLS) carrier_tree: outbound Next-lookup_domain: 47987 ----------------------- 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:449]: rewrite_on_rule(): searching for matching routing rules36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [prime_hash.c:66]: hash_func(): hash: 2729722775 % 1000 = 775 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:689]: ki_cr_do_route_helper(): uri 14379892230 was rewritten to sip:14379892230@sip.telnyx.com, carrier 1, domain 47987 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]-[cfg:2594] domain (sip.telnyx.com) starts with TELNYX_SIP_TLD, checking hijacking 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]-[cfg:2600] domain postfix: com However, after http_async_query for stir/shaken header, RURI still remains with the primary carrier domain 26(184) DEBUG: pv [pv_core.c:1358]: pv_get_dsturi_attr(): no destination URI 26(184) WARNING: <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]{INVITE} - [RELAY] use udp/udp/1 Protocol strict relay dest:<null> RURI:sip:14379892230@216.82.236.254:5061;transport=TLS dest-proto:<null> ruri-proto:TLS next-hop Proto: TLS I am attaching the complete log. Please help to understand and fix this issue. Regards *Maharaja Azhagiah* On Tue, Mar 19, 2024 at 6:30 AM Henning Westerholt <hw(a)gilawa.com> wrote:

...

Hello, Using http_async_query can change some script behaviour due to some side effects, I noticed this also e.g. on rtpengine functions. I did not looked into your cfg in details, but one easy option from your side would be to try a maintained Kamailio version (e.g. 5.7.x) and see if the problem also is observable there. Cheers, Henning *From:* Maharaja Azhagiah via sr-users <sr-users(a)lists.kamailio.org> *Sent:* Montag, 18. März 2024 22:21 *To:* Kamailio (SER) - Users Mailing List <sr-users(a)lists.kamailio.org> *Cc:* Maharaja Azhagiah <er.maharaja(a)gmail.com> *Subject:* [SR-Users] http_async_query on carrierfailureroute changes rd back to carrieroute primary Hi I am running kamailio 5.4 on debian I have carrierfailureroute configured incase of primary service provider fails. I also have Stirshaken configured to add Identity header on outbound calls. Issue is when call fail overs to carrierfailureroute, http_async_query changes $ru to the primary carrier From the debug logs, when primary carrier sends a 488 (primary carrier expects SIP TLS but my call is UDP - to test the failover scenario) 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} tmx [t_var.c:561]: pv_get_tm_reply_code(): reply code is <488> 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:178]: set_next_domain_on_rule(): searching for matching routing rules39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:197]: set_next_domain_on_rule(): next_domain is 47987 Carrier route rewrites the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:706]: cr_do_route(): uri 14371234567 was rewritten to sip:14371234567@sip.primaryprovider.com, carrier 1, domain 47987 Before http_async_query rd and ru are still the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2976] - Debug testing ----- rd is sip.primaryprovider.com ----- ru is sip:14371234567@sip.primaryprovider.com 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:469]: async_send_query(): transaction suspended [5261:1830449764] 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:625]: async_push_query(): query sent [ https://authn-uat.ccid.neustar.biz/ccid/authn/v2/identity?apiKey=randomkey] (0x7fdcad097e60) to worker 1 However, when the route is being called after the http_async_query it changes to the primary one: 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) DEBUG: http_async_client [async_http.c:235]: async_http_cb(): resuming transaction (5261:1830449764) 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) INFO: <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2995] - Debug testing ----- rd is 1.2.3.4 ----- ru is sip:14371234567@1.2.3.4:5061;transport=TLS Due to this, call keeps going to the primary and it fails if ( http_async_query(STIRSHAKEN_AS_URL, "AS_RESPONSE") == -1 ) { xlog("L_ERR ", "[cfg:$cfg(line)] Failed to connect AS service for token $fu -> $tu \n"); return; } route[AS_RESPONSE] { xlog("L_INFO", "[callid: $ci] - [cfg:$cfg(line)] - Debug testing ----- rd is $rd ----- ru is $ru\n"); if ($http_ok) { xlog("L_INFO", "[cfg:$cfg(line)] Resuming outbound call transaction for $fu -> $tu Received - $http_rb \n"); # Add identity and Date headers if (jansson_get("identity", $http_rb, "$var(identity)")) { insert_hf("Identity: $var(identity)\n", "Content-Length"); } if (jansson_get("date", $http_rb, "$var(date)")) { if ($hdr(Date) != $null){ remove_hf("Date"); } insert_hf("Date: $var(date)\n", "Identity"); } } else { xlog("L_ERR", "[cfg:$cfg(line)] Resuming outbound call transaction. Error - $http_err)\n"); } route(RELAY); exit; } Please help to understand why rd / ru changes to primary carrier. Regards, Maharaja Azhagiah

Federico Cabiddu

7 Aug 7 Aug

5:26 p.m.

Hi, changing version won't "fix', due to kamailio internals you have to rewrite the ruri after the async reply. Did you try what I suggested in the previous reply? Regards, Federico On Wed, Aug 7, 2024 at 3:13 PM Maharaja Azhagiah via sr-users < sr-users(a)lists.kamailio.org> wrote:

...

Hi I have upgraded kamailio to 5.7.6 and I still see the issue when call failover to the provider configured carrierfailureroute, RURI changed back to the first / primary carrier Call fails due to 488 and rewrites to next carrier 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3] - [cfg:2624] (INVITE) RTF_CARRIERS (sip:14379892230@216.82.236.254:5061;transport=TLS) Called for outbound mazhagiah1test.sip.sandbox.com, RU: 14379892230, RD: 216.82.236.254, 488 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tm [t_lookup.c:1565]: t_check_msg(): msg (0x7ff946d395f8) id=0/160 global id=0/160 T start=0x7ff946d00f48 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tm [t_lookup.c:1641]: t_check_msg(): T (0x7ff946d00f48) already found for msg (0x7ff946d395f8)! 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tmx [t_var.c:554]: pv_get_tm_reply_code(): reply code is <488> 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:163]: set_next_domain_on_rule(): searching for matching routing rules36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:184]: set_next_domain_on_rule(): next_domain is 47987 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3] - [cfg:2633] (INVITE) r-uri (sip:14379892230@216.82.236.254:5061;transport=TLS) carrier_tree: outbound Next-lookup_domain: 47987 ----------------------- 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:449]: rewrite_on_rule(): searching for matching routing rules36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [prime_hash.c:66]: hash_func(): hash: 2729722775 % 1000 = 775 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:689]: ki_cr_do_route_helper(): uri 14379892230 was rewritten to sip:14379892230@sip.telnyx.com, carrier 1, domain 47987 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]-[cfg:2594] domain ( sip.telnyx.com) starts with TELNYX_SIP_TLD, checking hijacking 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]-[cfg:2600] domain postfix: com However, after http_async_query for stir/shaken header, RURI still remains with the primary carrier domain 26(184) DEBUG: pv [pv_core.c:1358]: pv_get_dsturi_attr(): no destination URI 26(184) WARNING: <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]{INVITE} - [RELAY] use udp/udp/1 Protocol strict relay dest:<null> RURI:sip:14379892230@216.82.236.254:5061;transport=TLS dest-proto:<null> ruri-proto:TLS next-hop Proto: TLS I am attaching the complete log. Please help to understand and fix this issue. Regards *Maharaja Azhagiah* On Tue, Mar 19, 2024 at 6:30 AM Henning Westerholt <hw(a)gilawa.com> wrote:

Hello, Using http_async_query can change some script behaviour due to some side effects, I noticed this also e.g. on rtpengine functions. I did not looked into your cfg in details, but one easy option from your side would be to try a maintained Kamailio version (e.g. 5.7.x) and see if the problem also is observable there. Cheers, Henning *From:* Maharaja Azhagiah via sr-users <sr-users(a)lists.kamailio.org> *Sent:* Montag, 18. März 2024 22:21 *To:* Kamailio (SER) - Users Mailing List <sr-users(a)lists.kamailio.org> *Cc:* Maharaja Azhagiah <er.maharaja(a)gmail.com> *Subject:* [SR-Users] http_async_query on carrierfailureroute changes rd back to carrieroute primary Hi I am running kamailio 5.4 on debian I have carrierfailureroute configured incase of primary service provider fails. I also have Stirshaken configured to add Identity header on outbound calls. Issue is when call fail overs to carrierfailureroute, http_async_query changes $ru to the primary carrier From the debug logs, when primary carrier sends a 488 (primary carrier expects SIP TLS but my call is UDP - to test the failover scenario) 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} tmx [t_var.c:561]: pv_get_tm_reply_code(): reply code is <488> 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:178]: set_next_domain_on_rule(): searching for matching routing rules39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:197]: set_next_domain_on_rule(): next_domain is 47987 Carrier route rewrites the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:706]: cr_do_route(): uri 14371234567 was rewritten to sip:14371234567@sip.primaryprovider.com, carrier 1, domain 47987 Before http_async_query rd and ru are still the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2976] - Debug testing ----- rd is sip.primaryprovider.com ----- ru is sip:14371234567@sip.primaryprovider.com 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:469]: async_send_query(): transaction suspended [5261:1830449764] 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:625]: async_push_query(): query sent [ https://authn-uat.ccid.neustar.biz/ccid/authn/v2/identity?apiKey=randomkey] (0x7fdcad097e60) to worker 1 However, when the route is being called after the http_async_query it changes to the primary one: 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) DEBUG: http_async_client [async_http.c:235]: async_http_cb(): resuming transaction (5261:1830449764) 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) INFO: <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2995] - Debug testing ----- rd is 1.2.3.4 ----- ru is sip:14371234567@1.2.3.4:5061;transport=TLS Due to this, call keeps going to the primary and it fails if ( http_async_query(STIRSHAKEN_AS_URL, "AS_RESPONSE") == -1 ) { xlog("L_ERR ", "[cfg:$cfg(line)] Failed to connect AS service for token $fu -> $tu \n"); return; } route[AS_RESPONSE] { xlog("L_INFO", "[callid: $ci] - [cfg:$cfg(line)] - Debug testing ----- rd is $rd ----- ru is $ru\n"); if ($http_ok) { xlog("L_INFO", "[cfg:$cfg(line)] Resuming outbound call transaction for $fu -> $tu Received - $http_rb \n"); # Add identity and Date headers if (jansson_get("identity", $http_rb, "$var(identity)")) { insert_hf("Identity: $var(identity)\n", "Content-Length"); } if (jansson_get("date", $http_rb, "$var(date)")) { if ($hdr(Date) != $null){ remove_hf("Date"); } insert_hf("Date: $var(date)\n", "Identity"); } } else { xlog("L_ERR", "[cfg:$cfg(line)] Resuming outbound call transaction. Error - $http_err)\n"); } route(RELAY); exit; } Please help to understand why rd / ru changes to primary carrier. Regards, Maharaja Azhagiah

__________________________________________________________ Kamailio - Users Mailing List - Non Commercial Discussions To unsubscribe send an email to sr-users-leave(a)lists.kamailio.org Important: keep the mailing list in the recipients, do not reply only to the sender! Edit mailing list options or unsubscribe:

Maharaja Azhagiah

6:39 p.m.

Hi Federico, Yes, I tried to rewrite ruri after the http async reply and was able to send the call to the failover provider as expected. Thank you for your help :-) Regards *Maharaja Azhagiah* On Wed, Aug 7, 2024 at 10:26 AM Federico Cabiddu <federico.cabiddu(a)gmail.com> wrote:

...

Hi I have upgraded kamailio to 5.7.6 and I still see the issue when call failover to the provider configured carrierfailureroute, RURI changed back to the first / primary carrier Call fails due to 488 and rewrites to next carrier 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3] - [cfg:2624] (INVITE) RTF_CARRIERS (sip:14379892230@216.82.236.254:5061;transport=TLS) Called for outbound mazhagiah1test.sip.sandbox.com, RU: 14379892230, RD: 216.82.236.254, 488 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tm [t_lookup.c:1565]: t_check_msg(): msg (0x7ff946d395f8) id=0/160 global id=0/160 T start=0x7ff946d00f48 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tm [t_lookup.c:1641]: t_check_msg(): T (0x7ff946d00f48) already found for msg (0x7ff946d395f8)! 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tmx [t_var.c:554]: pv_get_tm_reply_code(): reply code is <488> 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:163]: set_next_domain_on_rule(): searching for matching routing rules36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:184]: set_next_domain_on_rule(): next_domain is 47987 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3] - [cfg:2633] (INVITE) r-uri (sip:14379892230@216.82.236.254:5061;transport=TLS) carrier_tree: outbound Next-lookup_domain: 47987 ----------------------- 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:449]: rewrite_on_rule(): searching for matching routing rules36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [prime_hash.c:66]: hash_func(): hash: 2729722775 % 1000 = 775 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:689]: ki_cr_do_route_helper(): uri 14379892230 was rewritten to sip:14379892230@sip.telnyx.com, carrier 1, domain 47987 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]-[cfg:2594] domain ( sip.telnyx.com) starts with TELNYX_SIP_TLD, checking hijacking 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]-[cfg:2600] domain postfix: com However, after http_async_query for stir/shaken header, RURI still remains with the primary carrier domain 26(184) DEBUG: pv [pv_core.c:1358]: pv_get_dsturi_attr(): no destination URI 26(184) WARNING: <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]{INVITE} - [RELAY] use udp/udp/1 Protocol strict relay dest:<null> RURI:sip:14379892230@216.82.236.254:5061;transport=TLS dest-proto:<null> ruri-proto:TLS next-hop Proto: TLS I am attaching the complete log. Please help to understand and fix this issue. Regards *Maharaja Azhagiah* On Tue, Mar 19, 2024 at 6:30 AM Henning Westerholt <hw(a)gilawa.com> wrote:

Hello, Using http_async_query can change some script behaviour due to some side effects, I noticed this also e.g. on rtpengine functions. I did not looked into your cfg in details, but one easy option from your side would be to try a maintained Kamailio version (e.g. 5.7.x) and see if the problem also is observable there. Cheers, Henning *From:* Maharaja Azhagiah via sr-users <sr-users(a)lists.kamailio.org> *Sent:* Montag, 18. März 2024 22:21 *To:* Kamailio (SER) - Users Mailing List <sr-users(a)lists.kamailio.org> *Cc:* Maharaja Azhagiah <er.maharaja(a)gmail.com> *Subject:* [SR-Users] http_async_query on carrierfailureroute changes rd back to carrieroute primary Hi I am running kamailio 5.4 on debian I have carrierfailureroute configured incase of primary service provider fails. I also have Stirshaken configured to add Identity header on outbound calls. Issue is when call fail overs to carrierfailureroute, http_async_query changes $ru to the primary carrier From the debug logs, when primary carrier sends a 488 (primary carrier expects SIP TLS but my call is UDP - to test the failover scenario) 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} tmx [t_var.c:561]: pv_get_tm_reply_code(): reply code is <488> 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:178]: set_next_domain_on_rule(): searching for matching routing rules39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:197]: set_next_domain_on_rule(): next_domain is 47987 Carrier route rewrites the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:706]: cr_do_route(): uri 14371234567 was rewritten to sip:14371234567@sip.primaryprovider.com, carrier 1, domain 47987 Before http_async_query rd and ru are still the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2976] - Debug testing ----- rd is sip.primaryprovider.com ----- ru is sip:14371234567@sip.primaryprovider.com 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:469]: async_send_query(): transaction suspended [5261:1830449764] 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:625]: async_push_query(): query sent [ https://authn-uat.ccid.neustar.biz/ccid/authn/v2/identity?apiKey=randomkey] (0x7fdcad097e60) to worker 1 However, when the route is being called after the http_async_query it changes to the primary one: 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) DEBUG: http_async_client [async_http.c:235]: async_http_cb(): resuming transaction (5261:1830449764) 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) INFO: <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2995] - Debug testing ----- rd is 1.2.3.4 ----- ru is sip:14371234567@1.2.3.4:5061;transport=TLS Due to this, call keeps going to the primary and it fails if ( http_async_query(STIRSHAKEN_AS_URL, "AS_RESPONSE") == -1 ) { xlog("L_ERR ", "[cfg:$cfg(line)] Failed to connect AS service for token $fu -> $tu \n"); return; } route[AS_RESPONSE] { xlog("L_INFO", "[callid: $ci] - [cfg:$cfg(line)] - Debug testing ----- rd is $rd ----- ru is $ru\n"); if ($http_ok) { xlog("L_INFO", "[cfg:$cfg(line)] Resuming outbound call transaction for $fu -> $tu Received - $http_rb \n"); # Add identity and Date headers if (jansson_get("identity", $http_rb, "$var(identity)")) { insert_hf("Identity: $var(identity)\n", "Content-Length"); } if (jansson_get("date", $http_rb, "$var(date)")) { if ($hdr(Date) != $null){ remove_hf("Date"); } insert_hf("Date: $var(date)\n", "Identity"); } } else { xlog("L_ERR", "[cfg:$cfg(line)] Resuming outbound call transaction. Error - $http_err)\n"); } route(RELAY); exit; } Please help to understand why rd / ru changes to primary carrier. Regards, Maharaja Azhagiah

Maharaja Azhagiah

6 Aug 6 Aug

5:11 p.m.

Hi I have upgraded kamailio to 5.7.6 and I still see the issue when call failover to the provider configured carrierfailureroute, RURI changed back to the first / primary carrier Call fails due to 488 and rewrites to next carrier 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3] - [cfg:2624] (INVITE) RTF_CARRIERS (sip:14379892230@216.82.236.254:5061;transport=TLS) Called for outbound mazhagiah1test.sip.sandbox.com, RU: 14379892230, RD: 216.82.236.254, 488 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tm [t_lookup.c:1565]: t_check_msg(): msg (0x7ff946d395f8) id=0/160 global id=0/160 T start=0x7ff946d00f48 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tm [t_lookup.c:1641]: t_check_msg(): T (0x7ff946d00f48) already found for msg (0x7ff946d395f8)! 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tmx [t_var.c:554]: pv_get_tm_reply_code(): reply code is <488> 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:163]: set_next_domain_on_rule(): searching for matching routing rules36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:184]: set_next_domain_on_rule(): next_domain is 47987 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3] - [cfg:2633] (INVITE) r-uri (sip:14379892230@216.82.236.254:5061;transport=TLS) carrier_tree: outbound Next-lookup_domain: 47987 ----------------------- 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:449]: rewrite_on_rule(): searching for matching routing rules36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [prime_hash.c:66]: hash_func(): hash: 2729722775 % 1000 = 775 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:689]: ki_cr_do_route_helper(): uri 14379892230 was rewritten to sip:14379892230@sip.telnyx.com, carrier 1, domain 47987 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]-[cfg:2594] domain (sip.telnyx.com) starts with TELNYX_SIP_TLD, checking hijacking 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]-[cfg:2600] domain postfix: com However, after http_async_query for stir/shaken header, RURI still remains with the primary carrier domain 26(184) DEBUG: pv [pv_core.c:1358]: pv_get_dsturi_attr(): no destination URI 26(184) WARNING: <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]{INVITE} - [RELAY] use udp/udp/1 Protocol strict relay dest:<null> RURI:sip:14379892230@216.82.236.254:5061;transport=TLS dest-proto:<null> ruri-proto:TLS next-hop Proto: TLS I have attached the log in the following link due to file size. https://drive.google.com/file/d/1dNS7Iyptz2x5evaVF-oSb-Erc4YIeuiW/view?usp=… Please help to understand and fix this issue. Regards *Maharaja Azhagiah* On Tue, Mar 19, 2024 at 6:30 AM Henning Westerholt <hw(a)gilawa.com> wrote:

...

Hello, Using http_async_query can change some script behaviour due to some side effects, I noticed this also e.g. on rtpengine functions. I did not looked into your cfg in details, but one easy option from your side would be to try a maintained Kamailio version (e.g. 5.7.x) and see if the problem also is observable there. Cheers, Henning *From:* Maharaja Azhagiah via sr-users <sr-users(a)lists.kamailio.org> *Sent:* Montag, 18. März 2024 22:21 *To:* Kamailio (SER) - Users Mailing List <sr-users(a)lists.kamailio.org> *Cc:* Maharaja Azhagiah <er.maharaja(a)gmail.com> *Subject:* [SR-Users] http_async_query on carrierfailureroute changes rd back to carrieroute primary Hi I am running kamailio 5.4 on debian I have carrierfailureroute configured incase of primary service provider fails. I also have Stirshaken configured to add Identity header on outbound calls. Issue is when call fail overs to carrierfailureroute, http_async_query changes $ru to the primary carrier From the debug logs, when primary carrier sends a 488 (primary carrier expects SIP TLS but my call is UDP - to test the failover scenario) 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} tmx [t_var.c:561]: pv_get_tm_reply_code(): reply code is <488> 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:178]: set_next_domain_on_rule(): searching for matching routing rules39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:197]: set_next_domain_on_rule(): next_domain is 47987 Carrier route rewrites the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:706]: cr_do_route(): uri 14371234567 was rewritten to sip:14371234567@sip.primaryprovider.com, carrier 1, domain 47987 Before http_async_query rd and ru are still the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2976] - Debug testing ----- rd is sip.primaryprovider.com ----- ru is sip:14371234567@sip.primaryprovider.com 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:469]: async_send_query(): transaction suspended [5261:1830449764] 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:625]: async_push_query(): query sent [ https://authn-uat.ccid.neustar.biz/ccid/authn/v2/identity?apiKey=randomkey] (0x7fdcad097e60) to worker 1 However, when the route is being called after the http_async_query it changes to the primary one: 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) DEBUG: http_async_client [async_http.c:235]: async_http_cb(): resuming transaction (5261:1830449764) 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) INFO: <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2995] - Debug testing ----- rd is 1.2.3.4 ----- ru is sip:14371234567@1.2.3.4:5061;transport=TLS Due to this, call keeps going to the primary and it fails if ( http_async_query(STIRSHAKEN_AS_URL, "AS_RESPONSE") == -1 ) { xlog("L_ERR ", "[cfg:$cfg(line)] Failed to connect AS service for token $fu -> $tu \n"); return; } route[AS_RESPONSE] { xlog("L_INFO", "[callid: $ci] - [cfg:$cfg(line)] - Debug testing ----- rd is $rd ----- ru is $ru\n"); if ($http_ok) { xlog("L_INFO", "[cfg:$cfg(line)] Resuming outbound call transaction for $fu -> $tu Received - $http_rb \n"); # Add identity and Date headers if (jansson_get("identity", $http_rb, "$var(identity)")) { insert_hf("Identity: $var(identity)\n", "Content-Length"); } if (jansson_get("date", $http_rb, "$var(date)")) { if ($hdr(Date) != $null){ remove_hf("Date"); } insert_hf("Date: $var(date)\n", "Identity"); } } else { xlog("L_ERR", "[cfg:$cfg(line)] Resuming outbound call transaction. Error - $http_err)\n"); } route(RELAY); exit; } Please help to understand why rd / ru changes to primary carrier. Regards, Maharaja Azhagiah

Maharaja Azhagiah

5:57 p.m.

Additional information. I have even upgraded to the latest kamailio version 5.8.2 with no luck in resolution on this issue. Regards *Maharaja Azhagiah* On Tue, Aug 6, 2024 at 10:11 AM Maharaja Azhagiah <er.maharaja(a)gmail.com> wrote:

...

Hi I have upgraded kamailio to 5.7.6 and I still see the issue when call failover to the provider configured carrierfailureroute, RURI changed back to the first / primary carrier Call fails due to 488 and rewrites to next carrier 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3] - [cfg:2624] (INVITE) RTF_CARRIERS (sip:14379892230@216.82.236.254:5061;transport=TLS) Called for outbound mazhagiah1test.sip.sandbox.com, RU: 14379892230, RD: 216.82.236.254, 488 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tm [t_lookup.c:1565]: t_check_msg(): msg (0x7ff946d395f8) id=0/160 global id=0/160 T start=0x7ff946d00f48 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tm [t_lookup.c:1641]: t_check_msg(): T (0x7ff946d00f48) already found for msg (0x7ff946d395f8)! 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tmx [t_var.c:554]: pv_get_tm_reply_code(): reply code is <488> 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:163]: set_next_domain_on_rule(): searching for matching routing rules36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:184]: set_next_domain_on_rule(): next_domain is 47987 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3] - [cfg:2633] (INVITE) r-uri (sip:14379892230@216.82.236.254:5061;transport=TLS) carrier_tree: outbound Next-lookup_domain: 47987 ----------------------- 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:449]: rewrite_on_rule(): searching for matching routing rules36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [prime_hash.c:66]: hash_func(): hash: 2729722775 % 1000 = 775 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:689]: ki_cr_do_route_helper(): uri 14379892230 was rewritten to sip:14379892230@sip.telnyx.com, carrier 1, domain 47987 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]-[cfg:2594] domain ( sip.telnyx.com) starts with TELNYX_SIP_TLD, checking hijacking 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]-[cfg:2600] domain postfix: com However, after http_async_query for stir/shaken header, RURI still remains with the primary carrier domain 26(184) DEBUG: pv [pv_core.c:1358]: pv_get_dsturi_attr(): no destination URI 26(184) WARNING: <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]{INVITE} - [RELAY] use udp/udp/1 Protocol strict relay dest:<null> RURI:sip:14379892230@216.82.236.254:5061;transport=TLS dest-proto:<null> ruri-proto:TLS next-hop Proto: TLS I have attached the log in the following link due to file size. https://drive.google.com/file/d/1dNS7Iyptz2x5evaVF-oSb-Erc4YIeuiW/view?usp=… Please help to understand and fix this issue. Regards *Maharaja Azhagiah* On Tue, Mar 19, 2024 at 6:30 AM Henning Westerholt <hw(a)gilawa.com> wrote:

Hello, Using http_async_query can change some script behaviour due to some side effects, I noticed this also e.g. on rtpengine functions. I did not looked into your cfg in details, but one easy option from your side would be to try a maintained Kamailio version (e.g. 5.7.x) and see if the problem also is observable there. Cheers, Henning *From:* Maharaja Azhagiah via sr-users <sr-users(a)lists.kamailio.org> *Sent:* Montag, 18. März 2024 22:21 *To:* Kamailio (SER) - Users Mailing List <sr-users(a)lists.kamailio.org> *Cc:* Maharaja Azhagiah <er.maharaja(a)gmail.com> *Subject:* [SR-Users] http_async_query on carrierfailureroute changes rd back to carrieroute primary Hi I am running kamailio 5.4 on debian I have carrierfailureroute configured incase of primary service provider fails. I also have Stirshaken configured to add Identity header on outbound calls. Issue is when call fail overs to carrierfailureroute, http_async_query changes $ru to the primary carrier From the debug logs, when primary carrier sends a 488 (primary carrier expects SIP TLS but my call is UDP - to test the failover scenario) 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} tmx [t_var.c:561]: pv_get_tm_reply_code(): reply code is <488> 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:178]: set_next_domain_on_rule(): searching for matching routing rules39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:197]: set_next_domain_on_rule(): next_domain is 47987 Carrier route rewrites the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:706]: cr_do_route(): uri 14371234567 was rewritten to sip:14371234567@sip.primaryprovider.com, carrier 1, domain 47987 Before http_async_query rd and ru are still the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2976] - Debug testing ----- rd is sip.primaryprovider.com ----- ru is sip:14371234567@sip.primaryprovider.com 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:469]: async_send_query(): transaction suspended [5261:1830449764] 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:625]: async_push_query(): query sent [ https://authn-uat.ccid.neustar.biz/ccid/authn/v2/identity?apiKey=randomkey] (0x7fdcad097e60) to worker 1 However, when the route is being called after the http_async_query it changes to the primary one: 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) DEBUG: http_async_client [async_http.c:235]: async_http_cb(): resuming transaction (5261:1830449764) 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) INFO: <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2995] - Debug testing ----- rd is 1.2.3.4 ----- ru is sip:14371234567@1.2.3.4:5061;transport=TLS Due to this, call keeps going to the primary and it fails if ( http_async_query(STIRSHAKEN_AS_URL, "AS_RESPONSE") == -1 ) { xlog("L_ERR ", "[cfg:$cfg(line)] Failed to connect AS service for token $fu -> $tu \n"); return; } route[AS_RESPONSE] { xlog("L_INFO", "[callid: $ci] - [cfg:$cfg(line)] - Debug testing ----- rd is $rd ----- ru is $ru\n"); if ($http_ok) { xlog("L_INFO", "[cfg:$cfg(line)] Resuming outbound call transaction for $fu -> $tu Received - $http_rb \n"); # Add identity and Date headers if (jansson_get("identity", $http_rb, "$var(identity)")) { insert_hf("Identity: $var(identity)\n", "Content-Length"); } if (jansson_get("date", $http_rb, "$var(date)")) { if ($hdr(Date) != $null){ remove_hf("Date"); } insert_hf("Date: $var(date)\n", "Identity"); } } else { xlog("L_ERR", "[cfg:$cfg(line)] Resuming outbound call transaction. Error - $http_err)\n"); } route(RELAY); exit; } Please help to understand why rd / ru changes to primary carrier. Regards, Maharaja Azhagiah

Federico Cabiddu

6:40 p.m.

Hi, a http_async_client resume route is internally a failure_route so the message is the one. of the first branch. You can try either to change $ru and $rd after the http reply or/and to do it in a branch_route. Hope this helps. Regards, Federico On Tue, Aug 6, 2024 at 5:33 PM Maharaja Azhagiah via sr-users < sr-users(a)lists.kamailio.org> wrote:

...

Hi I have upgraded kamailio to 5.7.6 and I still see the issue when call failover to the provider configured carrierfailureroute, RURI changed back to the first / primary carrier Call fails due to 488 and rewrites to next carrier 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3] - [cfg:2624] (INVITE) RTF_CARRIERS (sip:14379892230@216.82.236.254:5061;transport=TLS) Called for outbound mazhagiah1test.sip.sandbox.com, RU: 14379892230, RD: 216.82.236.254, 488 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tm [t_lookup.c:1565]: t_check_msg(): msg (0x7ff946d395f8) id=0/160 global id=0/160 T start=0x7ff946d00f48 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tm [t_lookup.c:1641]: t_check_msg(): T (0x7ff946d00f48) already found for msg (0x7ff946d395f8)! 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} tmx [t_var.c:554]: pv_get_tm_reply_code(): reply code is <488> 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:163]: set_next_domain_on_rule(): searching for matching routing rules36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:184]: set_next_domain_on_rule(): next_domain is 47987 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3] - [cfg:2633] (INVITE) r-uri (sip:14379892230@216.82.236.254:5061;transport=TLS) carrier_tree: outbound Next-lookup_domain: 47987 ----------------------- 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:449]: rewrite_on_rule(): searching for matching routing rules36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [prime_hash.c:66]: hash_func(): hash: 2729722775 % 1000 = 775 36(194) INFO: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} carrierroute [cr_func.c:689]: ki_cr_do_route_helper(): uri 14379892230 was rewritten to sip:14379892230@sip.telnyx.com, carrier 1, domain 47987 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]-[cfg:2594] domain ( sip.telnyx.com) starts with TELNYX_SIP_TLD, checking hijacking 36(194) DEBUG: {1 32676 INVITE P4GVS5mWnATVHneyX047QAx6Zv0ivpw3} <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]-[cfg:2600] domain postfix: com However, after http_async_query for stir/shaken header, RURI still remains with the primary carrier domain 26(184) DEBUG: pv [pv_core.c:1358]: pv_get_dsturi_attr(): no destination URI 26(184) WARNING: <script>: [callid: P4GVS5mWnATVHneyX047QAx6Zv0ivpw3]{INVITE} - [RELAY] use udp/udp/1 Protocol strict relay dest:<null> RURI:sip:14379892230@216.82.236.254:5061;transport=TLS dest-proto:<null> ruri-proto:TLS next-hop Proto: TLS I have attached the log in the following link due to file size. https://drive.google.com/file/d/1dNS7Iyptz2x5evaVF-oSb-Erc4YIeuiW/view?usp=… Please help to understand and fix this issue. Regards *Maharaja Azhagiah* On Tue, Mar 19, 2024 at 6:30 AM Henning Westerholt <hw(a)gilawa.com> wrote:

Hello, Using http_async_query can change some script behaviour due to some side effects, I noticed this also e.g. on rtpengine functions. I did not looked into your cfg in details, but one easy option from your side would be to try a maintained Kamailio version (e.g. 5.7.x) and see if the problem also is observable there. Cheers, Henning *From:* Maharaja Azhagiah via sr-users <sr-users(a)lists.kamailio.org> *Sent:* Montag, 18. März 2024 22:21 *To:* Kamailio (SER) - Users Mailing List <sr-users(a)lists.kamailio.org> *Cc:* Maharaja Azhagiah <er.maharaja(a)gmail.com> *Subject:* [SR-Users] http_async_query on carrierfailureroute changes rd back to carrieroute primary Hi I am running kamailio 5.4 on debian I have carrierfailureroute configured incase of primary service provider fails. I also have Stirshaken configured to add Identity header on outbound calls. Issue is when call fail overs to carrierfailureroute, http_async_query changes $ru to the primary carrier From the debug logs, when primary carrier sends a 488 (primary carrier expects SIP TLS but my call is UDP - to test the failover scenario) 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} tmx [t_var.c:561]: pv_get_tm_reply_code(): reply code is <488> 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:178]: set_next_domain_on_rule(): searching for matching routing rules39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:197]: set_next_domain_on_rule(): next_domain is 47987 Carrier route rewrites the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} carrierroute [cr_func.c:706]: cr_do_route(): uri 14371234567 was rewritten to sip:14371234567@sip.primaryprovider.com, carrier 1, domain 47987 Before http_async_query rd and ru are still the failover carrier 39(285) INFO: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2976] - Debug testing ----- rd is sip.primaryprovider.com ----- ru is sip:14371234567@sip.primaryprovider.com 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:469]: async_send_query(): transaction suspended [5261:1830449764] 39(285) DEBUG: {1 18398 INVITE 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn} http_async_client [async_http.c:625]: async_push_query(): query sent [ https://authn-uat.ccid.neustar.biz/ccid/authn/v2/identity?apiKey=randomkey] (0x7fdcad097e60) to worker 1 However, when the route is being called after the http_async_query it changes to the primary one: 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) DEBUG: http_async_client [async_http.c:235]: async_http_cb(): resuming transaction (5261:1830449764) 26(272) DEBUG: tm [t_lookup.c:1612]: t_lookup_ident_filter(): transaction found 26(272) INFO: <script>: [callid: 8EmmsLqNuMRYBduMqFgX3w4JHAn4C2xn] - [cfg:2995] - Debug testing ----- rd is 1.2.3.4 ----- ru is sip:14371234567@1.2.3.4:5061;transport=TLS Due to this, call keeps going to the primary and it fails if ( http_async_query(STIRSHAKEN_AS_URL, "AS_RESPONSE") == -1 ) { xlog("L_ERR ", "[cfg:$cfg(line)] Failed to connect AS service for token $fu -> $tu \n"); return; } route[AS_RESPONSE] { xlog("L_INFO", "[callid: $ci] - [cfg:$cfg(line)] - Debug testing ----- rd is $rd ----- ru is $ru\n"); if ($http_ok) { xlog("L_INFO", "[cfg:$cfg(line)] Resuming outbound call transaction for $fu -> $tu Received - $http_rb \n"); # Add identity and Date headers if (jansson_get("identity", $http_rb, "$var(identity)")) { insert_hf("Identity: $var(identity)\n", "Content-Length"); } if (jansson_get("date", $http_rb, "$var(date)")) { if ($hdr(Date) != $null){ remove_hf("Date"); } insert_hf("Date: $var(date)\n", "Identity"); } } else { xlog("L_ERR", "[cfg:$cfg(line)] Resuming outbound call transaction. Error - $http_err)\n"); } route(RELAY); exit; } Please help to understand why rd / ru changes to primary carrier. Regards, Maharaja Azhagiah

__________________________________________________________

Kamailio - Users Mailing List - Non Commercial Discussions To unsubscribe send an email to sr-users-leave(a)lists.kamailio.org Important: keep the mailing list in the recipients, do not reply only to the sender! Edit mailing list options or unsubscribe:

107

days inactive

249

days old

sr-users@lists.kamailio.org

Manage subscription

7 comments

3 participants

tags (0)

participants (3)

Federico Cabiddu
Henning Westerholt
Maharaja Azhagiah