Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Failure to update key after mki failure #710

Open
pbodilis opened this issue May 2, 2024 · 3 comments
Open

Failure to update key after mki failure #710

pbodilis opened this issue May 2, 2024 · 3 comments

Comments

@pbodilis
Copy link
Contributor

pbodilis commented May 2, 2024

As a receiver, I fail to update srtp keys with MKI using the srtp_stream_update
This is new to master, this works fine with version 2.6.0

scenario:

  1. init srtp with ssrc_any_inbound, use_mki is true
  2. try to unprotect a packet with ssrc0 and associated mki0 => failure
  3. add srtp key with matching mki0 => success
  4. try to unprotect a packet with ssrc0 and associated mki0 => success
  5. try to unprotect a packet with ssrc1 and associated mki1 => failure
  6. add srtp key with matching mki1 => failure
  7. update srtp with srtp key with matching mki1 => failure

I suspect the bug to be around update_template_stream_cb or srtp_stream_remove.

srtp_unprotect creates a new stream with srtp_stream_clone, ssrc is stored in network order


static bool update_template_stream_cb(srtp_stream_t stream, void *raw_data)
{
    struct update_template_stream_data *data =
        (struct update_template_stream_data *)raw_data;
    srtp_t session = data->session;
    uint32_t ssrc = stream->ssrc; // ssrc is in network order
...


    /* remove stream */
    data->status = srtp_stream_remove(session, ssrc);
    if (data->status) {
        return false;
    }



but then, srtp_strp_remove expect ssrc to be given in host order

so possible fix can be to replace the call in update_template_stream_cb to be consistent with the changes made in the API:
data->status = srtp_stream_remove(session, ntohl(ssrc));

PR: #711

@pbodilis
Copy link
Contributor Author

pbodilis commented May 2, 2024

Scenario logs:



           sw_srtp_log_handler|[srtp] alloc: (location: 0x6030000297d0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029800) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029830) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029860) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029890) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6030000298c0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029920) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029950) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029980) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6030000299b0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6030000299e0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029a10) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029a70) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029aa0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029ad0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029b00) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029b30) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029b60) allocated
