While I'm hardpressed to say exactly why, it does seem like your structure is a bit odd.

You show this as in your route - is this also after checking for a to: tag?  The decision to send a 300 reply from within a route named "RELAY" after arming the failure and onreply routes is awkward.  Finally, although the exit at the end of route[RELAY] is implied is it intended to be explicit if the method is INVITE?  Adding curly braces there may not be necessary, but it does improve readability.


Kaufman
Senior Voice Engineer



E: bkaufman@bcmone.com




 

SIP.US Client Support: 800.566.9810  |  SIPTRUNK Client Support: 800.250.6510  |  Flowroute Client Support: 855.356.9768

img
img
img
 


From: Sergio Charrua <sergio.charrua@voip.pt>
Sent: Monday, December 23, 2024 5:04 PM
To: Kamailio (SER) - Users Mailing List <sr-users@lists.kamailio.org>
Cc: Alexis Fidalgo <alzrck@gmail.com>; Ben Kaufman <bkaufman@bcmone.com>
Subject: Re: [SR-Users] Re: help on how to get ACK
 

CAUTION: This email originated from outside the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe.


Well, in my case I have:

route{
...
  if ( is_method("ACK") ) {
if ( t_check_trans() ) {
# no loose-route, but stateful ACK;
# must be an ACK after a 487
# or e.g. 404 from upstream server
xlog("L_INFO","ACK - t_check_trans \n"); 
route(RELAY);
exit;
} else {
# ACK without matching transaction ... ignore and discard
xlog("L_INFO","ACK without matching transaction \n");
exit;
}
}
}
route[RELAY] {
    xlog("L_INFO", " ******** RELAY *******");
    xlog("L_INFO", "RELAY - $rm to $si responding back to $su");
t_on_failure("FAILED_RELAY");
t_on_reply("MANAGE_REPLY");
if (is_method("INVITE")) 
send_reply("300", "Multiple Choices");
exit;
}

Via: SIP/2.0/UDP 10.20.0.1:5060;branch=z9hG4bK-3356440-1-0

SIP/2.0 100 trying -- your call is important to us
Via: SIP/2.0/UDP 10.20.0.1:5060;branch=z9hG4bK-3356440-1-0

(here I am testing a HTTP failure test case)
SIP/2.0 503 No Connection to HTTP API
Via: SIP/2.0/UDP 10.20.0.1:5060;branch=z9hG4bK-3356440-1-0

Via: SIP/2.0/UDP 10.20.0.1:5060;branch=z9hG4bK-3356440-1-0

But after this ACK, Kamailio sends:
SIP/2.0 500 I'm terribly sorry, server error occurred (1/TM)
Via: SIP/2.0/UDP 10.20.0.1:5060;branch=z9hG4bK-3356440-1-0

