Merge pull request #283 from geonnave/add-logs

Add logging

examples/coap/Cargo.toml

@@ -19,3 +19,6 @@ coap-handler = "0.2"
 coap-handler-implementations = "0.5"
 coap-numbers = "0.2.3"
 coap-message-utils = "0.3.1"
+
+env_logger = "0.11.3"
+log = "0.4"

examples/coap/src/bin/coapclient.rs

@@ -2,6 +2,7 @@ use coap::CoAPClient;
 use coap_lite::ResponseType;
 use hexlit::hex;
 use lakers::*;
+use log::*;
 use std::time::Duration;
 
 const _ID_CRED_I: &[u8] = &hex!("a104412b");
@@ -16,6 +17,8 @@ const CRED_R: &[u8] = &hex!("A2026008A101A5010202410A2001215820BBC34960526EA4D32
 const _G_R: &[u8] = &hex!("bbc34960526ea4d32e940cad2a234148ddc21791a12afbcbac93622046dd44f0");
 
 fn main() {
+    env_logger::init();
+    info!("Starting EDHOC CoAP Client");
     match client_handshake() {
         Ok(_) => println!("Handshake completed"),
         Err(e) => panic!("Handshake failed with error: {:?}", e),

examples/coap/src/bin/coapserver.rs

@@ -2,6 +2,7 @@ use coap_lite::{CoapRequest, Packet, ResponseType};
 use hexlit::hex;
 use lakers::*;
 use lakers_ead_authz::{ZeroTouchAuthenticator, ZeroTouchServer};
+use log::*;
 use std::net::UdpSocket;
 
 const ID_CRED_I: &[u8] = &hex!("a104412b");
@@ -14,6 +15,9 @@ const R: &[u8] = &hex!("72cc4761dbd4c78f758931aa589d348d1ef874a7e303ede2f140dcf3
 const W_TV: &[u8] = &hex!("4E5E15AB35008C15B89E91F9F329164D4AACD53D9923672CE0019F9ACD98573F");
 
 fn main() {
+    env_logger::init();
+    info!("Starting EDHOC CoAP Server");
+
     let mut buf = [0; MAX_MESSAGE_SIZE_LEN];
     let socket = UdpSocket::bind("127.0.0.1:5683").unwrap();
 

examples/lakers-no_std/Cargo.toml

@@ -20,6 +20,7 @@ cortex-m-semihosting = "0.5.0"
 panic-semihosting = { version = "0.6.0", features = ["exit"] }
 
 rtt-target = { version = "0.3.1", features = ["cortex-m"] }
+log = "0.4"
 
 [features]
 default = [ "rtt", "crypto-cryptocell310", "ead-none" ]

examples/lakers-no_std/README.md

@@ -20,3 +20,6 @@ and some needed RUSTFLAGS, so this should pretty much just work(tm):
 
 You can exit QEMU pressing `CTRL-A`, then `X`. Or, if you're using tmux like
 me, `CTRL-A`, `A`, `X`.
+
+## Disable logs
+To globally disable logs (e.g. for release builds), add the following feature: `log/release_max_level_off`.

lib/Cargo.toml

@@ -12,6 +12,8 @@ categories.workspace = true
 [dependencies]
 lakers-shared.workspace = true
 
+log = "0.4"
+
 [dev-dependencies]
 lakers-ead-authz = { workspace = true }
 lakers-crypto.workspace = true

lib/src/lib.rs

@@ -15,6 +15,9 @@
 //! [EDHOC]: https://datatracker.ietf.org/doc/html/rfc9528
 #![cfg_attr(not(test), no_std)]
 
+// use defmt_or_log::*; // FIXME: still not working
+use log::trace;
+
 pub use {lakers_shared::Crypto as CryptoTrait, lakers_shared::*};
 
 #[cfg(all(feature = "ead-authz", test))]
@@ -93,6 +96,7 @@ pub struct EdhocResponderDone<Crypto: CryptoTrait> {
 
 impl<'a, Crypto: CryptoTrait> EdhocResponder<'a, Crypto> {
     pub fn new(mut crypto: Crypto, r: &'a [u8], cred_r: CredentialRPK) -> Self {
+        trace!("Initializing EdhocInitiator");
         assert!(r.len() == P256_ELEM_LEN);
         let (y, g_y) = crypto.p256_generate_key_pair();
 
@@ -115,6 +119,7 @@ impl<'a, Crypto: CryptoTrait> EdhocResponder<'a, Crypto> {
         ),
         EDHOCError,
     > {
+        trace!("Enter process_message_1");
         let (state, c_i, ead_1) = r_process_message_1(&self.state, &mut self.crypto, message_1)?;
 
         Ok((
@@ -137,6 +142,7 @@ impl<'a, Crypto: CryptoTrait> EdhocResponderProcessedM1<'a, Crypto> {
         c_r: Option<ConnId>,
         ead_2: &Option<EADItem>,
     ) -> Result<(EdhocResponderWaitM3<Crypto>, BufferMessage2), EDHOCError> {
+        trace!("Enter prepare_message_2");
         let c_r = match c_r {
             Some(c_r) => c_r,
             None => generate_connection_identifier_cbor(&mut self.crypto),
@@ -175,6 +181,7 @@ impl<'a, Crypto: CryptoTrait> EdhocResponderWaitM3<Crypto> {
         ),
         EDHOCError,
     > {
+        trace!("Enter parse_message_3");
         match r_parse_message_3(&mut self.state, &mut self.crypto, message_3) {
             Ok((state, id_cred_i, ead_3)) => Ok((
                 EdhocResponderProcessingM3 {
@@ -194,6 +201,7 @@ impl<'a, Crypto: CryptoTrait> EdhocResponderProcessingM3<Crypto> {
         mut self,
         cred_i: CredentialRPK,
     ) -> Result<(EdhocResponderDone<Crypto>, [u8; SHA256_DIGEST_LEN]), EDHOCError> {
+        trace!("Enter verify_message_3");
         match r_verify_message_3(&mut self.state, &mut self.crypto, cred_i) {
             Ok((state, prk_out)) => Ok((
                 EdhocResponderDone {
@@ -242,12 +250,12 @@ impl<Crypto: CryptoTrait> EdhocResponderDone<Crypto> {
 
 impl<'a, Crypto: CryptoTrait> EdhocInitiator<Crypto> {
     pub fn new(mut crypto: Crypto) -> Self {
+        trace!("Initializing EdhocInitiator");
         // we only support a single cipher suite which is already CBOR-encoded
         let mut suites_i: BytesSuites = [0x0; SUITES_LEN];
         let suites_i_len = EDHOC_SUPPORTED_SUITES.len();
         suites_i[0..suites_i_len].copy_from_slice(&EDHOC_SUPPORTED_SUITES[..]);
         let (x, g_x) = crypto.p256_generate_key_pair();
-
         EdhocInitiator {
             state: InitiatorStart {
                 x,
@@ -264,6 +272,7 @@ impl<'a, Crypto: CryptoTrait> EdhocInitiator<Crypto> {
         c_i: Option<ConnId>,
         ead_1: &Option<EADItem>,
     ) -> Result<(EdhocInitiatorWaitM2<Crypto>, EdhocMessageBuffer), EDHOCError> {
+        trace!("Enter prepare_message_1");
         let c_i = match c_i {
             Some(c_i) => c_i,
             None => generate_connection_identifier_cbor(&mut self.crypto),
@@ -303,6 +312,7 @@ impl<'a, Crypto: CryptoTrait> EdhocInitiatorWaitM2<Crypto> {
         ),
         EDHOCError,
     > {
+        trace!("Enter parse_message_2");
         match i_parse_message_2(&self.state, &mut self.crypto, message_2) {
             Ok((state, c_r, id_cred_r, ead_2)) => Ok((
                 EdhocInitiatorProcessingM2 {
@@ -325,6 +335,7 @@ impl<'a, Crypto: CryptoTrait> EdhocInitiatorProcessingM2<Crypto> {
         cred_i: CredentialRPK,
         valid_cred_r: CredentialRPK,
     ) -> Result<EdhocInitiatorProcessedM2<Crypto>, EDHOCError> {
+        trace!("Enter verify_message_2");
         match i_verify_message_2(
             &self.state,
             &mut self.crypto,
@@ -354,6 +365,7 @@ impl<'a, Crypto: CryptoTrait> EdhocInitiatorProcessedM2<Crypto> {
         ),
         EDHOCError,
     > {
+        trace!("Enter prepare_message_3");
         match i_prepare_message_3(
             &mut self.state,
             &mut self.crypto,
@@ -433,6 +445,7 @@ pub fn credential_check_or_fetch(
     cred_expected: Option<CredentialRPK>,
     id_cred_received: CredentialRPK,
 ) -> Result<CredentialRPK, EDHOCError> {
+    trace!("Enter credential_check_or_fetch");
     // Processing of auth credentials according to draft-tiloca-lake-implem-cons
     // Comments tagged with a number refer to steps in Section 4.3.1. of draft-tiloca-lake-implem-cons
     if let Some(cred_expected) = cred_expected {

shared/Cargo.toml

@@ -14,6 +14,7 @@ categories.workspace = true
 [dependencies]
 pyo3 = { version = "0.20.2", features = ["extension-module"], optional = true }
 hex = { version = "0.4.3", optional = true }
+log = "0.4"
 
 [dev-dependencies]
 hexlit = "0.5.3"

shared/src/lib.rs

@@ -16,6 +16,7 @@ pub use edhoc_parser::*;
 pub use helpers::*;
 
 use core::num::NonZeroI16;
+use log::trace;
 
 mod crypto;
 pub use crypto::Crypto;
@@ -562,6 +563,7 @@ mod edhoc_parser {
     use super::*;
 
     pub fn parse_ead(buffer: &[u8]) -> Result<Option<EADItem>, EDHOCError> {
+        trace!("Enter parse_ead");
         // assuming label is a single byte integer (negative or positive)
         if let Some((&label, tail)) = buffer.split_first() {
             let label_res = if CBORDecoder::is_u8(label) {
@@ -601,6 +603,7 @@ mod edhoc_parser {
     pub fn parse_suites_i(
         mut decoder: CBORDecoder,
     ) -> Result<(BytesSuites, usize, CBORDecoder), EDHOCError> {
+        trace!("Enter parse_suites_i");
         let mut suites_i: BytesSuites = Default::default();
         if let Ok(curr) = decoder.current() {
             if CBOR_UINT_1BYTE_START == CBORDecoder::type_of(curr) {
@@ -641,6 +644,7 @@ mod edhoc_parser {
         ),
         EDHOCError,
     > {
+        trace!("Enter parse_message_1");
         let mut decoder = CBORDecoder::new(rcvd_message_1.as_slice());
         let method = decoder.u8()?;
 
@@ -674,6 +678,7 @@ mod edhoc_parser {
     pub fn parse_message_2(
         rcvd_message_2: &BufferMessage2,
     ) -> Result<(BytesP256ElemLen, BufferCiphertext2), EDHOCError> {
+        trace!("Enter parse_message_2");
         // FIXME decode negative integers as well
         let mut ciphertext_2: BufferCiphertext2 = BufferCiphertext2::new();
 
@@ -705,6 +710,7 @@ mod edhoc_parser {
     pub fn decode_plaintext_2(
         plaintext_2: &BufferCiphertext2,
     ) -> Result<(ConnId, IdCred, BytesMac2, Option<EADItem>), EDHOCError> {
+        trace!("Enter decode_plaintext_2");
         let mut mac_2: BytesMac2 = [0x00; MAC_LENGTH_2];
 
         let mut decoder = CBORDecoder::new(plaintext_2.as_slice());
@@ -743,6 +749,7 @@ mod edhoc_parser {
     pub fn decode_plaintext_3(
         plaintext_3: &BufferPlaintext3,
     ) -> Result<(IdCred, BytesMac3, Option<EADItem>), EDHOCError> {
+        trace!("Enter decode_plaintext_3");
         let mut mac_3: BytesMac3 = [0x00; MAC_LENGTH_3];
 
         let mut decoder = CBORDecoder::new(plaintext_3.as_slice());