sw_srtp_init_policy_and_add_streams|Adding 1 ssrc_any_outbound key(s) (mki_len: 8):
sw_srtp_init_policy_and_add_streams|SRTP key 'AEAD_AES_128_GCM' master key/salt 16/12: 3796faaaaa82499933fc96ee9ab142b8/66547ce59d4721e35cc4bb0f - mki: 076b3298c17cf5c5
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60d000000860) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x607000001670) allocated
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with key length 28
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029bc0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029bf0) allocated
           sw_srtp_log_handler|[srtp] auth func: allocating auth func with key length 0
           sw_srtp_log_handler|[srtp] auth func:                           tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000004b50) allocated
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with key length 28
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029c20) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029c50) allocated
           sw_srtp_log_handler|[srtp] auth func: allocating auth func with key length 0
           sw_srtp_log_handler|[srtp] auth func:                           tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000004b90) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000007e50) allocated
           sw_srtp_log_handler|[srtp] srtp: initializing stream (SSRC: 0x00000000)
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60c00001c600) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000007e70) allocated
           sw_srtp_log_handler|[srtp] srtp: input key len: 28
           sw_srtp_log_handler|[srtp] srtp: srtp key len: 28
           sw_srtp_log_handler|[srtp] srtp: srtcp key len: 28
           sw_srtp_log_handler|[srtp] srtp: base key len: 16
           sw_srtp_log_handler|[srtp] srtp: kdf key len: 30
           sw_srtp_log_handler|[srtp] srtp: rtp salt len: 12
           sw_srtp_log_handler|[srtp] aes icm ossl: allocating cipher with key length 30
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029da0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000004bd0) allocated
           sw_srtp_log_handler|[srtp] aes icm ossl: key:  3796faaaaa82499933fc96ee9ab142b8
           sw_srtp_log_handler|[srtp] aes icm ossl: offset: 66547ce59d4721e35cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000000000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 66547ce59d4721e35cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 66547ce59d4721e35cc4bb0f00000000
           sw_srtp_log_handler|[srtp] srtp: cipher key: 0b5053c5fac88b539932510fdb784111
           sw_srtp_log_handler|[srtp] srtp: found rtp_salt_len > 0, generating salt
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000020000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 66547ce59d4721e15cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 66547ce59d4721e15cc4bb0f00000000
           sw_srtp_log_handler|[srtp] srtp: cipher salt: 70ccbdfbad2173d7a8d1baa9
           sw_srtp_log_handler|[srtp] aes gcm: key:  0b5053c5fac88b539932510fdb784111
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000010000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 66547ce59d4721e25cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 66547ce59d4721e25cc4bb0f00000000
           sw_srtp_log_handler|[srtp] srtp: auth key:
           sw_srtp_log_handler|[srtp] srtp: rtcp salt len: 12
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000030000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 66547ce59d4721e05cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 66547ce59d4721e05cc4bb0f00000000
           sw_srtp_log_handler|[srtp] srtp: found rtcp_salt_len > 0, generating rtcp salt
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000050000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 66547ce59d4721e65cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 66547ce59d4721e65cc4bb0f00000000
           sw_srtp_log_handler|[srtp] srtp: rtcp cipher key: 6a5213294a60ec79a553ac7b938e4cda
           sw_srtp_log_handler|[srtp] srtp: rtcp cipher salt: a158b60cd61b7469a3b8d495
           sw_srtp_log_handler|[srtp] aes gcm: key:  6a5213294a60ec79a553ac7b938e4cda
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000040000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 66547ce59d4721e75cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 66547ce59d4721e75cc4bb0f00000000
           sw_srtp_log_handler|[srtp] srtp: rtcp auth key:
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000004bd0) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029da0) freed
sw_srtp_init_policy_and_add_streams|Adding 1 ssrc_any_outbound key(s) (mki_len: 8):
sw_srtp_init_policy_and_add_streams|SRTP key 'AEAD_AES_128_GCM' master key/salt 16/12: 5ed5c598f82844b085de460ce6319da0/776ecee3b53e26593cfe5cab - mki: 8845397d77977ceb
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60d000000a00) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x607000001c20) allocated
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with key length 28
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029e90) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029ec0) allocated
           sw_srtp_log_handler|[srtp] auth func: allocating auth func with key length 0
           sw_srtp_log_handler|[srtp] auth func:                           tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000004cd0) allocated
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with key length 28
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029ef0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x603000029f20) allocated
           sw_srtp_log_handler|[srtp] auth func: allocating auth func with key length 0
           sw_srtp_log_handler|[srtp] auth func:                           tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000004d10) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000007ed0) allocated
           sw_srtp_log_handler|[srtp] srtp: initializing stream (SSRC: 0x00000000)
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60c00001c6c0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000007ef0) allocated
           sw_srtp_log_handler|[srtp] srtp: input key len: 28
           sw_srtp_log_handler|[srtp] srtp: srtp key len: 28
           sw_srtp_log_handler|[srtp] srtp: srtcp key len: 28
           sw_srtp_log_handler|[srtp] srtp: base key len: 16
           sw_srtp_log_handler|[srtp] srtp: kdf key len: 30
           sw_srtp_log_handler|[srtp] srtp: rtp salt len: 12
           sw_srtp_log_handler|[srtp] aes icm ossl: allocating cipher with key length 30
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002a070) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000004d50) allocated
           sw_srtp_log_handler|[srtp] aes icm ossl: key:  5ed5c598f82844b085de460ce6319da0
           sw_srtp_log_handler|[srtp] aes icm ossl: offset: 776ecee3b53e26593cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000000000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e26593cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e26593cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: cipher key: 2b8bada2e878c3a9057e4fefacd87508
           sw_srtp_log_handler|[srtp] srtp: found rtp_salt_len > 0, generating salt
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000020000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e265b3cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e265b3cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: cipher salt: a3c615097fbd4c625a406d03
           sw_srtp_log_handler|[srtp] aes gcm: key:  2b8bada2e878c3a9057e4fefacd87508
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000010000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e26583cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e26583cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: auth key:
           sw_srtp_log_handler|[srtp] srtp: rtcp salt len: 12
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000030000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e265a3cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e265a3cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: found rtcp_salt_len > 0, generating rtcp salt
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000050000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e265c3cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e265c3cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: rtcp cipher key: f194108f1d9f0612a9ef84fc9b0037cf
           sw_srtp_log_handler|[srtp] srtp: rtcp cipher salt: a1f83d9f376d86176e15a8b5
           sw_srtp_log_handler|[srtp] aes gcm: key:  f194108f1d9f0612a9ef84fc9b0037cf
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000040000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e265d3cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e265d3cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: rtcp auth key:
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000004d50) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002a070) freed
sw_srtp_init_policy_and_add_streams|Adding 1 ssrc_any_outbound key(s) (mki_len: 8):
sw_srtp_init_policy_and_add_streams|SRTP key 'AEAD_AES_128_GCM' master key/salt 16/12: a2adc7b9712bc027e102b556008e3ec9/5e7f90715112e8f3a5e8a7d3 - mki: 1d299ea72caac714
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60d000000ba0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6070000021d0) allocated
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with key length 28
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002a160) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002a190) allocated
           sw_srtp_log_handler|[srtp] auth func: allocating auth func with key length 0
           sw_srtp_log_handler|[srtp] auth func:                           tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000004e50) allocated
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with key length 28
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002a1c0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002a1f0) allocated
           sw_srtp_log_handler|[srtp] auth func: allocating auth func with key length 0
           sw_srtp_log_handler|[srtp] auth func:                           tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000004e90) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000007f50) allocated
           sw_srtp_log_handler|[srtp] srtp: initializing stream (SSRC: 0x00000000)
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60c00001c780) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000007f70) allocated
           sw_srtp_log_handler|[srtp] srtp: input key len: 28
           sw_srtp_log_handler|[srtp] srtp: srtp key len: 28
           sw_srtp_log_handler|[srtp] srtp: srtcp key len: 28
           sw_srtp_log_handler|[srtp] srtp: base key len: 16
           sw_srtp_log_handler|[srtp] srtp: kdf key len: 30
           sw_srtp_log_handler|[srtp] srtp: rtp salt len: 12
           sw_srtp_log_handler|[srtp] aes icm ossl: allocating cipher with key length 30
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002a340) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000004ed0) allocated
           sw_srtp_log_handler|[srtp] aes icm ossl: key:  a2adc7b9712bc027e102b556008e3ec9
           sw_srtp_log_handler|[srtp] aes icm ossl: offset: 5e7f90715112e8f3a5e8a7d300000000
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000000000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 5e7f90715112e8f3a5e8a7d300000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 5e7f90715112e8f3a5e8a7d300000000
           sw_srtp_log_handler|[srtp] srtp: cipher key: 248bcd3636beea98324740d642cdf4ef
           sw_srtp_log_handler|[srtp] srtp: found rtp_salt_len > 0, generating salt
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000020000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 5e7f90715112e8f1a5e8a7d300000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 5e7f90715112e8f1a5e8a7d300000000
           sw_srtp_log_handler|[srtp] srtp: cipher salt: 39058ae7bdd70bacaa9af848
           sw_srtp_log_handler|[srtp] aes gcm: key:  248bcd3636beea98324740d642cdf4ef
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000010000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 5e7f90715112e8f2a5e8a7d300000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 5e7f90715112e8f2a5e8a7d300000000
           sw_srtp_log_handler|[srtp] srtp: auth key:
           sw_srtp_log_handler|[srtp] srtp: rtcp salt len: 12
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000030000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 5e7f90715112e8f0a5e8a7d300000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 5e7f90715112e8f0a5e8a7d300000000
           sw_srtp_log_handler|[srtp] srtp: found rtcp_salt_len > 0, generating rtcp salt
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000050000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 5e7f90715112e8f6a5e8a7d300000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 5e7f90715112e8f6a5e8a7d300000000
           sw_srtp_log_handler|[srtp] srtp: rtcp cipher key: 7bdebb7f0d8a169bf3d5e797a9a303ec
           sw_srtp_log_handler|[srtp] srtp: rtcp cipher salt: f5721460f55086b194eee59b
           sw_srtp_log_handler|[srtp] aes gcm: key:  7bdebb7f0d8a169bf3d5e797a9a303ec
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000040000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 5e7f90715112e8f7a5e8a7d300000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 5e7f90715112e8f7a5e8a7d300000000
           sw_srtp_log_handler|[srtp] srtp: rtcp auth key:
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000004ed0) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002a340) freed
2024/05/02 17:12:26.527|ERR|test_sw_srtp(138934242434304)|     test_sw_srtp.cc|0073|                      TestBody|##### 0, 0 2 idx 0 ssrc[idx] 1234
2024/05/02 17:12:26.527|DBG|test_sw_srtp(138934242434304)|     test_sw_srtp.cc|0075|                      TestBody|Change of sender #0 (ssrc: 1234) (packet #0)
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect
           sw_srtp_log_handler|[srtp] srtp: cloning stream (SSRC: 0x000004d2)
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60d000000c70) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x607000002780) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000008330) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60c00001d380) allocated
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000000
           sw_srtp_log_handler|[srtp] srtp: estimated packet index: 0000000000000000
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000000000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baa9
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000000000000000004d2
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect
    sw_srtp_recover_on_bad_mki|Bad MKI, trying to recover
    sw_srtp_recover_on_bad_mki|Found key with suite: AEAD_AES_128_GCM matching MKI in 0 ms:
    sw_srtp_recover_on_bad_mki| [    8] 07 6b 32 98 c1 7c f5 c5
      sw_srtp_masterkeys_store|sRTP key has been added:
      sw_srtp_masterkeys_store|SRTP key 'AEAD_AES_128_GCM' master key/salt 16/12: 3796faaaaa82499933fc96ee9ab142b8/66547ce59d4721e35cc4bb0f - mki: 076b3298c17cf5c5