Logs are weird too (debug = 3)
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field(): found end of header
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: {1 1 ACK 1-3356440@10.20.0.1} <core> [core/receive.c:263]: ksr_evrt_pre_routing(): event route core:pre-routing not defined
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: {1 1 ACK 1-3356440@10.20.0.1} <core> [core/receive.c:474]: receive_msg(): preparing to run routing scripts...
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: {1 1 ACK 1-3356440@10.20.0.1} sl [sl_funcs.c:472]: sl_filter_ACK(): SL local ACK found -> dropping it!
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: {1 1 ACK 1-3356440@10.20.0.1} <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: {1 1 ACK 1-3356440@10.20.0.1} <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: {1 1 ACK 1-3356440@10.20.0.1} <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: {1 1 ACK 1-3356440@10.20.0.1} <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: {1 1 ACK 1-3356440@10.20.0.1} <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: {1 1 ACK 1-3356440@10.20.0.1} <core> [core/usr_avp.c:654]: destroy_avp_list(): destroying list (nil)
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: {1 1 ACK 1-3356440@10.20.0.1} <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil)
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: {1 1 ACK 1-3356440@10.20.0.1} <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil)
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: {1 1 ACK 1-3356440@10.20.0.1} <core> [core/xavp.c:630]: xavp_destroy_list(): destroying xavp list (nil)
Dec 23 22:59:38 kamailio1 kamailio[4060752]: DEBUG: {1 1 ACK 1-3356440@10.20.0.1} <core> [core/receive.c:635]: receive_msg(): cleaning up
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: <core> [db_query.c:72]: db_do_submit_query(): submitted query: delete from `dialog` where `hash_entry`=3272 AND `hash_id`=10103, result 0
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: db_cluster [dbcl_api.c:663]: db_cluster_use_table(): use table (dialog_vars) - cluster [k1]
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: db_cluster [dbcl_api.c:670]: db_cluster_use_table(): set read table (dialog_vars) - cluster [k1] (9/0)
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: db_cluster [dbcl_api.c:680]: db_cluster_use_table(): set write table (dialog_vars) - cluster [k1] (9/0)
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: db_cluster [dbcl_api.c:570]: db_cluster_delete(): executing db cluster delete command
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: db_cluster [dbcl_api.c:571]: db_cluster_delete(): round robin operation - cluster [k1] (9/0)
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: <core> [db_query.c:72]: db_do_submit_query(): submitted query: delete from `dialog_vars` where `hash_entry`=3272 AND `hash_id`=10103, result 0
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: dialog [dlg_db_handler.c:759]: remove_dialog_from_db(): callid was 1-3356440@10.20.0.1
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: tm [h_table.c:551]: tm_xdata_swap(): restore X/AVPs msg context from txdata
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: tm [t_reply.c:1782]: cleanup_uac_timers(): RETR/FR timers reset
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: tm [t_reply.c:634]: _reply_light(): reply sent out - buf=0x7f4903fd57d0: SIP/2.0 500 I'm terr... shmem=0x7f48c27177a0: SIP/2.0 500 I'm terr
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: tm [t_funcs.c:133]: put_on_wait(): put T [0x7f48c271cda0] on wait
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: tm [t_reply.c:650]: _reply_light(): finished
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: http_async_client [async_http.h:153]: free_async_query(): freeing query 0x7f48c27229b0
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: http_async_client [http_multi.c:661]: check_multi_info(): reply: [428] HTTP/1.0 428 PRECONDITION REQUIRED#015#012Content-Type: text/html; charset=utf-8#015#012Content-Length: 138#015#012Server: Werkzeug/2.0.3 Python/3.9.16#015#012Date: Mon, 23 Dec 2024 22:59:09 GMT#015#012#015#012<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 3.2 Final//EN">#012<title>428 Precondition Required</title>#012<h1>Precondition Required</h1>#012<p>{}</p>#012 [312]
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: http_async_client [http_multi.c:668]: check_multi_info(): cleaning up cell 0x7f48c2722d30
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: http_async_client [http_multi.c:673]: check_multi_info(): Removing handle 0x7f48c2717e80
Dec 23 22:59:38 kamailio1 kamailio[4060844]: DEBUG: http_async_client [http_multi.c:150]: event_cb(): last transfer done, kill timeout
Dec 23 22:59:39 kamailio1 kamailio[4060839]: DEBUG: tm [t_funcs.c:133]: put_on_wait(): put T [0x7f48c271cda0] on wait
Dec 23 22:59:39 kamailio1 kamailio[4060839]: DEBUG: <core> [core/timer.c:555]: timer_add_safe(): timer_add called on an active timer 0x7f48c271ce58 (0x7f48c2225bc0, 0x7f48c2225bc0), flags 201
Dec 23 22:59:39 kamailio1 kamailio[4060839]: DEBUG: tm [t_funcs.c:156]: put_on_wait(): transaction 0x7f48c271cda0 already on wait

Running same SIP Invite from SIPp but with test case where HTTP API returns a valid (200) response, everything works fine!


Atenciosamente / Kind Regards / Cordialement / Un saludo,


Sérgio Charrua


On Mon, Dec 23, 2024 at 11:49 PM Ben Kaufman via sr-users <sr-users@lists.kamailio.org> wrote:
Which log line do you get?  Also note that both of your log lines say "Matched transaction", but the condition is negated (it starts with an exclamation mark).

Also refer to the documentation for the function to see what happens when the ACK for a negative reply is matched.


Kaufman
Senior Voice Engineer



E: bkaufman@bcmone.com




 

SIP.US Client Support: 800.566.9810  |  SIPTRUNK Client Support: 800.250.6510  |  Flowroute Client Support: 855.356.9768

img
img
img
 


From: Alexis Fidalgo via sr-users <sr-users@lists.kamailio.org>
Sent: Monday, December 23, 2024 4:16 PM
To: Kamailio (SER) - Users Mailing List <sr-users@lists.kamailio.org>
Cc: Alexis Fidalgo <alzrck@gmail.com>
Subject: [SR-Users] Re: help on how to get ACK
 
CAUTION: This email originated from outside the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe.


Yes, i’ve been reading it when you mentioned the loose_route and has_totag() in a previous email.

        if(is_method("ACK")){
                if(!t_check_trans()){
                xlog("L_INFO","AAAA: MATCHED TRANSACTION\n");
                } else {
                xlog("L_INFO","BBBB: MATCHED TRANSACTION\n");
                }
                exit;
        }

(moving the exit; inside the else has same effect on my test)


