Add logging

Author: dhebbeker

lib/storage/storage.cpp

@@ -3,9 +3,19 @@
 #include <USB.h>
 #include <USBMSC.h>
 #include <cstdint>
-#include <iostream>
+#include <esp32-hal-log.h>
+#include <esp_partition.h>
 #include <string>
 
+#if ARDUINO_USB_CDC_ON_BOOT == 1
+#define HWSerial Serial0
+#define USBSerial Serial
+#else
+#define HWSerial Serial
+#include <USBCDC.h>
+USBCDC USBSerial;
+#endif
+
 #if defined(ARDUINO_USB_MODE)
 static_assert(ARDUINO_USB_MODE == 0, "USB must be in OTG mode");
 #endif
@@ -14,16 +24,29 @@ const esp_partition_t *check_ffat_partition(const char *label); // defined in FF
 
 static const std::string rootPath = "/";
 static constexpr std::size_t blockSize = 512; // bytes
+static const char *const TAG = "STORAGE";
 
 static const esp_partition_t *partition;
 static USBMSC usbMsc;
 static bool usbIsRunning = false;
 static bool fileSystemIsReady = false;
 
+static void usb_stopped_cb(void *const pvParameters)
+{
+    Storage::switchToApplicationMode();
+    vTaskDelete(nullptr);
+}
+
+static void usb_started_cb(void *const pvParameters)
+{
+    Storage::switchToUsbMode();
+    vTaskDelete(nullptr);
+}
+
 static void callbackUsbStarted(void *, esp_event_base_t, int32_t event_id, void *)
 {
     usbIsRunning = true;
-    Storage::switchToUsbMode();
+    xTaskCreate(usb_started_cb, "USB_Started_CB", 4096, nullptr, 5, nullptr);
 }
 
 static void callbackUsbStopped(void *, esp_event_base_t, int32_t event_id, void *)
@@ -33,7 +56,7 @@ static void callbackUsbStopped(void *, esp_event_base_t, int32_t event_id, void
         return;
     }
     usbIsRunning = false;