sw_srtp_masterkeys_find_from_packet|sRTP key has been found:
sw_srtp_masterkeys_find_from_packet|SRTP key 'AEAD_AES_128_GCM' master key/salt 16/12: 3796faaaaa82499933fc96ee9ab142b8/66547ce59d4721e35cc4bb0f - mki: 076b3298c17cf5c5
sw_srtp_init_policy_and_add_streams|Adding 1 ssrc_any_inbound key(s) (mki_len: 8):
sw_srtp_init_policy_and_add_streams|SRTP key 'AEAD_AES_128_GCM' master key/salt 16/12: 3796faaaaa82499933fc96ee9ab142b8/66547ce59d4721e35cc4bb0f - mki: 076b3298c17cf5c5
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60d000000fb0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x607000002860) allocated
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with key length 28
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002ac10) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002ac40) allocated
           sw_srtp_log_handler|[srtp] auth func: allocating auth func with key length 0
           sw_srtp_log_handler|[srtp] auth func:                           tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6040000054d0) allocated
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with key length 28
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002ac70) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002aca0) allocated
           sw_srtp_log_handler|[srtp] auth func: allocating auth func with key length 0
           sw_srtp_log_handler|[srtp] auth func:                           tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000005510) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000008390) allocated
           sw_srtp_log_handler|[srtp] srtp: initializing stream (SSRC: 0x00000000)
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60c00001d440) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6020000083b0) allocated
           sw_srtp_log_handler|[srtp] srtp: input key len: 28
           sw_srtp_log_handler|[srtp] srtp: srtp key len: 28
           sw_srtp_log_handler|[srtp] srtp: srtcp key len: 28
           sw_srtp_log_handler|[srtp] srtp: base key len: 16
           sw_srtp_log_handler|[srtp] srtp: kdf key len: 30
           sw_srtp_log_handler|[srtp] srtp: rtp salt len: 12
           sw_srtp_log_handler|[srtp] aes icm ossl: allocating cipher with key length 30
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002adf0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000005550) allocated
           sw_srtp_log_handler|[srtp] aes icm ossl: key:  3796faaaaa82499933fc96ee9ab142b8
           sw_srtp_log_handler|[srtp] aes icm ossl: offset: 66547ce59d4721e35cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000000000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 66547ce59d4721e35cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 66547ce59d4721e35cc4bb0f00000000
           sw_srtp_log_handler|[srtp] srtp: cipher key: 0b5053c5fac88b539932510fdb784111
           sw_srtp_log_handler|[srtp] srtp: found rtp_salt_len > 0, generating salt
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000020000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 66547ce59d4721e15cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 66547ce59d4721e15cc4bb0f00000000
           sw_srtp_log_handler|[srtp] srtp: cipher salt: 70ccbdfbad2173d7a8d1baa9
           sw_srtp_log_handler|[srtp] aes gcm: key:  0b5053c5fac88b539932510fdb784111
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000010000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 66547ce59d4721e25cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 66547ce59d4721e25cc4bb0f00000000
           sw_srtp_log_handler|[srtp] srtp: auth key:
           sw_srtp_log_handler|[srtp] srtp: rtcp salt len: 12
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000030000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 66547ce59d4721e05cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 66547ce59d4721e05cc4bb0f00000000
           sw_srtp_log_handler|[srtp] srtp: found rtcp_salt_len > 0, generating rtcp salt
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000050000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 66547ce59d4721e65cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 66547ce59d4721e65cc4bb0f00000000
           sw_srtp_log_handler|[srtp] srtp: rtcp cipher key: 6a5213294a60ec79a553ac7b938e4cda
           sw_srtp_log_handler|[srtp] srtp: rtcp cipher salt: a158b60cd61b7469a3b8d495
           sw_srtp_log_handler|[srtp] aes gcm: key:  6a5213294a60ec79a553ac7b938e4cda
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000040000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 66547ce59d4721e75cc4bb0f00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 66547ce59d4721e75cc4bb0f00000000
           sw_srtp_log_handler|[srtp] srtp: rtcp auth key:
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000005550) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002adf0) freed
sw_srtp_recover_on_bad_mki|Successfully recovered with key:
sw_srtp_recover_on_bad_mki|SRTP key 'AEAD_AES_128_GCM' master key/salt 16/12: 3796faaaaa82499933fc96ee9ab142b8/66547ce59d4721e35cc4bb0f - mki: 076b3298c17cf5c5
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect
           sw_srtp_log_handler|[srtp] srtp: using provisional stream (SSRC: 0x000004d2)
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000000
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000000
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000000000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baa9
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000000000000000004d2
           sw_srtp_log_handler|[srtp] srtp: cloning stream (SSRC: 0x000004d2)
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60d000001150) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x607000002e80) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6020000083d0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60c00001d500) allocated
2024/05/02 17:12:26.527|ERR|test_sw_srtp(138934242434304)|     test_sw_srtp.cc|0073|                      TestBody|##### 1, 0 2 idx 0 ssrc[idx] 1234
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000001
           sw_srtp_log_handler|[srtp] srtp: estimated packet index: 0000000000000001
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000100000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baa8
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b0001000003c0000004d2
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000001
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000001
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000001
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000100000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baa8
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b0001000003c0000004d2
2024/05/02 17:12:26.527|ERR|test_sw_srtp(138934242434304)|     test_sw_srtp.cc|0073|                      TestBody|##### 2, 0 2 idx 0 ssrc[idx] 1234
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000002
           sw_srtp_log_handler|[srtp] srtp: estimated packet index: 0000000000000002
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000200000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baab
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000200000780000004d2
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000002
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000002
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000002
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000200000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baab
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000200000780000004d2
2024/05/02 17:12:26.527|ERR|test_sw_srtp(138934242434304)|     test_sw_srtp.cc|0073|                      TestBody|##### 3, 0 2 idx 0 ssrc[idx] 1234
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000003
           sw_srtp_log_handler|[srtp] srtp: estimated packet index: 0000000000000003
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000300000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baaa
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000300000b40000004d2
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000003
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000003
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000003
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000300000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baaa
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000300000b40000004d2
2024/05/02 17:12:26.527|ERR|test_sw_srtp(138934242434304)|     test_sw_srtp.cc|0073|                      TestBody|##### 4, 0 2 idx 0 ssrc[idx] 1234
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000004
           sw_srtp_log_handler|[srtp] srtp: estimated packet index: 0000000000000004
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000400000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baad
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000400000f00000004d2
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000004
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000004
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000004
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000400000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baad
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000400000f00000004d2
2024/05/02 17:12:26.527|ERR|test_sw_srtp(138934242434304)|     test_sw_srtp.cc|0073|                      TestBody|##### 5, 0 2 idx 0 ssrc[idx] 1234
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000005
           sw_srtp_log_handler|[srtp] srtp: estimated packet index: 0000000000000005
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000500000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baac
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b0005000012c0000004d2
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000005
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000005
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000005
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000500000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baac
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b0005000012c0000004d2
2024/05/02 17:12:26.527|ERR|test_sw_srtp(138934242434304)|     test_sw_srtp.cc|0073|                      TestBody|##### 6, 0 2 idx 0 ssrc[idx] 1234
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000006
           sw_srtp_log_handler|[srtp] srtp: estimated packet index: 0000000000000006
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000600000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baaf
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000600001680000004d2
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000006
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000006
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000006
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000600000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baaf
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000600001680000004d2
2024/05/02 17:12:26.527|ERR|test_sw_srtp(138934242434304)|     test_sw_srtp.cc|0073|                      TestBody|##### 7, 0 2 idx 0 ssrc[idx] 1234
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000007
           sw_srtp_log_handler|[srtp] srtp: estimated packet index: 0000000000000007
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000700000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baae
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000700001a40000004d2
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000007
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000007
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000007
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000700000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baae
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000700001a40000004d2
2024/05/02 17:12:26.527|ERR|test_sw_srtp(138934242434304)|     test_sw_srtp.cc|0073|                      TestBody|##### 8, 0 2 idx 0 ssrc[idx] 1234
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000008
           sw_srtp_log_handler|[srtp] srtp: estimated packet index: 0000000000000008
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000800000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baa1
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000800001e00000004d2
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000008
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000008
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000008
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000800000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baa1
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b000800001e00000004d2
2024/05/02 17:12:26.527|ERR|test_sw_srtp(138934242434304)|     test_sw_srtp.cc|0073|                      TestBody|##### 9, 0 2 idx 0 ssrc[idx] 1234
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000009
           sw_srtp_log_handler|[srtp] srtp: estimated packet index: 0000000000000009
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000900000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baa0
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b0009000021c0000004d2
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000009
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000009
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000009
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 0000000004d200000000000900000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = 70ccbdfbad2173d7a8d1baa900000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: 70ccbdfba9f373d7a8d1baa0
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b0009000021c0000004d2
2024/05/02 17:12:26.527|ERR|test_sw_srtp(138934242434304)|     test_sw_srtp.cc|0073|                      TestBody|##### 10, 1 2 idx 1 ssrc[idx] 5678
2024/05/02 17:12:26.527|DBG|test_sw_srtp(138934242434304)|     test_sw_srtp.cc|0075|                      TestBody|Change of sender #1 (ssrc: 5678) (packet #10)
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect
           sw_srtp_log_handler|[srtp] srtp: cloning stream (SSRC: 0x0000162e)
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60d000001220) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6070000036d0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6020000083f0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60c00001d5c0) allocated
           sw_srtp_log_handler|[srtp] srtp: function srtp_protect_aead
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000000
           sw_srtp_log_handler|[srtp] srtp: estimated packet index: 0000000000000000
           sw_srtp_log_handler|[srtp] srtp: Pre-salted RTP IV = 00000000162e00000000000000000000
           sw_srtp_log_handler|[srtp] srtp: RTP SALT = a3c615097fbd4c625a406d0300000000
           sw_srtp_log_handler|[srtp] aes gcm: setting iv: a3c6150969934c625a406d03
           sw_srtp_log_handler|[srtp] aes gcm: setting AAD: 807b0000000025800000162e
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect
           sw_srtp_log_handler|[srtp] srtp: using provisional stream (SSRC: 0x0000162e)
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000000
    sw_srtp_recover_on_bad_mki|Bad MKI, trying to recover
    sw_srtp_recover_on_bad_mki|Found key with suite: AEAD_AES_128_GCM matching MKI in 0 ms:
    sw_srtp_recover_on_bad_mki| [    8] 88 45 39 7d 77 97 7c eb
      sw_srtp_masterkeys_store|sRTP key has been added:
      sw_srtp_masterkeys_store|SRTP key 'AEAD_AES_128_GCM' master key/salt 16/12: 5ed5c598f82844b085de460ce6319da0/776ecee3b53e26593cfe5cab - mki: 8845397d77977ceb