> On 23 Dec 2024, at 6:49 PM, Alex Balashov via sr-users <sr-users@lists.kamailio.org> wrote:
>
> Look very carefully at how negative ACKs are handled here:
>
> https://nam11.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fkamailio%2Fkamailio%2Fblob%2Fmaster%2Fetc%2Fkamailio.cfg%23L716&data=05%7C02%7Cbkaufman%40bcmone.com%7C344d8fe5f8604da6709608dd23a04195%7Cafc1818e7b6848568913201b9396c4fc%7C1%7C0%7C638705893409762065%7CUnknown%7CTWFpbGZsb3d8eyJFbXB0eU1hcGkiOnRydWUsIlYiOiIwLjAuMDAwMCIsIlAiOiJXaW4zMiIsIkFOIjoiTWFpbCIsIldUIjoyfQ%3D%3D%7C0%7C%7C%7C&sdata=pWUV9HfUBdFYItGmXv9lpUOYmWXHJdrquEnfXWAl6Kg%3D&reserved=0
>
> -- Alex
>
>> On Dec 23, 2024, at 4:19 pm, Alexis Fidalgo via sr-users <sr-users@lists.kamailio.org> wrote:
>>
>> Hello all, moving just a bit aside of the http and async_http.
>>
>> After all the real useful and interesting thread on that topic what helped me, im facing a problem i cant deal with and need a hint at least.
>>
>> Scenario
>>
>> INVITE -> Kamailio
>>
>> on request_route
>> ...
>> if(is_method("INVITE")){
>> t_newtran();
>> http_async_query("http://nuc:8080", "HTTP_REPLY");
>> }
>> …
>>
>> Kamailio -> 100 - Trying
>>
>>
>> then
>>
>> route[HTTP_REPLY] {
>>   if ($http_ok) {
>>       xlog("L_INFO", "route[HTTP_REPLY]: status $http_rs\n");
>>       xlog("L_INFO", "route[HTTP_REPLY]: body   $http_rb\n");
>> t_reply(302,"Redirect");
>>   } else {
>>       xlog("L_INFO", "route[HTTP_REPLY]: error  $http_err)\n");
>>   }
>> }
>>
>> Kamailio -> 302 Redirect
>> ACK -> Kamailio
>>
>> This last ACK, how can i read it and use it to terminate the transaction? because Kamailio keeps transmitting the 302 message 3 more times until the transaction is finished by a timer
>>
>> 42(44) DEBUG: tm [t_reply.c:1723]: t_retransmit_reply(): reply retransmitted. buf=0x7f4c44f9d680: SIP/2.0 3..., shmem=0x7f4c3fce7900: SIP/2.0 3
>> 42(44) DEBUG: tm [t_reply.c:1723]: t_retransmit_reply(): reply retransmitted. buf=0x7f4c44f9d680: SIP/2.0 3..., shmem=0x7f4c3fce7900: SIP/2.0 3
>> 42(44) DEBUG: tm [t_reply.c:1723]: t_retransmit_reply(): reply retransmitted. buf=0x7f4c44f9d680: SIP/2.0 3..., shmem=0x7f4c3fce7900: SIP/2.0 3
>> 42(44) DEBUG: tm [timer.c:642]: wait_handler(): finished transaction: 0x7f4c3fcd35a0 (p:0x7f4c3fad85d0/n:0x7f4c3fad85d0)
>> 42(44) DEBUG: tm [h_table.c:133]: free_cell_helper(): freeing transaction 0x7f4c3fcd35a0 from timer.c:651
>>
>>
>> in request_route i have
>>
>> if(is_method("ACK")){
>> if(!t_check_trans()){
>> t_release();
>> }
>> exit;
>> }
>>
>>
>> __________________________________________________________
>> Kamailio - Users Mailing List - Non Commercial Discussions -- sr-users@lists.kamailio.org
>> To unsubscribe send an email to sr-users-leave@lists.kamailio.org
>> Important: keep the mailing list in the recipients, do not reply only to the sender!
>
> --
> Alex Balashov
> Principal Consultant
> Evariste Systems LLC
> Web: https://nam11.safelinks.protection.outlook.com/?url=https%3A%2F%2Fevaristesys.com%2F&data=05%7C02%7Cbkaufman%40bcmone.com%7C344d8fe5f8604da6709608dd23a04195%7Cafc1818e7b6848568913201b9396c4fc%7C1%7C0%7C638705893409783811%7CUnknown%7CTWFpbGZsb3d8eyJFbXB0eU1hcGkiOnRydWUsIlYiOiIwLjAuMDAwMCIsIlAiOiJXaW4zMiIsIkFOIjoiTWFpbCIsIldUIjoyfQ%3D%3D%7C0%7C%7C%7C&sdata=OjJMQi9y1SfE4Vkkbd58SiGGHACvEFYRohAxXKZaFW0%3D&reserved=0
> Tel: +1-706-510-6800
>
> __________________________________________________________
> Kamailio - Users Mailing List - Non Commercial Discussions -- sr-users@lists.kamailio.org
> To unsubscribe send an email to sr-users-leave@lists.kamailio.org
> Important: keep the mailing list in the recipients, do not reply only to the sender!

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