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@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@10.20.0.1} <script>: HANDLE_STIRSHAKEN - Encoded Header 1: eyJhbGciOiAiRVMyNTYiLCJwcHQiOiAic2hha2VuIiwidHlwIjogInBhc3Nwb3J0IiwieDV1IjogImh0dHBzOi8vY2VydGlmaWNhdGVzLmNsZWFyaXAuY29tL2IxNWQ3Y2M5LTBmMjYtNDZjMi04M2VhLWEzZTYzYTgyZWMzYS83Y2M0ZGI2OTVkMTNlZGFkYTRkMWY5ODYxYjliODBmZS5jcnQifQ
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE 1-1966540@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@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@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@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@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@10.20.0.1} <script>: HANDLE_STIRSHAKEN - Encoded Header 2: eyJhdHRlc3QiOiAiQSIsImRlc3QiOiB7InRuIjogWyIxNDA0NTI2NjA2MCJdfSwiaWF0IjogMTU0ODg1OTk4Miwib3JpZyI6IHsidG4iOiAiMTgwMDEyMzQ1NjcifSwib3JpZ2lkIjogIjNhNDdjYTIzLWQ3YWItNDQ2Yi04MjFkLTMzZDVkZWVkYmVkNCJ9


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@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@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@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@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@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@10.20.0.1} <script>: HANDLE_STIRSHAKEN - Decoded Header 1:
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE 1-1966540@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@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@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@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@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@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@10.20.0.1} <script>: HANDLE_STIRSHAKEN - Parsing!
May 10 09:09:42 kamailio1 kamailio[153201]: DEBUG: {1 10 INVITE 1-1966540@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@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@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@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@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@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@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@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@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@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@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@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