sw_srtp_masterkeys_find_from_packet|sRTP key has been found:
sw_srtp_masterkeys_find_from_packet|SRTP key 'AEAD_AES_128_GCM' master key/salt 16/12: 5ed5c598f82844b085de460ce6319da0/776ecee3b53e26593cfe5cab - mki: 8845397d77977ceb
sw_srtp_init_policy_and_add_streams|Adding 1 ssrc_any_inbound key(s) (mki_len: 8):
sw_srtp_init_policy_and_add_streams|SRTP key 'AEAD_AES_128_GCM' master key/salt 16/12: 5ed5c598f82844b085de460ce6319da0/776ecee3b53e26593cfe5cab - mki: 8845397d77977ceb
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60d000001560) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6070000037b0) allocated
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with key length 28
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002afa0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002afd0) allocated
           sw_srtp_log_handler|[srtp] auth func: allocating auth func with key length 0
           sw_srtp_log_handler|[srtp] auth func:                           tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000006450) allocated
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with key length 28
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b000) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b030) allocated
           sw_srtp_log_handler|[srtp] auth func: allocating auth func with key length 0
           sw_srtp_log_handler|[srtp] auth func:                           tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000006490) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000008450) allocated
           sw_srtp_log_handler|[srtp] srtp: initializing stream (SSRC: 0x00000000)
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60c00001d680) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000008470) allocated
           sw_srtp_log_handler|[srtp] srtp: input key len: 28
           sw_srtp_log_handler|[srtp] srtp: srtp key len: 28
           sw_srtp_log_handler|[srtp] srtp: srtcp key len: 28
           sw_srtp_log_handler|[srtp] srtp: base key len: 16
           sw_srtp_log_handler|[srtp] srtp: kdf key len: 30
           sw_srtp_log_handler|[srtp] srtp: rtp salt len: 12
           sw_srtp_log_handler|[srtp] aes icm ossl: allocating cipher with key length 30
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b180) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6040000064d0) allocated
           sw_srtp_log_handler|[srtp] aes icm ossl: key:  5ed5c598f82844b085de460ce6319da0
           sw_srtp_log_handler|[srtp] aes icm ossl: offset: 776ecee3b53e26593cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000000000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e26593cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e26593cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: cipher key: 2b8bada2e878c3a9057e4fefacd87508
           sw_srtp_log_handler|[srtp] srtp: found rtp_salt_len > 0, generating salt
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000020000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e265b3cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e265b3cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: cipher salt: a3c615097fbd4c625a406d03
           sw_srtp_log_handler|[srtp] aes gcm: key:  2b8bada2e878c3a9057e4fefacd87508
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000010000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e26583cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e26583cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: auth key:
           sw_srtp_log_handler|[srtp] srtp: rtcp salt len: 12
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000030000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e265a3cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e265a3cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: found rtcp_salt_len > 0, generating rtcp salt
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000050000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e265c3cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e265c3cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: rtcp cipher key: f194108f1d9f0612a9ef84fc9b0037cf
           sw_srtp_log_handler|[srtp] srtp: rtcp cipher salt: a1f83d9f376d86176e15a8b5
           sw_srtp_log_handler|[srtp] aes gcm: key:  f194108f1d9f0612a9ef84fc9b0037cf
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000040000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e265d3cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e265d3cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: rtcp auth key:
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6040000064d0) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b180) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002afd0) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002afa0) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000006450) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b030) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b000) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000006490) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000008470) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000008450) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6070000037b0) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60c00001d680) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60d000001560) freed
2024/05/02 17:12:26.531|ERR|test_sw_srtp(138934242434304)|           sw_srtp.c|0656|sw_srtp_init_policy_and_add_streams|Failed to add stream to srtp session err: 2 (srtp_err_status_bad_param)
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60d000001630) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x607000003dd0) allocated
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with key length 28
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b240) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b270) allocated
           sw_srtp_log_handler|[srtp] auth func: allocating auth func with key length 0
           sw_srtp_log_handler|[srtp] auth func:                           tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000006850) allocated
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with key length 28
           sw_srtp_log_handler|[srtp] aes gcm: allocating cipher with tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b2a0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b2d0) allocated
           sw_srtp_log_handler|[srtp] auth func: allocating auth func with key length 0
           sw_srtp_log_handler|[srtp] auth func:                           tag length 16
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000006890) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000008490) allocated
           sw_srtp_log_handler|[srtp] srtp: initializing stream (SSRC: 0x00000000)
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60c00001d740) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6020000084b0) allocated
           sw_srtp_log_handler|[srtp] srtp: input key len: 28
           sw_srtp_log_handler|[srtp] srtp: srtp key len: 28
           sw_srtp_log_handler|[srtp] srtp: srtcp key len: 28
           sw_srtp_log_handler|[srtp] srtp: base key len: 16
           sw_srtp_log_handler|[srtp] srtp: kdf key len: 30
           sw_srtp_log_handler|[srtp] srtp: rtp salt len: 12
           sw_srtp_log_handler|[srtp] aes icm ossl: allocating cipher with key length 30
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b420) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6040000068d0) allocated
           sw_srtp_log_handler|[srtp] aes icm ossl: key:  5ed5c598f82844b085de460ce6319da0
           sw_srtp_log_handler|[srtp] aes icm ossl: offset: 776ecee3b53e26593cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000000000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e26593cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e26593cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: cipher key: 2b8bada2e878c3a9057e4fefacd87508
           sw_srtp_log_handler|[srtp] srtp: found rtp_salt_len > 0, generating salt
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000020000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e265b3cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e265b3cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: cipher salt: a3c615097fbd4c625a406d03
           sw_srtp_log_handler|[srtp] aes gcm: key:  2b8bada2e878c3a9057e4fefacd87508
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000010000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e26583cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e26583cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: auth key:
           sw_srtp_log_handler|[srtp] srtp: rtcp salt len: 12
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000030000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e265a3cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e265a3cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: found rtcp_salt_len > 0, generating rtcp salt
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000050000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e265c3cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e265c3cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: rtcp cipher key: f194108f1d9f0612a9ef84fc9b0037cf
           sw_srtp_log_handler|[srtp] srtp: rtcp cipher salt: a1f83d9f376d86176e15a8b5
           sw_srtp_log_handler|[srtp] aes gcm: key:  f194108f1d9f0612a9ef84fc9b0037cf
           sw_srtp_log_handler|[srtp] aes icm ossl: setting iv: 00000000000000040000000000000000
           sw_srtp_log_handler|[srtp] aes icm ossl: set_counter: 776ecee3b53e265d3cfe5cab00000000
           sw_srtp_log_handler|[srtp] aes icm ossl: rs0: 776ecee3b53e265d3cfe5cab00000000
           sw_srtp_log_handler|[srtp] srtp: rtcp auth key:
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6040000068d0) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b420) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b4e0) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b510) allocated
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b510) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b4e0) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b270) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b240) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000006850) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b2d0) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60300002b2a0) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x604000006890) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x6020000084b0) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x602000008490) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x607000003dd0) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60c00001d740) freed
           sw_srtp_log_handler|[srtp] alloc: (location: 0x60d000001630) freed
