Effect of GRUU on the behavior of loose_route() - sr-users

21 Jan 2022


      Hello!
I ask for help in explaining the different behavior of loose_route()
function in two similar cases (depending on GRUU parameter on the end
device).
The call path goes through a series of Proxies:
Proxy Registrar (use Path) -> Proxy Edge -> PhonerLite (GRUU on/off).
If the GRUU parameter is enabled on the PhonerLite, then the in-dialog SIP
ACK (on 200 OK/SDP) message is routed on the Proxy Edge successfully
(loose_route() deletes Route and handle_ruri_alias() sets $du).
When GRUU is disabled - loose_route() for some reason replaces RURI (but
lr=on ?) and sets $du.
The configuration of the [WITHINDLG] route section is similar to the
default script.
IP: 1.1.1.1 is the Proxy Registrar
IP: 2.2.2.2 is the Proxy Edge
IP: 3.3.3.3 is the Phone (Phoner Lite)
Successful case (GRUU enabled):
2022/01/21 20:08:20.745859 1.1.1.1:5060 -> 2.2.2.2:5060
ACK sip:userid@2.2.2.2:5060;gr=009356C7-5A79-EC11-8468-538E88103B96;alias=3.3.3.3~5065~1
SIP/2.0
Via: SIP/2.0/UDP
1.1.1.1;branch=z9hG4bK0a34.0bcc52c86238bd3a73bd88712c562d10.0
Via: SIP/2.0/UDP
10.60.27.126;rport=5060;branch=z9hG4bK0a34.1bb19d987d7566fe74d300766284d73a.0
Via: SIP/2.0/UDP 10.60.27.84:5080
;received=10.60.27.84;branch=z9hG4bKkr2inaF~;rport=5080
From: "Denys VOIP" sip:5009@1.1.1.1;tag=41A6E617-61EB049F000008A2-86EEE700
To: sip:userid@10.60.27.84;tag=00fd16295b79ec118469538e88103b96
CSeq: 10 ACK
Call-ID: 537f0686-f590-123a-ffb5-001dd8b71cb2_userid
Route: sip:2.2.2.2;lr=on;nat=yes;did=28c.4fa
Max-Forwards: 63
Contact: sip:10.60.27.84:5080;transport=udp
Content-Length: 0
2022/01/21 20:08:20.746952 2.2.2.2:5060 -> 3.3.3.3:5065
ACK sip:userid@2.2.2.2:5060;gr=009356C7-5A79-EC11-8468-538E88103B96 SIP/2.0
Via: SIP/2.0/UDP
2.2.2.2;branch=z9hG4bK0a34.2b5076a5473cc42d883bf38969aa7dcf.0
Via: SIP/2.0/UDP
1.1.1.1;rport=5060;branch=z9hG4bK0a34.0bcc52c86238bd3a73bd88712c562d10.0
Via: SIP/2.0/UDP
10.60.27.126;rport=5060;branch=z9hG4bK0a34.1bb19d987d7566fe74d300766284d73a.0
Via: SIP/2.0/UDP 10.60.27.84:5080
;received=10.60.27.84;branch=z9hG4bKkr2inaF~;rport=5080
From: "Denys VOIP" sip:5009@1.1.1.1;tag=41A6E617-61EB049F000008A2-86EEE700
To: sip:userid@10.60.27.84;tag=00fd16295b79ec118469538e88103b96
CSeq: 10 ACK
Call-ID: 537f0686-f590-123a-ffb5-001dd8b71cb2_userid
Max-Forwards: 62
Contact: sip:10.60.27.84:5080;transport=udp
Content-Length: 0
DEBUG:
 3(11755) DEBUG: rr [loose.c:85]: is_preloaded(): is_preloaded: No
 3(11755) DEBUG: <core> [core/socket_info.c:646]: grep_sock_info():
checking if host==us: 13==13 && [2.2.2.2] == [2.2.2.2]
 3(11755) DEBUG: <core> [core/socket_info.c:649]: grep_sock_info():
checking if port 5060 (advertise 0) matches port 5060
 3(11755) DEBUG: <core> [core/forward.c:429]: check_self(): host (0:
2.2.2.2:5060) == me
 3(11755) DEBUG: <core> [core/socket_info.c:646]: grep_sock_info():
checking if host==us: 13==13 && [2.2.2.2] == [2.2.2.2]
 3(11755) DEBUG: <core> [core/socket_info.c:649]: grep_sock_info():
checking if port 5060 (advertise 0) matches port 5060
 3(11755) DEBUG: <core> [core/forward.c:429]: check_self(): host (0:
2.2.2.2:5060) == me
 3(11755) DEBUG: rr [loose.c:856]: after_loose(): Topmost route URI:
'sip:2.2.2.2;lr=on;nat=yes;did=28c.4fa' is me
 3(11755) DEBUG: <core> [core/parser/msg_parser.c:91]: get_hdr_field():
found end of header
 3(11755) DEBUG: rr [loose.c:181]: find_next_route(): No next Route HF found
 3(11755) DEBUG: rr [loose.c:886]: after_loose(): No next URI found
 3(11755) DEBUG: rr [rr_cb.c:95]: run_rr_callbacks(): callback id 1 entered
with <lr=on;nat=yes;did=28c.4fa>
 3(11755) DEBUG: path [path.c:397]: path_rr_callback(): no received
parameter in route header
 3(11755) DEBUG: rr [rr_cb.c:95]: run_rr_callbacks(): callback id 0 entered
