Can't see AES-CBC-NO-PADDING 2nd test log messages

I call nrfAes128Test() two times in function body of main(). But RTT Viewer only shows log messages of 1st times.

void main(void) {
    nrfAes128Init();
    nrfAes128Test(1);
    nrfAes128Test(2);

#ifdef CONFIG_PM
    while (1) {
        k_usleep(1);
    }
#endif
}

The following are log messages of RTT Viewer.

00> *** Booting Zephyr OS build v3.3.99-ncs1 ***
00> btInit() e
00> btInit() x
00> [00:00:00.974,151] <inf> aes_cbc: Starting AES-CBC-NO-PADDING test 1
00> [00:00:00.974,456] <inf> aes_cbc: Importing random AES key...
00> psa_import_key() nrf e
00> [00:00:00.974,853] <inf> aes_cbc: AES key imported successfully!
00> [00:00:00.975,189] <inf> aes_cbc: Encrypting using AES CBC MODE...
00> psa_cipher_encrypt_setup() nrf e
00> psa_cipher_setup() nrf e
00> psa_key_algorithm_permits() e key_type=9216, policy_alg=71319552, requested_alg=71319552
00> psa_cipher_setup() return 0
00> [00:00:00.976,531] <inf> aes_cbc: Encryption successful!
00> [00:00:00.976,867] <inf> aes_cbc: Decrypting using AES CBC MODE...
00> psa_cipher_setup() nrf e
00> psa_key_algorithm_permits() e key_type=9216, policy_alg=71319552, requested_alg=71319552
00> psa_cipher_setup() return 0
00> [00:00:00.977,996] <inf> aes_cbc: Decryption successful!
00> [00:00:00.978,302] <inf> aes_cbc: Example finished successfully!
00> [00:00:00.978,607] <

Procedures to reproduce this issue are as follows.

1. Unzipping minimal_log_aes.zip to D:\ncs\v2.4.0\nrf\samples folder.
2. cd D:\ncs\v2.4.0\nrf\samples\minimal_log_aes
3. west build -b nrf5340dk_nrf5340_cpuapp
4. west flash
5. Rebooting nRF5340 device and connecting to RTT Viewer.

  • Hi 

    I tested your code, and it seems to work fine for me. The only change I made was to use the UART LOG backend instead of RTT:

    *** Booting Zephyr OS build v3.3.99-ncs1 ***
    btInit() e
    btInit() x
    [00:00:00.270,477] <inf> aes_cbc: Starting AES-CBC-NO-PADDING test 1
    [00:00:00.277,252] <inf> aes_cbc: Importing random AES key...
    [00:00:00.283,477] <inf> aes_cbc: AES key imported successfully!
    [00:00:00.289,916] <inf> aes_cbc: Encrypting using AES CBC MODE...
    [00:00:00.296,936] <inf> aes_cbc: Encryption successful!
    [00:00:00.302,642] <inf> aes_cbc: Decrypting using AES CBC MODE...
    [00:00:00.309,570] <inf> aes_cbc: Decryption successful!
    [00:00:00.315,277] <inf> aes_cbc: Example finished successfully!
    [00:00:00.321,685] <inf> aes_cbc: Starting AES-CBC-NO-PADDING test 2
    [00:00:00.328,491] <inf> aes_cbc: Importing random AES key...
    [00:00:00.334,686] <inf> aes_cbc: AES key imported successfully!
    [00:00:00.341,125] <inf> aes_cbc: Encrypting using AES CBC MODE...
    [00:00:00.348,144] <inf> aes_cbc: Encryption successful!
    [00:00:00.353,851] <inf> aes_cbc: Decrypting using AES CBC MODE...
    [00:00:00.360,778] <inf> aes_cbc: Decryption successful!
    [00:00:00.366,485] <inf> aes_cbc: Example finished successfully!
    _btReady(0) e
    Bluetooth initialized
    _btReady(0) x

    Could you try this as well and see if it makes a difference?

    Are you testing on an nRF5340DK, or on custom hardware?

    Best regards
    Torbjørn

  • Thanks for your reply! I am using Raytac MDBT53-DB-40 board. (https://www.raytac.com/product/ins.php?index_id=139). Could you try to use RTT LOG backend since I don't use UART?

  • Hi

    Switching to RTT logging I see the same issue, for some reason it hangs in the middle. 

    Adding a 3 second delay at the top of main solves it, but I am not exactly sure why. 

    I will have to investigate this a bit further and see if I can find the root cause. 

    Best regards
    Torbjørn

  • Hi 

    I believe the issue is related to the size of the outgoing RTT buffer, which you can change by modifying the CONFIG_SEGGER_RTT_BUFFER_SIZE_UP parameter. 

    By default this is set to 1024, which is not enough to buffer all the output during your boot sequence. 

    Every time you flash the nRF device and reset the board the JLink RTT viewer will be disconnected, and by the time you are able to reconnect the viewer and start polling out the RTT data the buffers have overflowed, leading to loss of logging data. 

    The reason adding a delay worked for me is that I was able to connect the RTT viewer before the nRF started printing log messages, avoiding the overflow.

    Try setting CONFIG_SEGGER_RTT_BUFFER_SIZE_UP  to 2048 or more and it should work fine. 

    Best regards
    Torbjørn

Related