2024/05/02 17:12:26.531|ERR|test_sw_srtp(138934242434304)|           sw_srtp.c|0660|sw_srtp_init_policy_and_add_streams|Failed to add stream to srtp session err: 13 (srtp_err_status_no_ctx)
2024/05/02 17:12:26.531|DBG|test_sw_srtp(138934242434304)|           sw_srtp.c|0825|    sw_srtp_recover_on_bad_mki|Successfully recovered with key:
2024/05/02 17:12:26.531|DBG|test_sw_srtp(138934242434304)|           sw_srtp.c|0826|    sw_srtp_recover_on_bad_mki|SRTP key 'AEAD_AES_128_GCM' master key/salt 16/12: 5ed5c598f82844b085de460ce6319da0/776ecee3b53e26593cfe5cab - mki: 8845397d77977ceb
           sw_srtp_log_handler|[srtp] srtp: function srtp_unprotect
           sw_srtp_log_handler|[srtp] srtp: using provisional stream (SSRC: 0x0000162e)
           sw_srtp_log_handler|[srtp] srtp: estimated u_packet index: 0000000000000000
2024/05/02 17:12:26.531|ERR|test_sw_srtp(138934242434304)|           sw_srtp.c|0869|        sw_srtp_unprotect2_rtp|Failed to unprotect stream 5678: 25 (srtp_err_status_bad_mki)
2024/05/02 17:12:26.531|ERR|test_sw_srtp(138934242434304)|           sw_srtp.c|0870|        sw_srtp_unprotect2_rtp|V: 2, P: 0, X: 0, cc: 0, mb: 0, pt: 123, sn: 0, ts: 9600, ssrc: 5678 (0x162e) - size: 87

@pabuhler
Copy link
Member

pabuhler commented May 2, 2024

Thanks for reporting this, there was always a chance changing the API would break something but I think have a consistent public API is worth it. I have approved the PR but I also found another occurrence of this issue. I plan to add a test for this, so will get this issue open until the test is added.

@pbodilis
Copy link
Contributor Author

pbodilis commented May 3, 2024

alright, thanks :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants