10 May
2024
10 May
'24
5:24 a.m.
Hi all!
Solved the issue by using s.decode.base64t instead of s.decode.base64 ...
Thanks anyway!
*Sérgio Charrua*
On Fri, May 10, 2024 at 9:40 AM Sergio Charrua <sergio.charrua(a)voip.pt>
wrote:
Hi all!
I have been dealing with STIR/SHAKEN for a few weeks now, and while doing
some tests I have found an issue which I can't find the reason for.
The script has the following route logic:
route[HANDLE_STIRSHAKEN]
{
xlog("L_INFO", "HANDLE_STIRSHAKEN - STIR/SHAKEN Logic");
if ($hdrc(Identity) == 0 ){
xlog("L_INFO", "HANDLE_STIRSHAKEN - No Identity Header ->
Skipping
this logic");
return;
}
#Verify Call Identity
xlog("L_INFO", "HANDLE_STIRSHAKEN - Identity Header:
$hdr(Identity)");
$var(header_1)= $(hdr(Identity){s.select,0,.});
$var(header_2)= $(hdr(Identity){s.select,1,.});
xlog("L_INFO", "HANDLE_STIRSHAKEN - Encoded Header 1:
$var(header_1)");
xlog("L_INFO", "HANDLE_STIRSHAKEN - Encoded Header 2:
$var(header_2)");
xlog("L_INFO", "HANDLE_STIRSHAKEN - Decoded Header 1:
$(var(header_1){s.decode.base64})");
xlog("L_INFO", "HANDLE_STIRSHAKEN - Decoded Header 2:
$(var(header_2){s.decode.base64})");
xlog("L_INFO", "HANDLE_STIRSHAKEN - Parsing!");
$var(hdr_1_json_payload) = $(var(header_1){s.decode.base64}); # Header
1
xlog("L_INFO", "HANDLE_STIRSHAKEN - Parsed!");
xlog("L_INFO", "HANDLE_STIRSHAKEN - Header 1 payload =
$var(hdr_1_json_payload) ");
$var(hdr_2_json_payload) = $(var(header_2){s.decode.base64}); # Header
2
jansson_get_field($var(hdr_2_json_payload), "attest",
"$var(attest_value)");
jansson_get_field($var(hdr_2_json_payload), "ppt",
"$var(ppt_value)");
jansson_get_field($var(hdr_2_json_payload), "typ",
"$var(typ_value)");
jansson_get_field($var(hdr_2_json_payload), "x5u",
"$var(x5u_value)");
xlog("L_INFO", "HANDLE_STIRSHAKEN - $var(attest_value)
$var(ppt_value)
$var(typ_value) $var(x5u_value) ");
}
All it does is parse the Identity header received on the initial INVITE,
decodes it (it is encoded in base64) and writes some JSON values on log.
Nothing serious....
As the Identity header is divided into multiple parts, separated by a ".",
I get the first 2 parts in 2 private variables, as per lines:
$var(header_1)= $(hdr(Identity){s.select,0,.});
$var(header_2)= $(hdr(Identity){s.select,1,.});
Logs show correctly that both variables are populated:
May 10 09:09:42 kamailio1 kamailio[153201]: INFO: {1 10 INVITE
1-1966540(a)10.20.0.1} <script>: HANDLE_STIRSHAKEN - Encoded Header 1:
eyJhbGciOiAiRVMyNTYiLCJwcHQiOiAic2hha2VuIiwidHlwIjogInBhc3Nwb3J0IiwieDV1IjogImh0dHBzOi8vY2VydGlmaWNh
dGVzLmNsZWFyaXAuY29tL2IxNWQ3Y2M5LTBmMjYtNDZjMi04M2VhLWEzZTYzYTgyZWMzYS83Y2M0ZGI2OTVkMTNlZGFkYTRkMWY5ODYxYjliODBmZS5jcnQifQ
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/parser/msg_parser.c:324]:
parse_headers(): flags=ffffffffffffffff
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 34
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/parser/msg_parser.c:324]:
parse_headers(): flags=ffffffffffffffff
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 34
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 230
May 10 09:09:42 kamailio1 kamailio[153201]: INFO: {1 10 INVITE
1-1966540(a)10.20.0.1} <script>: HANDLE_STIRSHAKEN - Encoded Header 2:
eyJhdHRlc3QiOiAiQSIsImRlc3QiOiB7InRuIjogWyIxNDA0NTI2NjA2MCJdfSwiaWF0IjogMTU0ODg1OTk4Miwib3JpZyI6IHsi
dG4iOiAiMTgwMDEyMzQ1NjcifSwib3JpZ2lkIjogIjNhNDdjYTIzLWQ3YWItNDQ2Yi04MjFkLTMzZDVkZWVkYmVkNCJ9
However, when decoding both values:
xlog("L_INFO", "HANDLE_STIRSHAKEN - Decoded Header 1:
$(var(header_1){s.decode.base64})");
xlog("L_INFO", "HANDLE_STIRSHAKEN - Decoded Header 2:
$(var(header_2){s.decode.base64})");
only $var(header_2) gets decoded:
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/parser/msg_parser.c:324]:
parse_headers(): flags=ffffffffffffffff
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 34
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/parser/msg_parser.c:324]:
parse_headers(): flags=ffffffffffffffff
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 34
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 38
May 10 09:09:42 kamailio1 kamailio[153201]: INFO: {1 10 INVITE
1-1966540(a)10.20.0.1} <script>: *HANDLE_STIRSHAKEN - Decoded Header 1:*
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/parser/msg_parser.c:324]:
parse_headers(): flags=ffffffffffffffff
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 34
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/parser/msg_parser.c:324]:
parse_headers(): flags=ffffffffffffffff
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 34
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 182
May 10 09:09:42 kamailio1 kamailio[153201]: INFO: {1 10 INVITE
1-1966540(a)10.20.0.1} <script>: *HANDLE_STIRSHAKEN - Decoded Header 2:
{"attest": "A","dest": {"tn":
["14045266060"]},"iat": 1548859982,"orig":
{"tn": "18001234567"},"origid":
"3a47ca23-d7ab-446b-821d-33d5deedbed4"}*
As you can veri
And to ease debugging, I have isolated the line that generates the issue:
May 10 09:09:42 kamailio1 kamailio[153201]: INFO: {1 10 INVITE
1-1966540(a)10.20.0.1} <script>: HANDLE_STIRSHAKEN - Parsing!
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/parser/msg_parser.c:324]:
parse_headers(): flags=ffffffffffffffff
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 34
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/parser/msg_parser.c:324]:
parse_headers(): flags=ffffffffffffffff
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 34
*May 10 09:09:42 kamailio1 kamailio[153201]: ERROR: {1 10 INVITE
1-1966540(a)10.20.0.1 <1-1966540(a)10.20.0.1>} <core> [core/lvalue.c:351]:
lval_pvar_assign(): non existing right pvar*
*May 10 09:09:42 kamailio1 kamailio[153201]: ERROR: {1 10 INVITE
1-1966540(a)10.20.0.1 <1-1966540(a)10.20.0.1>} <core> [core/lvalue.c:411]:
lval_assign(): assignment failed at pos: (21,32-21,64)*
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/parser/msg_parser.c:324]:
parse_headers(): flags=ffffffffffffffff
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 34
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/parser/msg_parser.c:324]:
parse_headers(): flags=ffffffffffffffff
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 34
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE
1-1966540(a)10.20.0.1} <core> [core/pvapi.c:1418]: pv_printf_mode(): final
buffer length 27
May 10 09:09:42 kamailio1 kamailio[153201]: INFO: {1 10 INVITE
1-1966540(a)10.20.0.1} <script>: HANDLE_STIRSHAKEN - Parsed!
Even though the $var(header_1) contains a base64 encoded string, the
decoder seems to fail.
If I copy the value contained in $var(header_1) to an online decoder like
https://www.base64decode.org/ the string gets decoded correctly.
I have even modified the line :
$var(header_1)= $(hdr(Identity){s.select,0,.});
to get the reverse index from the Identity string by doing
$var(header_1)= $(hdr(Identity){s.select,-6,.});
It gets the same encoded string, same value (as expected), but the result
is the same: Kamailio's s.decode.base64 fails with the same error.
i'm not sure what
assignment failed at pos: (21,32-21,64)
could mean....
I don't think my code is wrong, as the same function is used on
$var(header_2) value and it works, but maybe someone can correct me.
Greatly appreciate your help.
Cheers,
*Sérgio Charrua*