with <lr=on;nat=yes;did=28c.4fa>
 3(11755) DEBUG: nathelper [nathelper.c:1202]: handle_ruri_alias(): setting
dst_uri to sip:3.3.3.3:5065
 3(11755) DEBUG: nathelper [nathelper.c:1224]: handle_ruri_alias():
rewriting r-uri to sip:userid@2.2.2.2:5060
;gr=009356C7-5A79-EC11-8468-538E88103B96
Unsuccessful case (GRUU disabled):
2022/01/21 20:08:47.851170 1.1.1.1:5060 -> 2.2.2.2:5060
ACK sip:userid@2.2.2.2:5060;alias=3.3.3.3~5065~1 SIP/2.0
Via: SIP/2.0/UDP
1.1.1.1;branch=z9hG4bK110e.a47bb0e8f6d6d99a10ae36eb25d2f665.0
Via: SIP/2.0/UDP
10.60.27.126;rport=5060;branch=z9hG4bK110e.4d82c337912ca1187474aa2474a7d563.0
Via: SIP/2.0/UDP 10.60.27.84:5080
;received=10.60.27.84;branch=z9hG4bK4bKmGaAy;rport=5080
From: "Denys VOIP" sip:5009@1.1.1.1;tag=0FBBBFFE-61EB04BB000A3B4F-86EEE700
To: sip:userid@10.60.27.84;tag=80dc2e395b79ec11846d538e88103b96
CSeq: 10 ACK
Call-ID: 64957c76-f590-123a-ffb5-001dd8b71cb2_userid
Route: sip:2.2.2.2;lr=on;nat=yes;did=3f8.6a83
Max-Forwards: 63
Contact: sip:10.60.27.84:5080;transport=udp
Content-Length: 0
2022/01/21 20:08:47.851963 2.2.2.2:5060 -> 2.2.2.2:5060
ACK sip:2.2.2.2;lr=on;nat=yes;did=3f8.6a83 SIP/2.0
Via: SIP/2.0/UDP
2.2.2.2;branch=z9hG4bK110e.af605388ece54d48387c1de53615d894.0
Via: SIP/2.0/UDP
1.1.1.1;rport=5060;branch=z9hG4bK110e.a47bb0e8f6d6d99a10ae36eb25d2f665.0
Via: SIP/2.0/UDP
10.60.27.126;rport=5060;branch=z9hG4bK110e.4d82c337912ca1187474aa2474a7d563.0
Via: SIP/2.0/UDP 10.60.27.84:5080
;received=10.60.27.84;branch=z9hG4bK4bKmGaAy;rport=5080
From: "Denys VOIP" sip:5009@1.1.1.1;tag=0FBBBFFE-61EB04BB000A3B4F-86EEE700
To: sip:userid@10.60.27.84;tag=80dc2e395b79ec11846d538e88103b96
CSeq: 10 ACK
Call-ID: 64957c76-f590-123a-ffb5-001dd8b71cb2_userid
Max-Forwards: 62
Contact: sip:10.60.27.84:5080;transport=udp
Content-Length: 0
DEBUG:
 1(11753) DEBUG: rr [loose.c:85]: is_preloaded(): is_preloaded: No
 1(11753) DEBUG: <core> [core/socket_info.c:646]: grep_sock_info():
checking if host==us: 13==13 && [2.2.2.2] == [2.2.2.2]
 1(11753) DEBUG: <core> [core/socket_info.c:649]: grep_sock_info():
checking if port 5060 (advertise 0) matches port 5060
 1(11753) DEBUG: <core> [core/forward.c:429]: check_self(): host (0:
2.2.2.2:5060) == me
 1(11753) DEBUG: rr [loose.c:676]: after_strict(): Next hop:
'sip:2.2.2.2;lr=on;nat=yes;did=3f8.6a83' is loose router
 1(11753) DEBUG: rr [loose.c:726]: after_strict(): The last route URI:
'sip:2.2.2.2;lr=on;nat=yes;did=3f8.6a83'
 1(11753) DEBUG: rr [rr_cb.c:95]: run_rr_callbacks(): callback id 1 entered
with <alias=3.3.3.3~5065~1>
 1(11753) DEBUG: path [path.c:397]: path_rr_callback(): no received
parameter in route header
 1(11753) DEBUG: rr [rr_cb.c:95]: run_rr_callbacks(): callback id 0 entered
with <alias=3.3.3.3~5065~1>
 1(11753) DEBUG: rr [record.c:977]: add_rr_param():
rr_param_buf=<;did=3f8.6a83>
 1(11753) DEBUG: siputils [checks.c:123]: has_totag(): totag found
 1(11753) DEBUG: siputils [checks.c:123]: has_totag(): totag found
 1(11753) DEBUG: tm [t_lookup.c:1329]: t_newtran(): msg (0x7efe343f4998)
id=11/11753 global id=10/11753 T start=0xffffffffffffffff
 1(11753) DEBUG: tm [t_lookup.c:498]: t_lookup_request(): start searching:
hash=57361, isACK=1
 1(11753) DEBUG: tm [t_lookup.c:456]: matching_3261(): RFC3261 transaction
matching failed - via branch
[z9hG4bK110e.a47bb0e8f6d6d99a10ae36eb25d2f665.0]
 1(11753) DEBUG: tm [t_lookup.c:675]: t_lookup_request(): no transaction
found
 1(11753) DEBUG: tm [t_funcs.c:286]: t_relay_to(): forwarding ACK
statelessly
--
BR,
Denys Pozniak