-    Storage::switchToApplicationMode();
+    xTaskCreate(usb_stopped_cb, "USB_Stopped_CB", 4096, nullptr, 5, nullptr);
 }
 
 /**
@@ -47,7 +70,7 @@ static void callbackUsbStopped(void *, esp_event_base_t, int32_t event_id, void
 static std::int32_t usbMsc_onWrite(const std::uint32_t lba, const std::uint32_t offset, std::uint8_t *const buffer,
                                    const uint32_t bufsize)
 {
-    std::cout << "MSC WRITE: lba: " << lba << ", offset: " << offset << ", bufsize: " << bufsize << std::endl;
+    ESP_LOGV(TAG, "MSC WRITE: lba: %u, offset: %u, bufsize: %u\n", lba, offset, bufsize);
     const std::uint32_t byteOffset = lba * blockSize + offset;
     ESP_ERROR_CHECK(esp_partition_erase_range(partition, byteOffset, bufsize)); // erase must be called before write
     ESP_ERROR_CHECK(esp_partition_write(partition, byteOffset, buffer, bufsize));
@@ -68,16 +91,15 @@ static std::int32_t usbMsc_onWrite(const std::uint32_t lba, const std::uint32_t
 static std::int32_t usbMsc_onRead(const std::uint32_t lba, const std::uint32_t offset, void *const buffer,
                                   const std::uint32_t bufsize)
 {
-    std::cout << "MSC READ: lba: " << lba << ", offset: " << offset << ", bufsize: " << bufsize << std::endl;
+    ESP_LOGV(TAG, "MSC READ: lba: %u, offset: %u, bufsize: %u\n", lba, offset, bufsize);
     const std::uint32_t byteOffset = lba * blockSize + offset;
     ESP_ERROR_CHECK(esp_partition_read(partition, byteOffset, buffer, bufsize));
     return bufsize;
 }
 
 static bool usbMsc_onStartStop(const std::uint8_t power_condition, const bool start, const bool load_eject)
 {
-    std::cout << "MSC START/STOP: power: " << power_condition << ", start: " << start << ", eject: " << load_eject
-              << std::endl;
+    ESP_LOGV(TAG, "MSC START/STOP: power: %u, start: %u, eject: %u\n", power_condition, start, load_eject);
     return true;
 }
 
@@ -86,25 +108,27 @@ std::size_t Storage::size()
     return FFat.totalBytes();
 }
 
-void Storage::begin(const bool formatFsOnFail, const char *const partitionLabel)
+bool Storage::begin(const bool formatFsOnFail, const char *const partitionLabel)
 {
+    ESP_LOGI(TAG, "Starting storage...");
     partition = check_ffat_partition(partitionLabel);
 
     if (!partition)
     {
-        std::cerr << "Error with partition!" << std::endl;
-        return;
+        ESP_LOGE(TAG, "Error with partition!");
+        return false;
     }
 
     // initialize file system
     const auto basePath = rootPath + partitionLabel;
     constexpr auto maxOpenFiles = 10U;
     if (!FFat.begin(formatFsOnFail, basePath.c_str(), maxOpenFiles, partitionLabel))
     {
-        std::cerr << "File-system initialization failed!" << std::endl;
-        return;
+        ESP_LOGE(TAG, "File-system initialization failed!");
+        return false;
     }
-    std::cout << "Storage has a size of " << size() << " bytes." << std::endl;
+    ESP_LOGI(TAG, "Storage has a size of %u bytes.", size());
+    ESP_LOGI(TAG, "Storage mounted at '%s'.", basePath.c_str());
 
     // setup USB Mass Storage Class
     usbMsc.vendorID("TTS");        // max 8 chars
@@ -116,13 +140,23 @@ void Storage::begin(const bool formatFsOnFail, const char *const partitionLabel)
     usbMsc.onWrite(usbMsc_onWrite);
     // usbMsc is ready for read/write
     usbMsc.mediaPresent(true);
-    usbMsc.begin(FFat.totalBytes() / blockSize, blockSize);
+    if (!usbMsc.begin(FFat.totalBytes() / blockSize, blockSize))
+    {
+        ESP_LOGE(TAG, "USB MSC initialization failed!");
+        return false;
+    }
     fileSystemIsReady = true;
 
     // subscribe to USB events
     USB.onEvent(ARDUINO_USB_STARTED_EVENT, callbackUsbStarted);
     USB.onEvent(ARDUINO_USB_STOPPED_EVENT, callbackUsbStopped);
-    USB.begin();
+    if (!USB.begin())
+    {
+        ESP_LOGE(TAG, "USB initialization failed!");
+        return false;
+    }
+    ESP_LOGI(TAG, "Storage started.");
+    return true;
 }
 
 void Storage::end()
@@ -138,6 +172,7 @@ void Storage::switchToUsbMode()
     FFat.end(); // flush and unmount
     fileSystemIsReady = false;
     usbMsc.mediaPresent(true);
+    ESP_LOGD(TAG, "Switched to USB mode");
 }
 
 bool Storage::isFileSystemReady()
@@ -151,6 +186,7 @@ void Storage::switchToApplicationMode()
     FFat.end();   // invalidate cache
     FFat.begin(); // update data
     fileSystemIsReady = true;
+    ESP_LOGD(TAG, "Switched to application mode");
 }
 
 fs::FS &Storage::getFileSystem()

lib/storage/storage.hpp

@@ -4,13 +4,12 @@
 #include <USBMSC.h>
 #include <cstddef>
 #include <esp_event_base.h>
-#include <esp_partition.h>
 #include <string>
 
 class Storage
 {
   public:
-    static void begin(bool formatFsOnFail = false, const char *partitionLabel = FFAT_PARTITION_LABEL);
+    static bool begin(bool formatFsOnFail = false, const char *partitionLabel = FFAT_PARTITION_LABEL);
     static void end();
     static bool isFileSystemReady();
     static std::size_t size();

platformio.ini

@@ -6,6 +6,7 @@ board_build.filesystem = fatfs
 board_build.partitions = default_ffat_8MB.csv
 monitor_filters = esp32_exception_decoder
 monitor_speed = 115200
+build_type = debug
 
 build_unflags =
     -DARDUINO_USB_MODE=1
@@ -18,3 +19,5 @@ build_flags =
     -DARDUINO_USB_CDC_ON_BOOT=1
     -DARDUINO_USB_MSC_ON_BOOT=0
     -DARDUINO_USB_DFU_ON_BOOT=0
+    -DCONFIG_ARDUHAL_LOG_COLORS=1
+    -DCORE_DEBUG_LEVEL=ARDUHAL_LOG_LEVEL_VERBOSE

src/main.cpp

@@ -1,4 +1,6 @@
 #include <Arduino.h>
+#include <esp32-hal-log.h>
+#include <iostream>
 #include <storage.hpp>
 
 #if ARDUINO_USB_CDC_ON_BOOT == 1
@@ -10,6 +12,8 @@
 USBCDC USBSerial;
 #endif
 
+static const char *const TAG = "MAIN";
+
 struct TestStorage : Storage
 {
 
@@ -18,12 +22,13 @@ struct TestStorage : Storage
      */
     static void listFiles(const char *const dirname)
     {
-        auto FFat = getFileSystem();
+        // auto FFat = getFileSystem();
         HWSerial.printf("Directory: '%s'\n", dirname);
         File root = FFat.open(dirname);
         if (!root || !root.isDirectory())
         {
-            HWSerial.printf("Error: '%s' is not a directory!\n", dirname);
+            ESP_LOGE(TAG, "'%s' is not a directory!\n", dirname);
+            root.close();
             return;
         }
 
@@ -33,15 +38,24 @@ struct TestStorage : Storage
             HWSerial.printf("  %s (%s, %d Bytes)\n", file.name(), file.isDirectory() ? "d" : "f", file.size());
             file = root.openNextFile();
         }
+        file.close();
+        root.close();
     }
 };
 
 void setup()
 {
-    ESP_LOGE("tag", "hello"), HWSerial.begin(115200);
+    HWSerial.begin(115200);
     HWSerial.setDebugOutput(true);
-    Storage::begin();
-
+    delay(300); // in order to give the serial monitor time to start
+    HWSerial.println("START HWSerial");
+    ESP_LOGE(TAG, "Example error");
+    ESP_LOGW(TAG, "Example warning");
+    ESP_LOGI(TAG, "Example info");
+    ESP_LOGD(TAG, "Example debug");
+    ESP_LOGV(TAG, "Example verbose");
+    std::cout << "Hello" << std::endl;
+    Storage::begin(true);
     USBSerial.begin();
 }