Change NFC log messaged level (#906)

* nfc: change nfc worker log messaged to debug level
* FuriHal: switch logging level to trace in nfc

Co-authored-by: Aleksandr Kutuzov <alleteam@gmail.com>

applications/nfc/nfc_worker.c

@@ -144,7 +144,7 @@ void nfc_worker_emulate(NfcWorker* nfc_worker) {
     NfcDeviceCommonData* data = &nfc_worker->dev_data->nfc_data;
     while(nfc_worker->state == NfcWorkerStateEmulate) {
         if(furi_hal_nfc_listen(data->uid, data->uid_len, data->atqa, data->sak, false, 100)) {
-            FURI_LOG_I(TAG, "Reader detected");
+            FURI_LOG_D(TAG, "Reader detected");
         }
         osDelay(10);
     }
@@ -174,17 +174,17 @@ void nfc_worker_read_emv_app(NfcWorker* nfc_worker) {
                     result->nfc_data.uid, dev_list[0].dev.nfca.nfcId1, result->nfc_data.uid_len);
                 result->nfc_data.protocol = NfcDeviceProtocolEMV;
 
-                FURI_LOG_I(TAG, "Send select PPSE command");
+                FURI_LOG_D(TAG, "Send select PPSE command");
                 tx_len = emv_prepare_select_ppse(tx_buff);
                 err = furi_hal_nfc_data_exchange(tx_buff, tx_len, &rx_buff, &rx_len, false);
                 if(err != ERR_NONE) {
-                    FURI_LOG_E(TAG, "Error during selection PPSE request: %d", err);
+                    FURI_LOG_D(TAG, "Error during selection PPSE request: %d", err);
                     furi_hal_nfc_deactivate();
                     continue;
                 }
-                FURI_LOG_I(TAG, "Select PPSE response received. Start parsing response");
+                FURI_LOG_D(TAG, "Select PPSE response received. Start parsing response");
                 if(emv_decode_ppse_response(rx_buff, *rx_len, &emv_app)) {
-                    FURI_LOG_I(TAG, "Select PPSE responce parced");
+                    FURI_LOG_D(TAG, "Select PPSE responce parced");
                     // Notify caller and exit
                     result->emv_data.aid_len = emv_app.aid_len;
                     memcpy(result->emv_data.aid, emv_app.aid, emv_app.aid_len);
@@ -193,7 +193,7 @@ void nfc_worker_read_emv_app(NfcWorker* nfc_worker) {
                     }
                     break;
                 } else {
-                    FURI_LOG_E(TAG, "Can't find pay application");
+                    FURI_LOG_D(TAG, "Can't find pay application");
                     furi_hal_nfc_deactivate();
                     continue;
                 }
@@ -204,7 +204,7 @@ void nfc_worker_read_emv_app(NfcWorker* nfc_worker) {
             }
         } else {
             // Can't find EMV card
-            FURI_LOG_W(TAG, "Can't find any cards");
+            FURI_LOG_D(TAG, "Can't find any cards");
             furi_hal_nfc_deactivate();
         }
         osDelay(20);
@@ -235,53 +235,53 @@ void nfc_worker_read_emv(NfcWorker* nfc_worker) {
                     result->nfc_data.uid, dev_list[0].dev.nfca.nfcId1, result->nfc_data.uid_len);
                 result->nfc_data.protocol = NfcDeviceProtocolEMV;
 
-                FURI_LOG_I(TAG, "Send select PPSE command");
+                FURI_LOG_D(TAG, "Send select PPSE command");
                 tx_len = emv_prepare_select_ppse(tx_buff);
                 err = furi_hal_nfc_data_exchange(tx_buff, tx_len, &rx_buff, &rx_len, false);
                 if(err != ERR_NONE) {
-                    FURI_LOG_E(TAG, "Error during selection PPSE request: %d", err);
+                    FURI_LOG_D(TAG, "Error during selection PPSE request: %d", err);
                     furi_hal_nfc_deactivate();
                     continue;
                 }
-                FURI_LOG_I(TAG, "Select PPSE response received. Start parsing response");
+                FURI_LOG_D(TAG, "Select PPSE response received. Start parsing response");
                 if(emv_decode_ppse_response(rx_buff, *rx_len, &emv_app)) {
-                    FURI_LOG_I(TAG, "Select PPSE responce parced");
+                    FURI_LOG_D(TAG, "Select PPSE responce parced");
                     result->emv_data.aid_len = emv_app.aid_len;
                     memcpy(result->emv_data.aid, emv_app.aid, emv_app.aid_len);
                 } else {
-                    FURI_LOG_E(TAG, "Can't find pay application");
+                    FURI_LOG_D(TAG, "Can't find pay application");
                     furi_hal_nfc_deactivate();
                     continue;
                 }
-                FURI_LOG_I(TAG, "Starting application ...");
+                FURI_LOG_D(TAG, "Starting application ...");
                 tx_len = emv_prepare_select_app(tx_buff, &emv_app);
                 err = furi_hal_nfc_data_exchange(tx_buff, tx_len, &rx_buff, &rx_len, false);
                 if(err != ERR_NONE) {
-                    FURI_LOG_E(TAG, "Error during application selection request: %d", err);
+                    FURI_LOG_D(TAG, "Error during application selection request: %d", err);
                     furi_hal_nfc_deactivate();
                     continue;
                 }
-                FURI_LOG_I(TAG, "Select application response received. Start parsing response");
+                FURI_LOG_D(TAG, "Select application response received. Start parsing response");
                 if(emv_decode_select_app_response(rx_buff, *rx_len, &emv_app)) {
-                    FURI_LOG_I(TAG, "Card name: %s", emv_app.name);
+                    FURI_LOG_D(TAG, "Card name: %s", emv_app.name);
                     memcpy(result->emv_data.name, emv_app.name, sizeof(emv_app.name));
                 } else if(emv_app.pdol.size > 0) {
-                    FURI_LOG_W(TAG, "Can't find card name, but PDOL is present.");
+                    FURI_LOG_D(TAG, "Can't find card name, but PDOL is present.");
                 } else {
-                    FURI_LOG_E(TAG, "Can't find card name or PDOL");
+                    FURI_LOG_D(TAG, "Can't find card name or PDOL");
                     furi_hal_nfc_deactivate();
                     continue;
                 }
-                FURI_LOG_I(TAG, "Starting Get Processing Options command ...");
+                FURI_LOG_D(TAG, "Starting Get Processing Options command ...");
                 tx_len = emv_prepare_get_proc_opt(tx_buff, &emv_app);
                 err = furi_hal_nfc_data_exchange(tx_buff, tx_len, &rx_buff, &rx_len, false);
                 if(err != ERR_NONE) {
-                    FURI_LOG_E(TAG, "Error during Get Processing Options command: %d", err);
+                    FURI_LOG_D(TAG, "Error during Get Processing Options command: %d", err);
                     furi_hal_nfc_deactivate();
                     continue;
                 }
                 if(emv_decode_get_proc_opt(rx_buff, *rx_len, &emv_app)) {
-                    FURI_LOG_I(TAG, "Card number parsed");
+                    FURI_LOG_D(TAG, "Card number parsed");
                     result->emv_data.number_len = emv_app.card_number_len;
                     memcpy(result->emv_data.number, emv_app.card_number, emv_app.card_number_len);
                     // Notify caller and exit
@@ -304,7 +304,7 @@ void nfc_worker_read_emv(NfcWorker* nfc_worker) {
                             err = furi_hal_nfc_data_exchange(
                                 tx_buff, tx_len, &rx_buff, &rx_len, false);
                             if(err != ERR_NONE) {
-                                FURI_LOG_E(
+                                FURI_LOG_D(
                                     TAG,
                                     "Error reading application sfi %d, record %d",
                                     sfi,
@@ -317,7 +317,7 @@ void nfc_worker_read_emv(NfcWorker* nfc_worker) {
                         }
                     }
                     if(pan_found) {
-                        FURI_LOG_I(TAG, "Card PAN found");
+                        FURI_LOG_D(TAG, "Card PAN found");
                         result->emv_data.number_len = emv_app.card_number_len;
                         memcpy(
                             result->emv_data.number,
@@ -339,7 +339,7 @@ void nfc_worker_read_emv(NfcWorker* nfc_worker) {
                         }
                         break;
                     } else {
-                        FURI_LOG_E(TAG, "Can't read card number");
+                        FURI_LOG_D(TAG, "Can't read card number");
                     }
                     furi_hal_nfc_deactivate();
                 }
@@ -350,7 +350,7 @@ void nfc_worker_read_emv(NfcWorker* nfc_worker) {
             }
         } else {
             // Can't find EMV card
-            FURI_LOG_W(TAG, "Can't find any cards");
+            FURI_LOG_D(TAG, "Can't find any cards");
             furi_hal_nfc_deactivate();
         }
         osDelay(20);
@@ -412,63 +412,63 @@ void nfc_worker_emulate_apdu(NfcWorker* nfc_worker) {
 
     while(nfc_worker->state == NfcWorkerStateEmulateApdu) {
         if(furi_hal_nfc_listen(params.uid, params.uid_len, params.atqa, params.sak, false, 300)) {
-            FURI_LOG_I(TAG, "POS terminal detected");
+            FURI_LOG_D(TAG, "POS terminal detected");
             // Read data from POS terminal
             err = furi_hal_nfc_data_exchange(NULL, 0, &rx_buff, &rx_len, false);
             if(err == ERR_NONE) {
-                FURI_LOG_I(TAG, "Received Select PPSE");
+                FURI_LOG_D(TAG, "Received Select PPSE");
             } else {
-                FURI_LOG_E(TAG, "Error in 1st data exchange: select PPSE");
+                FURI_LOG_D(TAG, "Error in 1st data exchange: select PPSE");
                 furi_hal_nfc_deactivate();
                 continue;
             }
-            FURI_LOG_I(TAG, "Transive SELECT PPSE ANS");
+            FURI_LOG_D(TAG, "Transive SELECT PPSE ANS");
             tx_len = emv_select_ppse_ans(tx_buff);
             err = furi_hal_nfc_data_exchange(tx_buff, tx_len, &rx_buff, &rx_len, false);
             if(err == ERR_NONE) {
-                FURI_LOG_I(TAG, "Received Select APP");
+                FURI_LOG_D(TAG, "Received Select APP");
             } else {
-                FURI_LOG_E(TAG, "Error in 2nd data exchange: select APP");
+                FURI_LOG_D(TAG, "Error in 2nd data exchange: select APP");
                 furi_hal_nfc_deactivate();
                 continue;
             }
 
-            FURI_LOG_I(TAG, "Transive SELECT APP ANS");
+            FURI_LOG_D(TAG, "Transive SELECT APP ANS");
             tx_len = emv_select_app_ans(tx_buff);
             err = furi_hal_nfc_data_exchange(tx_buff, tx_len, &rx_buff, &rx_len, false);
             if(err == ERR_NONE) {
-                FURI_LOG_I(TAG, "Received PDOL");
+                FURI_LOG_D(TAG, "Received PDOL");
             } else {
-                FURI_LOG_E(TAG, "Error in 3rd data exchange: receive PDOL");
+                FURI_LOG_D(TAG, "Error in 3rd data exchange: receive PDOL");
                 furi_hal_nfc_deactivate();
                 continue;
             }
 
-            FURI_LOG_I(TAG, "Transive PDOL ANS");
+            FURI_LOG_D(TAG, "Transive PDOL ANS");
             tx_len = emv_get_proc_opt_ans(tx_buff);
             err = furi_hal_nfc_data_exchange(tx_buff, tx_len, &rx_buff, &rx_len, false);
             if(err == ERR_NONE) {
-                FURI_LOG_I(TAG, "Transive PDOL ANS");
+                FURI_LOG_D(TAG, "Transive PDOL ANS");
             } else {
-                FURI_LOG_E(TAG, "Error in 4rd data exchange: Transive PDOL ANS");
+                FURI_LOG_D(TAG, "Error in 4rd data exchange: Transive PDOL ANS");
                 furi_hal_nfc_deactivate();
                 continue;
             }
 
             if(*rx_len != sizeof(debug_rx) || memcmp(rx_buff, debug_rx, sizeof(debug_rx))) {
-                FURI_LOG_E(TAG, "Failed long message test");
+                FURI_LOG_D(TAG, "Failed long message test");
             } else {
-                FURI_LOG_I(TAG, "Correct debug message received");
+                FURI_LOG_D(TAG, "Correct debug message received");
                 tx_len = sizeof(debug_tx);
                 err = furi_hal_nfc_data_exchange(
                     (uint8_t*)debug_tx, tx_len, &rx_buff, &rx_len, false);
                 if(err == ERR_NONE) {
-                    FURI_LOG_I(TAG, "Transive Debug message");
+                    FURI_LOG_D(TAG, "Transive Debug message");
                 }
             }
             furi_hal_nfc_deactivate();
         } else {
-            FURI_LOG_W(TAG, "Can't find reader");
+            FURI_LOG_D(TAG, "Can't find reader");
         }
         osDelay(20);
     }
@@ -495,26 +495,26 @@ void nfc_worker_read_mifare_ul(NfcWorker* nfc_worker) {
                    dev_list[0].dev.nfca.sensRes.platformInfo,
                    dev_list[0].dev.nfca.selRes.sak)) {
                 // Get Mifare Ultralight version
-                FURI_LOG_I(TAG, "Found Mifare Ultralight tag. Reading tag version");
+                FURI_LOG_D(TAG, "Found Mifare Ultralight tag. Reading tag version");
                 tx_len = mf_ul_prepare_get_version(tx_buff);
                 err = furi_hal_nfc_data_exchange(tx_buff, tx_len, &rx_buff, &rx_len, false);
                 if(err == ERR_NONE) {
                     mf_ul_parse_get_version_response(rx_buff, &mf_ul_read);
-                    FURI_LOG_I(
+                    FURI_LOG_D(
                         TAG,
                         "Mifare Ultralight Type: %d, Pages: %d",
                         mf_ul_read.type,
                         mf_ul_read.pages_to_read);
-                    FURI_LOG_I(TAG, "Reading signature ...");
+                    FURI_LOG_D(TAG, "Reading signature ...");
                     tx_len = mf_ul_prepare_read_signature(tx_buff);
                     if(furi_hal_nfc_data_exchange(tx_buff, tx_len, &rx_buff, &rx_len, false)) {
-                        FURI_LOG_W(TAG, "Failed reading signature");
+                        FURI_LOG_D(TAG, "Failed reading signature");
                         memset(mf_ul_read.data.signature, 0, sizeof(mf_ul_read.data.signature));
                     } else {
                         mf_ul_parse_read_signature_response(rx_buff, &mf_ul_read);
                     }
                 } else if(err == ERR_TIMEOUT) {
-                    FURI_LOG_W(
+                    FURI_LOG_D(
                         TAG,
                         "Card doesn't respond to GET VERSION command. Setting default read parameters");
                     err = ERR_NONE;
@@ -522,27 +522,27 @@ void nfc_worker_read_mifare_ul(NfcWorker* nfc_worker) {
                     // Reinit device
                     furi_hal_nfc_deactivate();
                     if(!furi_hal_nfc_detect(&dev_list, &dev_cnt, 300, false)) {
-                        FURI_LOG_E(TAG, "Lost connection. Restarting search");
+                        FURI_LOG_D(TAG, "Lost connection. Restarting search");
                         continue;
                     }
                 } else {
-                    FURI_LOG_E(
+                    FURI_LOG_D(
                         TAG, "Error getting Mifare Ultralight version. Error code: %d", err);
                     continue;
                 }
 
                 if(mf_ul_read.support_fast_read) {
-                    FURI_LOG_I(TAG, "Reading pages ...");
+                    FURI_LOG_D(TAG, "Reading pages ...");
                     tx_len = mf_ul_prepare_fast_read(tx_buff, 0x00, mf_ul_read.pages_to_read - 1);
                     if(furi_hal_nfc_data_exchange(tx_buff, tx_len, &rx_buff, &rx_len, false)) {
-                        FURI_LOG_E(TAG, "Failed reading pages");
+                        FURI_LOG_D(TAG, "Failed reading pages");
                         continue;
                     } else {
                         mf_ul_parse_fast_read_response(
                             rx_buff, 0x00, mf_ul_read.pages_to_read - 1, &mf_ul_read);
                     }
 
-                    FURI_LOG_I(TAG, "Reading 3 counters ...");
+                    FURI_LOG_D(TAG, "Reading 3 counters ...");
                     for(uint8_t i = 0; i < 3; i++) {
                         tx_len = mf_ul_prepare_read_cnt(tx_buff, i);
                         if(furi_hal_nfc_data_exchange(tx_buff, tx_len, &rx_buff, &rx_len, false)) {
@@ -553,11 +553,11 @@ void nfc_worker_read_mifare_ul(NfcWorker* nfc_worker) {
                         }
                     }
 
-                    FURI_LOG_I(TAG, "Checking tearing flags ...");
+                    FURI_LOG_D(TAG, "Checking tearing flags ...");
                     for(uint8_t i = 0; i < 3; i++) {
                         tx_len = mf_ul_prepare_check_tearing(tx_buff, i);
                         if(furi_hal_nfc_data_exchange(tx_buff, tx_len, &rx_buff, &rx_len, false)) {
-                            FURI_LOG_E(TAG, "Error checking tearing flag %d", i);
+                            FURI_LOG_D(TAG, "Error checking tearing flag %d", i);
                             mf_ul_read.data.tearing[i] = MF_UL_TEARING_FLAG_DEFAULT;
                         } else {
                             mf_ul_parse_check_tearing_response(rx_buff, i, &mf_ul_read);
@@ -566,10 +566,10 @@ void nfc_worker_read_mifare_ul(NfcWorker* nfc_worker) {
                 } else {
                     // READ card with READ command (4 pages at a time)
                     for(uint8_t page = 0; page < mf_ul_read.pages_to_read; page += 4) {
-                        FURI_LOG_I(TAG, "Reading pages %d - %d ...", page, page + 3);
+                        FURI_LOG_D(TAG, "Reading pages %d - %d ...", page, page + 3);
                         tx_len = mf_ul_prepare_read(tx_buff, page);
                         if(furi_hal_nfc_data_exchange(tx_buff, tx_len, &rx_buff, &rx_len, false)) {
-                            FURI_LOG_E(TAG, "Read pages %d - %d failed", page, page + 3);
+                            FURI_LOG_D(TAG, "Read pages %d - %d failed", page, page + 3);
                             continue;
                         } else {
                             mf_ul_parse_read_response(rx_buff, page, &mf_ul_read);
@@ -596,7 +596,7 @@ void nfc_worker_read_mifare_ul(NfcWorker* nfc_worker) {
                 FURI_LOG_W(TAG, "Tag does not support Mifare Ultralight");
             }
         } else {
-            FURI_LOG_W(TAG, "Can't find any tags");
+            FURI_LOG_D(TAG, "Can't find any tags");
         }
         osDelay(100);
     }
@@ -634,14 +634,17 @@ void nfc_worker_emulate_mifare_ul(NfcWorker* nfc_worker) {
                         if(err == ERR_NONE) {
                             continue;
                         } else {
+                            FURI_LOG_D(TAG, "Communication error: %d", err);
                             break;
                         }
                     } else {
+                        FURI_LOG_D(TAG, "Not valid command: %02X", rx_buff[0]);
                         furi_hal_nfc_deactivate();
                         break;
                     }
                 }
             } else {
+                FURI_LOG_D(TAG, "Error in 1st data exchange");
                 furi_hal_nfc_deactivate();
             }
         }
@@ -652,6 +655,7 @@ void nfc_worker_emulate_mifare_ul(NfcWorker* nfc_worker) {
                 nfc_worker->callback(nfc_worker->context);
             }
         }
+        FURI_LOG_D(TAG, "Can't find reader");
         osThreadYield();
     }
 }

firmware/targets/f6/furi-hal/furi-hal-nfc.c

@@ -65,7 +65,7 @@ bool furi_hal_nfc_detect(rfalNfcDevice **dev_list, uint8_t* dev_cnt, uint32_t ti
     while(state != RFAL_NFC_STATE_ACTIVATED) {
         rfalNfcWorker();
         state = rfalNfcGetState();
-        FURI_LOG_D(TAG, "Current state %d", state);
+        FURI_LOG_T(TAG, "Current state %d", state);
         if(state == RFAL_NFC_STATE_POLL_ACTIVATION) {
             start = DWT->CYCCNT;
             continue;
@@ -75,7 +75,7 @@ bool furi_hal_nfc_detect(rfalNfcDevice **dev_list, uint8_t* dev_cnt, uint32_t ti
         }
         if(DWT->CYCCNT - start > timeout * clocks_in_ms) {
             rfalNfcDeactivate(true);
-            FURI_LOG_D(TAG, "Timeout");
+            FURI_LOG_T(TAG, "Timeout");
             return false;
         }
         osThreadYield();

firmware/targets/f7/furi-hal/furi-hal-nfc.c

@@ -65,7 +65,7 @@ bool furi_hal_nfc_detect(rfalNfcDevice **dev_list, uint8_t* dev_cnt, uint32_t ti
     while(state != RFAL_NFC_STATE_ACTIVATED) {
         rfalNfcWorker();
         state = rfalNfcGetState();
-        FURI_LOG_D(TAG, "Current state %d", state);
+        FURI_LOG_T(TAG, "Current state %d", state);
         if(state == RFAL_NFC_STATE_POLL_ACTIVATION) {
             start = DWT->CYCCNT;
             continue;
@@ -75,7 +75,7 @@ bool furi_hal_nfc_detect(rfalNfcDevice **dev_list, uint8_t* dev_cnt, uint32_t ti
         }
         if(DWT->CYCCNT - start > timeout * clocks_in_ms) {
             rfalNfcDeactivate(true);
-            FURI_LOG_D(TAG, "Timeout");
+            FURI_LOG_T(TAG, "Timeout");
             return false;
         }
         osThreadYield();