Skip to content

Commit 1b7fde0

Browse files
ArekBalysNordicArekBalysNordic
committed
Add logs to all crypto operations
1 parent 668f104 commit 1b7fde0

File tree

4 files changed

+212
-259
lines changed

4 files changed

+212
-259
lines changed

‎src/crypto/CHIPCryptoPALPSA.cpp

+42-5
Original file line numberDiff line numberDiff line change
@@ -67,7 +67,6 @@ bool isValidTag(const uint8_t * tag, size_t tag_length)
6767
}
6868

6969
} // namespace
70-
7170
CHIP_ERROR AES_CCM_encrypt(const uint8_t * plaintext, size_t plaintext_length, const uint8_t * aad, size_t aad_length,
7271
const Aes128KeyHandle & key, const uint8_t * nonce, size_t nonce_length, uint8_t * ciphertext,
7372
uint8_t * tag, size_t tag_length)
@@ -84,38 +83,45 @@ CHIP_ERROR AES_CCM_encrypt(const uint8_t * plaintext, size_t plaintext_length, c
8483
size_t tag_out_length;
8584

8685
status = psa_aead_encrypt_setup(&operation, key.As<psa_key_id_t>(), algorithm);
86+
ChipLogError(Crypto, "AES_CCM_encrypt: psa_aead_encrypt_setup status: %d", status);
8787
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
8888

8989
status = psa_aead_set_lengths(&operation, aad_length, plaintext_length);
90+
ChipLogError(Crypto, "AES_CCM_encrypt: psa_aead_set_lengths status: %d", status);
9091
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
9192

9293
status = psa_aead_set_nonce(&operation, nonce, nonce_length);
94+
ChipLogError(Crypto, "AES_CCM_encrypt: psa_aead_set_nonce status: %d", status);
9395
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
9496

9597
if (aad_length != 0)
9698
{
9799
status = psa_aead_update_ad(&operation, aad, aad_length);
100+
ChipLogError(Crypto, "AES_CCM_encrypt: psa_aead_update_ad status: %d", status);
98101
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
99102
}
100103
else
101104
{
102-
ChipLogDetail(Crypto, "AES_CCM_encrypt: Using aad == null path");
105+
ChipLogError(Crypto, "AES_CCM_encrypt: Using aad == null path");
103106
}
104107

105108
if (plaintext_length != 0)
106109
{
107110
status = psa_aead_update(&operation, plaintext, plaintext_length, ciphertext,
108111
PSA_AEAD_UPDATE_OUTPUT_SIZE(PSA_KEY_TYPE_AES, algorithm, plaintext_length), &out_length);
112+
ChipLogError(Crypto, "AES_CCM_encrypt: psa_aead_update status: %d", status);
109113
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
110114

111115
ciphertext += out_length;
112116

113117
status = psa_aead_finish(&operation, ciphertext, PSA_AEAD_FINISH_OUTPUT_SIZE(PSA_KEY_TYPE_AES, algorithm), &out_length, tag,
114118
tag_length, &tag_out_length);
119+
ChipLogError(Crypto, "AES_CCM_encrypt: psa_aead_finish status: %d", status);
115120
}
116121
else
117122
{
118123
status = psa_aead_finish(&operation, nullptr, 0, &out_length, tag, tag_length, &tag_out_length);
124+
ChipLogError(Crypto, "AES_CCM_encrypt: psa_aead_finish status: %d", status);
119125
}
120126
VerifyOrReturnError(status == PSA_SUCCESS && tag_length == tag_out_length, CHIP_ERROR_INTERNAL);
121127

@@ -137,38 +143,45 @@ CHIP_ERROR AES_CCM_decrypt(const uint8_t * ciphertext, size_t ciphertext_length,
137143
size_t outLength;
138144

139145
status = psa_aead_decrypt_setup(&operation, key.As<psa_key_id_t>(), algorithm);
146+
ChipLogError(Crypto, "AES_CCM_decrypt: psa_aead_decrypt_setup status: %d", status);
140147
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
141148

142149
status = psa_aead_set_lengths(&operation, aad_length, ciphertext_length);
150+
ChipLogError(Crypto, "AES_CCM_decrypt: psa_aead_set_lengths status: %d", status);
143151
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
144152

145153
status = psa_aead_set_nonce(&operation, nonce, nonce_length);
154+
ChipLogError(Crypto, "AES_CCM_decrypt: psa_aead_set_nonce status: %d", status);
146155
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
147156

148157
if (aad_length != 0)
149158
{
150159
status = psa_aead_update_ad(&operation, aad, aad_length);
160+
ChipLogError(Crypto, "AES_CCM_decrypt: psa_aead_update_ad status: %d", status);
151161
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
152162
}
153163
else
154164
{
155-
ChipLogDetail(Crypto, "AES_CCM_decrypt: Using aad == null path");
165+
ChipLogError(Crypto, "AES_CCM_decrypt: Using aad == null path");
156166
}
157167

158168
if (ciphertext_length != 0)
159169
{
160170
status = psa_aead_update(&operation, ciphertext, ciphertext_length, plaintext,
161171
PSA_AEAD_UPDATE_OUTPUT_SIZE(PSA_KEY_TYPE_AES, algorithm, ciphertext_length), &outLength);
172+
ChipLogError(Crypto, "AES_CCM_decrypt: psa_aead_update status: %d", status);
162173
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
163174

164175
plaintext += outLength;
165176

166177
status = psa_aead_verify(&operation, plaintext, PSA_AEAD_VERIFY_OUTPUT_SIZE(PSA_KEY_TYPE_AES, algorithm), &outLength, tag,
167178
tag_length);
179+
ChipLogError(Crypto, "AES_CCM_decrypt: psa_aead_verify status: %d", status);
168180
}
169181
else
170182
{
171183
status = psa_aead_verify(&operation, nullptr, 0, &outLength, tag, tag_length);
184+
ChipLogError(Crypto, "AES_CCM_decrypt: psa_aead_verify status: %d", status);
172185
}
173186

174187
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
@@ -182,6 +195,7 @@ CHIP_ERROR Hash_SHA256(const uint8_t * data, const size_t data_length, uint8_t *
182195

183196
const psa_status_t status =
184197
psa_hash_compute(PSA_ALG_SHA_256, data, data_length, out_buffer, PSA_HASH_LENGTH(PSA_ALG_SHA_256), &outLength);
198+
ChipLogError(Crypto, "Hash_SHA256: psa_hash_compute status: %d", status);
185199

186200
return status == PSA_SUCCESS ? CHIP_NO_ERROR : CHIP_ERROR_INTERNAL;
187201
}
@@ -192,6 +206,7 @@ CHIP_ERROR Hash_SHA1(const uint8_t * data, const size_t data_length, uint8_t * o
192206

193207
const psa_status_t status =
194208
psa_hash_compute(PSA_ALG_SHA_1, data, data_length, out_buffer, PSA_HASH_LENGTH(PSA_ALG_SHA_1), &outLength);
209+
ChipLogError(Crypto, "Hash_SHA1: psa_hash_compute status: %d", status);
195210

196211
return status == PSA_SUCCESS ? CHIP_NO_ERROR : CHIP_ERROR_INTERNAL;
197212
}
@@ -220,13 +235,15 @@ CHIP_ERROR Hash_SHA256_stream::Begin()
220235
{
221236
toHashOperation(mContext) = PSA_HASH_OPERATION_INIT;
222237
const psa_status_t status = psa_hash_setup(toHashOperation(&mContext), PSA_ALG_SHA_256);
238+
ChipLogError(Crypto, "Hash_SHA256_stream::Begin: psa_hash_setup status: %d", status);
223239

224240
return status == PSA_SUCCESS ? CHIP_NO_ERROR : CHIP_ERROR_INTERNAL;
225241
}
226242

227243
CHIP_ERROR Hash_SHA256_stream::AddData(const ByteSpan data)
228244
{
229245
const psa_status_t status = psa_hash_update(toHashOperation(&mContext), data.data(), data.size());
246+
ChipLogError(Crypto, "Hash_SHA256_stream::AddData: psa_hash_update status: %d", status);
230247

231248
return status == PSA_SUCCESS ? CHIP_NO_ERROR : CHIP_ERROR_INTERNAL;
232249
}
@@ -241,9 +258,11 @@ CHIP_ERROR Hash_SHA256_stream::GetDigest(MutableByteSpan & out_buffer)
241258
size_t outLength;
242259

243260
status = psa_hash_clone(toHashOperation(&mContext), &operation);
261+
ChipLogError(Crypto, "Hash_SHA256_stream::GetDigest: psa_hash_clone status: %d", status);
244262
VerifyOrExit(status == PSA_SUCCESS, error = CHIP_ERROR_INTERNAL);
245263

246264
status = psa_hash_finish(&operation, out_buffer.data(), out_buffer.size(), &outLength);
265+
ChipLogError(Crypto, "Hash_SHA256_stream::GetDigest: psa_hash_finish status: %d", status);
247266
VerifyOrExit(status == PSA_SUCCESS, error = CHIP_ERROR_INTERNAL);
248267
out_buffer.reduce_size(outLength);
249268

@@ -260,6 +279,7 @@ CHIP_ERROR Hash_SHA256_stream::Finish(MutableByteSpan & out_buffer)
260279
size_t outLength;
261280

262281
const psa_status_t status = psa_hash_finish(toHashOperation(&mContext), out_buffer.data(), out_buffer.size(), &outLength);
282+
ChipLogError(Crypto, "Hash_SHA256_stream::Finish: psa_hash_finish status: %d", status);
263283
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
264284
out_buffer.reduce_size(outLength);
265285

@@ -281,6 +301,7 @@ CHIP_ERROR PsaKdf::Init(const ByteSpan & secret, const ByteSpan & salt, const By
281301
psa_set_key_usage_flags(&attrs, PSA_KEY_USAGE_DERIVE);
282302

283303
status = psa_import_key(&attrs, secret.data(), secret.size(), &mSecretKeyId);
304+
ChipLogError(Crypto, "PsaKdf::Init: psa_import_key status: %d", status);
284305
psa_reset_key_attributes(&attrs);
285306
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
286307

@@ -291,22 +312,25 @@ CHIP_ERROR PsaKdf::Init(const HkdfKeyHandle & hkdfKey, const ByteSpan & salt, co
291312
{
292313
return InitOperation(hkdfKey.As<psa_key_id_t>(), salt, info);
293314
}
294-
295315
CHIP_ERROR PsaKdf::InitOperation(psa_key_id_t hkdfKey, const ByteSpan & salt, const ByteSpan & info)
296316
{
297317
psa_status_t status = psa_key_derivation_setup(&mOperation, PSA_ALG_HKDF(PSA_ALG_SHA_256));
318+
ChipLogError(Crypto, "PsaKdf::InitOperation: psa_key_derivation_setup status: %d", status);
298319
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
299320

300321
if (salt.size() > 0)
301322
{
302323
status = psa_key_derivation_input_bytes(&mOperation, PSA_KEY_DERIVATION_INPUT_SALT, salt.data(), salt.size());
324+
ChipLogError(Crypto, "PsaKdf::InitOperation: psa_key_derivation_input_bytes (salt) status: %d", status);
303325
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
304326
}
305327

306328
status = psa_key_derivation_input_key(&mOperation, PSA_KEY_DERIVATION_INPUT_SECRET, hkdfKey);
329+
ChipLogError(Crypto, "PsaKdf::InitOperation: psa_key_derivation_input_key status: %d", status);
307330
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
308331

309332
status = psa_key_derivation_input_bytes(&mOperation, PSA_KEY_DERIVATION_INPUT_INFO, info.data(), info.size());
333+
ChipLogError(Crypto, "PsaKdf::InitOperation: psa_key_derivation_input_bytes (info) status: %d", status);
310334
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
311335

312336
return CHIP_NO_ERROR;
@@ -315,6 +339,7 @@ CHIP_ERROR PsaKdf::InitOperation(psa_key_id_t hkdfKey, const ByteSpan & salt, co
315339
CHIP_ERROR PsaKdf::DeriveBytes(const MutableByteSpan & output)
316340
{
317341
psa_status_t status = psa_key_derivation_output_bytes(&mOperation, output.data(), output.size());
342+
ChipLogError(Crypto, "PsaKdf::DeriveBytes: psa_key_derivation_output_bytes status: %d", status);
318343
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
319344

320345
return CHIP_NO_ERROR;
@@ -323,6 +348,7 @@ CHIP_ERROR PsaKdf::DeriveBytes(const MutableByteSpan & output)
323348
CHIP_ERROR PsaKdf::DeriveKey(const psa_key_attributes_t & attributes, psa_key_id_t & keyId)
324349
{
325350
psa_status_t status = psa_key_derivation_output_key(&attributes, &mOperation, &keyId);
351+
ChipLogError(Crypto, "PsaKdf::DeriveKey: psa_key_derivation_output_key status: %d", status);
326352
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
327353

328354
return CHIP_NO_ERROR;
@@ -361,9 +387,11 @@ CHIP_ERROR HMAC_sha::HMAC_SHA256(const uint8_t * key, size_t key_length, const u
361387
psa_set_key_usage_flags(&attrs, PSA_KEY_USAGE_SIGN_HASH);
362388

363389
status = psa_import_key(&attrs, key, key_length, &keyId);
390+
ChipLogError(Crypto, "HMAC_sha::HMAC_SHA256: psa_import_key status: %d", status);
364391
VerifyOrExit(status == PSA_SUCCESS, error = CHIP_ERROR_INTERNAL);
365392

366393
status = psa_mac_compute(keyId, algorithm, message, message_length, out_buffer, out_length, &out_length);
394+
ChipLogError(Crypto, "HMAC_sha::HMAC_SHA256: psa_mac_compute status: %d", status);
367395
VerifyOrExit(status == PSA_SUCCESS, error = CHIP_ERROR_INTERNAL);
368396

369397
exit:
@@ -383,6 +411,7 @@ CHIP_ERROR HMAC_sha::HMAC_SHA256(const Hmac128KeyHandle & key, const uint8_t * m
383411
psa_status_t status = PSA_SUCCESS;
384412

385413
status = psa_mac_compute(key.As<psa_key_id_t>(), algorithm, message, message_length, out_buffer, out_length, &out_length);
414+
ChipLogError(Crypto, "HMAC_sha::HMAC_SHA256: psa_mac_compute status: %d", status);
386415
VerifyOrReturnError(status == PSA_SUCCESS, CHIP_ERROR_INTERNAL);
387416

388417
return CHIP_NO_ERROR;
@@ -423,7 +452,6 @@ CHIP_ERROR PBKDF2_sha256::pbkdf2_sha256(const uint8_t * pass, size_t pass_length
423452
424453
return error;
425454
*/
426-
427455
VerifyOrReturnError(isBufferNonEmpty(pass, pass_length), CHIP_ERROR_INVALID_ARGUMENT);
428456
VerifyOrReturnError(salt != nullptr && salt_length >= kSpake2p_Min_PBKDF_Salt_Length &&
429457
salt_length <= kSpake2p_Max_PBKDF_Salt_Length,
@@ -442,6 +470,7 @@ CHIP_ERROR PBKDF2_sha256::pbkdf2_sha256(const uint8_t * pass, size_t pass_length
442470
psa_set_key_usage_flags(&attrs, PSA_KEY_USAGE_SIGN_HASH);
443471

444472
status = psa_import_key(&attrs, pass, pass_length, &keyId);
473+
ChipLogError(Crypto, "pbkdf2_sha256: psa_import_key status: %d", status);
445474
VerifyOrExit(status == PSA_SUCCESS, error = CHIP_ERROR_INTERNAL);
446475

447476
for (uint32_t blockNo = 1; key_length != 0; ++blockNo)
@@ -458,6 +487,7 @@ CHIP_ERROR PBKDF2_sha256::pbkdf2_sha256(const uint8_t * pass, size_t pass_length
458487
for (size_t iteration = 0; iteration < iteration_count; ++iteration)
459488
{
460489
status = psa_mac_compute(keyId, algorithm, in, inLength, out, sizeof(out), &outLength);
490+
ChipLogError(Crypto, "pbkdf2_sha256: psa_mac_compute status: %d", status);
461491
VerifyOrExit(status == PSA_SUCCESS && outLength == kMacLength, error = CHIP_ERROR_INTERNAL);
462492

463493
for (size_t byteNo = 0; byteNo < kMacLength; ++byteNo)
@@ -492,6 +522,7 @@ CHIP_ERROR DRBG_get_bytes(uint8_t * out_buffer, const size_t out_length)
492522
VerifyOrReturnError(isBufferNonEmpty(out_buffer, out_length), CHIP_ERROR_INVALID_ARGUMENT);
493523

494524
const psa_status_t status = psa_generate_random(out_buffer, out_length);
525+
ChipLogError(Crypto, "DRBG_get_bytes: psa_generate_random status: %d", status);
495526

496527
return status == PSA_SUCCESS ? CHIP_NO_ERROR : CHIP_ERROR_INTERNAL;
497528
}
@@ -513,6 +544,7 @@ CHIP_ERROR P256Keypair::ECDSA_sign_msg(const uint8_t * msg, const size_t msg_len
513544

514545
status = psa_sign_message(context.key_id, PSA_ALG_ECDSA(PSA_ALG_SHA_256), msg, msg_length, out_signature.Bytes(),
515546
out_signature.Capacity(), &outputLen);
547+
ChipLogError(Crypto, "ECDSA_sign_msg: psa_sign_message status: %d", status);
516548

517549
VerifyOrExit(status == PSA_SUCCESS, error = CHIP_ERROR_INTERNAL);
518550
VerifyOrExit(outputLen == kP256_ECDSA_Signature_Length_Raw, error = CHIP_ERROR_INTERNAL);
@@ -538,9 +570,11 @@ CHIP_ERROR P256PublicKey::ECDSA_validate_msg_signature(const uint8_t * msg, cons
538570
psa_set_key_usage_flags(&attributes, PSA_KEY_USAGE_VERIFY_MESSAGE);
539571

540572
status = psa_import_key(&attributes, ConstBytes(), Length(), &keyId);
573+
ChipLogError(Crypto, "ECDSA_validate_msg_signature: psa_import_key status: %d", status);
541574
VerifyOrExit(status == PSA_SUCCESS, error = CHIP_ERROR_INTERNAL);
542575

543576
status = psa_verify_message(keyId, PSA_ALG_ECDSA(PSA_ALG_SHA_256), msg, msg_length, signature.ConstBytes(), signature.Length());
577+
ChipLogError(Crypto, "ECDSA_validate_msg_signature: psa_verify_message status: %d", status);
544578
VerifyOrExit(status == PSA_SUCCESS, error = CHIP_ERROR_INVALID_SIGNATURE);
545579

546580
exit:
@@ -567,9 +601,11 @@ CHIP_ERROR P256PublicKey::ECDSA_validate_hash_signature(const uint8_t * hash, co
567601
psa_set_key_algorithm(&attributes, PSA_ALG_ECDSA(PSA_ALG_SHA_256));
568602

569603
status = psa_import_key(&attributes, ConstBytes(), Length(), &keyId);
604+
ChipLogError(Crypto, "ECDSA_validate_hash_signature: psa_import_key status: %d", status);
570605
VerifyOrExit(status == PSA_SUCCESS, error = CHIP_ERROR_INTERNAL);
571606

572607
status = psa_verify_hash(keyId, PSA_ALG_ECDSA(PSA_ALG_SHA_256), hash, hash_length, signature.ConstBytes(), signature.Length());
608+
ChipLogError(Crypto, "ECDSA_validate_hash_signature: psa_verify_hash status: %d", status);
573609
VerifyOrExit(status == PSA_SUCCESS, error = CHIP_ERROR_INVALID_SIGNATURE);
574610

575611
exit:
@@ -592,6 +628,7 @@ CHIP_ERROR P256Keypair::ECDH_derive_secret(const P256PublicKey & remote_public_k
592628

593629
status = psa_raw_key_agreement(PSA_ALG_ECDH, context.key_id, remote_public_key.ConstBytes(), remote_public_key.Length(),
594630
out_secret.Bytes(), outputSize, &outputLength);
631+
ChipLogError(Crypto, "ECDH_derive_secret: psa_raw_key_agreement status: %d", status);
595632
VerifyOrExit(status == PSA_SUCCESS, error = CHIP_ERROR_INTERNAL);
596633
SuccessOrExit(error = out_secret.SetLength(outputLength));
597634

0 commit comments

Comments
 (0)