From 26fcad218b9d73e8a66af774c1d848437e1faa43 Mon Sep 17 00:00:00 2001 From: Vasily Davydov Date: Thu, 11 May 2023 16:47:55 +0300 Subject: [PATCH 01/13] log: add logging lib --- source/shoh/src/threads/common/Log.h | 82 ++++++++++++++++++++++++++++ 1 file changed, 82 insertions(+) create mode 100644 source/shoh/src/threads/common/Log.h diff --git a/source/shoh/src/threads/common/Log.h b/source/shoh/src/threads/common/Log.h new file mode 100644 index 0000000..7703bf2 --- /dev/null +++ b/source/shoh/src/threads/common/Log.h @@ -0,0 +1,82 @@ +#ifndef __THREAD_COMMON_LOG_H_ +#define __THREAD_COMMON_LOG_H_ + +#include "chip.h" +#include "board.h" +#include +#include + +/* ================= Settings ================== */ +#define LOG_DEBUGGING_E +#define LOG_COLORED_OUTPUT +#define HIGH_PRIORITY_DEBUG +/* ================= Settings ================== */ + +// internal debug defines +#ifdef HIGH_PRIORITY_DEBUG +#include +#define INT_ASSERT(statement) assert(statement) +#else +#define INT_ASSERT(statement) +#endif + +#ifdef LOG_COLORED_OUTPUT +#define C_INFO "\x1b[34mINFO\x1b[0m" +#define C_DEBUG "\x1b[35mDEBUG\x1b[0m" +#define C_WARN "\x1b[33mWARNING\x1b[0m" +#define C_ERROR "\x1b[31mERROR\x1b[0m" +#else +#define C_INFO "INFO" +#define C_DEBUG "DEBUG" +#define C_WARN "WARNING" +#define C_ERROR "ERROR" +#endif + +#define LOG_BUFFER_MAX_CAP 500 +#define LOG_MESSAGE_MAX_CAP 150 + +#define _LOG_STREAMOUT(message, message_length) \ + INT_ASSERT(message_length > 0); \ + printf("%.*s\n", message_length, message); \ + +static void create_log_line(const char * _status, + const char * _location, + const size_t _line, + const char * _fmt, ...) +{ + va_list args; + va_start(args, _fmt); + char message [LOG_BUFFER_MAX_CAP] = {0}; + int message_len = vsnprintf(message, LOG_BUFFER_MAX_CAP, _fmt, args); + va_end(args); + char buffer [LOG_BUFFER_MAX_CAP] = {0}; + int buffer_len = snprintf(buffer, LOG_BUFFER_MAX_CAP, + "[%s] [File: %s] [Line: %ld] %.*s\n", + _status, + _location, + _line, + message_len, + message); + _LOG_STREAMOUT(buffer, buffer_len) + +} + +#define LOG_INFO(fmt, ...) \ + create_log_line(C_INFO, __FILE__, __LINE__, fmt, ##__VA_ARGS__); \ + +#define LOG_WARNING(fmt, ...) \ + create_log_line(C_WARN, __FILE__, __LINE__, fmt, ##__VA_ARGS__); \ + +#define LOG_ERROR(fmt, ...) \ + create_log_line(C_ERROR, __FILE__, __LINE__, fmt, ##__VA_ARGS__); \ + exit(1); \ + +#ifdef LOG_DEBUGGING_E +#define LOG_DEBUG(fmt, ...) \ + create_log_line(C_INFO, __FILE__, __LINE__, fmt, ##__VA_ARGS__); \ +#else +#define LOG_DEBUG(fmt, ...) +#endif + + +#endif /* __THREAD_COMMON_LOG_H_ */ \ No newline at end of file From 3fe383f18007b25e11438e7a09d66304356e1c4c Mon Sep 17 00:00:00 2001 From: Vasily Davydov Date: Thu, 11 May 2023 17:04:43 +0300 Subject: [PATCH 02/13] menu: add debug logging to menu --- source/shoh/src/threads/manager/Menu.cpp | 17 +++++++++++++++-- 1 file changed, 15 insertions(+), 2 deletions(-) diff --git a/source/shoh/src/threads/manager/Menu.cpp b/source/shoh/src/threads/manager/Menu.cpp index b7765f1..0415721 100644 --- a/source/shoh/src/threads/manager/Menu.cpp +++ b/source/shoh/src/threads/manager/Menu.cpp @@ -8,12 +8,14 @@ #include "Menu.h" #include #include "UserInterface.h" +#include "Log.h" Menu::Menu(ThreadCommon::QueueManager* qm): _qm(qm), current(&Menu::sInitView), ext_temp(-99, 99, 1), set_point(-99, 99, 1), main_text ("CURRENT %3d DESIRED %3d "), set_point_text("CURRENT %3d DESIRED[%3d] ") { + LOG_DEBUG("Creating Menu"); this->SetState(&Menu::sInitView); ext_temp.setCurrent(0); set_point.setCurrent(0); @@ -21,6 +23,7 @@ set_point_text("CURRENT %3d DESIRED[%3d] ") Menu::~Menu() { + LOG_DEBUG("Deleting Menu"); } void Menu::HandleEventPair (Event::EventPair *ep) @@ -71,10 +74,11 @@ void Menu::sInitView(const MenuObjEvent &e) switch (e.type) { case MenuObjEvent::eFocus: + LOG_DEBUG("enter sInitView"); this->NotifyAndRefreshUI("Loading..."); break; case MenuObjEvent::eUnFocus: - printf("NOTE: leave sInitView\n"); + LOG_DEBUG("leave sInitView"); this->NotifyAndRefreshUI(""); break; case MenuObjEvent::eRollClockWise: @@ -82,10 +86,11 @@ void Menu::sInitView(const MenuObjEvent &e) case MenuObjEvent::eRollCClockWise: break; case MenuObjEvent::eClick: + LOG_DEBUG("click sInitView"); this->SetState(&Menu::sMainView); break; case MenuObjEvent::eRefresh: - printf("NOTE: sInitView handled eRefresh.\n"); + LOG_DEBUG("refersh sInitView"); this->SetState(&Menu::sMainView); break; default: @@ -99,11 +104,13 @@ void Menu::sMainView(const MenuObjEvent &e) switch (e.type) { case MenuObjEvent::eFocus: + LOG_DEBUG("enter sMainView"); sprintf(screen_text, main_text, this->ext_temp.getCurrent(), this->set_point.getCurrent()); this->NotifyAndRefreshUI(screen_text); break; case MenuObjEvent::eUnFocus: + LOG_DEBUG("leave sMainView"); this->NotifyAndRefreshUI(""); break; case MenuObjEvent::eRollClockWise: @@ -111,11 +118,13 @@ void Menu::sMainView(const MenuObjEvent &e) case MenuObjEvent::eRollCClockWise: break; case MenuObjEvent::eClick: + LOG_DEBUG("click sMainView"); this->SetState(&Menu::sSetPointMod); break; case MenuObjEvent::eRefresh: sprintf(screen_text, main_text, this->ext_temp.getCurrent(), this->set_point.getCurrent()); + LOG_DEBUG("refresh sMainView"); this->NotifyAndRefreshUI(screen_text); break; default: @@ -129,11 +138,13 @@ void Menu::sSetPointMod(const MenuObjEvent &e) switch (e.type) { case MenuObjEvent::eFocus: + LOG_DEBUG("enter sSetPointMod"); sprintf(screen_text, set_point_text, this->ext_temp.getCurrent(), this->set_point.getCurrent()); this->NotifyAndRefreshUI(screen_text); break; case MenuObjEvent::eUnFocus: + LOG_DEBUG("leave sSetPointMod"); this->NotifyAndRefreshUI(""); break; case MenuObjEvent::eRollClockWise: @@ -149,9 +160,11 @@ void Menu::sSetPointMod(const MenuObjEvent &e) this->NotifyAndRefreshUI(screen_text); break; case MenuObjEvent::eClick: + LOG_DEBUG("click sSetPointMod"); this->SetState(&Menu::sMainView); break; case MenuObjEvent::eRefresh: + LOG_DEBUG("refresh sSetPointMod"); sprintf(screen_text, set_point_text, this->ext_temp.getCurrent(), this->set_point.getCurrent()); this->NotifyAndRefreshUI(screen_text); From 90656fae95327d7cb5295fcedeaef7093dd9a202 Mon Sep 17 00:00:00 2001 From: Vasily Davydov Date: Thu, 11 May 2023 17:29:56 +0300 Subject: [PATCH 03/13] log: correct macros --- source/shoh/src/threads/common/Log.h | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) diff --git a/source/shoh/src/threads/common/Log.h b/source/shoh/src/threads/common/Log.h index 7703bf2..6dfaf9d 100644 --- a/source/shoh/src/threads/common/Log.h +++ b/source/shoh/src/threads/common/Log.h @@ -7,9 +7,9 @@ #include /* ================= Settings ================== */ -#define LOG_DEBUGGING_E #define LOG_COLORED_OUTPUT #define HIGH_PRIORITY_DEBUG +#define LOG_DEBUG_MESSAGES 1 /* ================= Settings ================== */ // internal debug defines @@ -51,7 +51,7 @@ static void create_log_line(const char * _status, va_end(args); char buffer [LOG_BUFFER_MAX_CAP] = {0}; int buffer_len = snprintf(buffer, LOG_BUFFER_MAX_CAP, - "[%s] [File: %s] [Line: %ld] %.*s\n", + "[%s] [File: %s] [Line: %ld] %.*s", _status, _location, _line, @@ -69,9 +69,8 @@ static void create_log_line(const char * _status, #define LOG_ERROR(fmt, ...) \ create_log_line(C_ERROR, __FILE__, __LINE__, fmt, ##__VA_ARGS__); \ - exit(1); \ -#ifdef LOG_DEBUGGING_E +#if LOG_DEBUG_MESSAGES #define LOG_DEBUG(fmt, ...) \ create_log_line(C_INFO, __FILE__, __LINE__, fmt, ##__VA_ARGS__); \ #else From 1a4c09c4add14bef56f78cb6d1be0d0980ec2216 Mon Sep 17 00:00:00 2001 From: Vasily Davydov Date: Fri, 12 May 2023 00:57:55 +0300 Subject: [PATCH 04/13] threads: add logging --- .../shoh/src/threads/common/QueueManager.cpp | 4 ++++ .../shoh/src/threads/common/ThreadManager.cpp | 9 ++++++++- source/shoh/src/threads/manager/Manager.cpp | 5 ++++- source/shoh/src/threads/master/Master.cpp | 6 +++++- source/shoh/src/threads/rotary/Rotary.cpp | 20 +++++++++++++++++-- .../threads/user_interface/UserInterface.cpp | 7 ++++++- 6 files changed, 45 insertions(+), 6 deletions(-) diff --git a/source/shoh/src/threads/common/QueueManager.cpp b/source/shoh/src/threads/common/QueueManager.cpp index 8f4c42a..61a750a 100644 --- a/source/shoh/src/threads/common/QueueManager.cpp +++ b/source/shoh/src/threads/common/QueueManager.cpp @@ -6,17 +6,21 @@ */ #include "ThreadCommon.h" +#include "Log.h" ThreadCommon::QueueManager::QueueManager() {} bool ThreadCommon::QueueManager::createQueue(size_t queue_length, size_t item_size, Queue_id qid) { QueueHandle_t queue_to_create; + LOG_DEBUG("Creating queue with id %d", qid); if ((queue_to_create = xQueueCreate(queue_length, item_size))) { + LOG_DEBUG("Queue with id %d has been created", qid); queues.insert({qid, queue_to_create}); return true; } + LOG_ERROR("Failed to cerate queue with id %d", qid); return false; } diff --git a/source/shoh/src/threads/common/ThreadManager.cpp b/source/shoh/src/threads/common/ThreadManager.cpp index 2ac2803..877c5eb 100644 --- a/source/shoh/src/threads/common/ThreadManager.cpp +++ b/source/shoh/src/threads/common/ThreadManager.cpp @@ -1,4 +1,5 @@ #include "ThreadCommon.h" +#include "Log.h" ThreadCommon::ThreadManager::ThreadManager(){} @@ -10,12 +11,18 @@ bool ThreadCommon::ThreadManager::createTask(void (*task_func)(void*), void* parameters) { const char * t_name = name.c_str(); + LOG_DEBUG("Creating task [name: %s, priority: %ld, stack: %ld]", + t_name, priority, stack_size); BaseType_t taskCreated = xTaskCreate(task_func, t_name, stack_size, parameters, priority, NULL); - assert(taskCreated == pdPASS); + if (!(taskCreated == pdPASS)) + { + LOG_ERROR("Failed to create a task [name: %s, priority: %ld, stack: %ld]", + t_name, priority, stack_size) + } return (taskCreated == pdPASS); } diff --git a/source/shoh/src/threads/manager/Manager.cpp b/source/shoh/src/threads/manager/Manager.cpp index 2f4e9ca..668c551 100644 --- a/source/shoh/src/threads/manager/Manager.cpp +++ b/source/shoh/src/threads/manager/Manager.cpp @@ -7,15 +7,17 @@ #include "Manager.h" #include "ThreadCommon.h" +#include "Log.h" Manager::Manager(ThreadCommon::QueueManager* qm) : _qm(qm), _menu{qm} { + LOG_DEBUG("Creating Manager"); } Manager::~Manager() { - // TODO Auto-generated destructor stub + LOG_ERROR("Deleting Manager"); } Event::EventPair Manager::parseEvent(Event* e) @@ -32,6 +34,7 @@ Event::EventPair Manager::parseEvent(Event* e) return p; } } + LOG_WARNING("Event is empty"); return {ERROR_RETURN, Event::Null}; } diff --git a/source/shoh/src/threads/master/Master.cpp b/source/shoh/src/threads/master/Master.cpp index 775771b..18072e9 100644 --- a/source/shoh/src/threads/master/Master.cpp +++ b/source/shoh/src/threads/master/Master.cpp @@ -6,6 +6,7 @@ */ #include "Master.h" +#include "Log.h" static const char* rotary_direction[] = { @@ -17,7 +18,7 @@ static const char* rotary_direction[] = Master::Master(ThreadCommon::QueueManager* qm) : _qm(qm) { - + LOG_DEBUG("Creating Master"); } void Master::HandleEventType(Event* e, Event::EventType type) @@ -29,6 +30,7 @@ void Master::HandleEventType(Event* e, Event::EventType type) case Event::Rotary: //Comes from rotary, goes to manager _qm->send(ThreadCommon::QueueManager::manager_event_master, e, 0); + LOG_DEBUG("Rotary: %s has been forwarded to manager", rotary_direction[e->getDataOf(type)]); break; case Event::InternalTemp: // TODO remove (deprecated) @@ -37,10 +39,12 @@ void Master::HandleEventType(Event* e, Event::EventType type) //Comes from sensors, goes to relay & manager _qm->send(ThreadCommon::QueueManager::relay_event_master, e, 0); _qm->send(ThreadCommon::QueueManager::manager_event_master, e, 0); + LOG_DEBUG("ExtTemp: %d has been forwarded to manager and relay", e->getDataOf(type)); break; case Event::SetPoint: //Comes from manager, goes to relay _qm->send(ThreadCommon::QueueManager::relay_event_master, e, 0); + LOG_DEBUG("SetPoint: %d has been forwarded to relay", e->getDataOf(type)); break; default: assert(0); diff --git a/source/shoh/src/threads/rotary/Rotary.cpp b/source/shoh/src/threads/rotary/Rotary.cpp index eb9f19d..71c36ce 100644 --- a/source/shoh/src/threads/rotary/Rotary.cpp +++ b/source/shoh/src/threads/rotary/Rotary.cpp @@ -8,6 +8,7 @@ #include "Rotary.h" #include "board.h" #include "queue.h" +#include "Log.h" static QueueHandle_t * p_rotary_isr_q; @@ -20,6 +21,10 @@ extern "C" portBASE_TYPE xHigherPriorityWoken = pdFALSE; uint8_t data = ThreadCommon::RotaryAction::Right; xQueueSendFromISR (*p_rotary_isr_q, &data, &xHigherPriorityWoken); + if(!xHigherPriorityWoken) + { + LOG_WARNING("[PIN_INT0_IRQn] portEND_SWITCHING_ISR called with False value"); + } portEND_SWITCHING_ISR(xHigherPriorityWoken); } @@ -30,6 +35,10 @@ extern "C" portBASE_TYPE xHigherPriorityWoken = pdFALSE; uint8_t data = ThreadCommon::RotaryAction::Left; xQueueSendFromISR (*p_rotary_isr_q, &data, &xHigherPriorityWoken); + if(!xHigherPriorityWoken) + { + LOG_WARNING("[PIN_INT1_IRQn] portEND_SWITCHING_ISR called with False value"); + } portEND_SWITCHING_ISR(xHigherPriorityWoken); } @@ -40,16 +49,23 @@ extern "C" portBASE_TYPE xHigherPriorityWoken = pdFALSE; uint8_t data = ThreadCommon::RotaryAction::Press; xQueueSendFromISR (*p_rotary_isr_q, &data, &xHigherPriorityWoken); + if(!xHigherPriorityWoken) + { + LOG_WARNING("[PIN_INT2_IRQn] portEND_SWITCHING_ISR called with False value"); + } portEND_SWITCHING_ISR(xHigherPriorityWoken); } } Rotary::Rotary(ThreadCommon::QueueManager* qm) : _qm(qm) { - + LOG_DEBUG("Creating Rotary"); } -Rotary::~Rotary() {} +Rotary::~Rotary() +{ + LOG_ERROR("Deleting Rotary"); +} void Rotary::taskFunction() { diff --git a/source/shoh/src/threads/user_interface/UserInterface.cpp b/source/shoh/src/threads/user_interface/UserInterface.cpp index bafd5d4..a720cc0 100644 --- a/source/shoh/src/threads/user_interface/UserInterface.cpp +++ b/source/shoh/src/threads/user_interface/UserInterface.cpp @@ -5,16 +5,19 @@ */ #include "UserInterface.h" +#include "Log.h" #include UserInterface::UserInterface(ThreadCommon::QueueManager* qm) : _qm(qm), lcd1(nullptr) { + LOG_DEBUG("Creating UserInterface"); this->initLCD1(); } UserInterface::~UserInterface() { + LOG_ERROR("Deleting UserInterface"); delete this->lcd1; delete this->lcd1_rs; delete this->lcd1_en; @@ -45,7 +48,7 @@ void UserInterface::handleEvent(InterfaceWithData* ui_data) break; default: //Should never happen. - printf("WARNING: [UserInterface::handleEvent] executed default case.\n"); + LOG_ERROR("[UserInterface::handleEvent] executed default case"); break; } } @@ -59,11 +62,13 @@ void UserInterface::handleLCD(LiquidCrystal *lcd, const char *str) //Interpret empty string as clear. if(!strlen(str)) lcd->clear(); + LOG_INFO("Clear up LCD"); //Print the text otherwise. else { lcd->setCursor(0, 0); lcd->print(str); + LOG_INFO("Printing [%s] on LCD"); } } From 49f86131666eb287b677dd0ab320f29920721912 Mon Sep 17 00:00:00 2001 From: Vasily Davydov Date: Fri, 12 May 2023 00:58:33 +0300 Subject: [PATCH 05/13] main: add logging --- source/shoh/src/main.cpp | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-) diff --git a/source/shoh/src/main.cpp b/source/shoh/src/main.cpp index 740e2b4..d1dc3d6 100644 --- a/source/shoh/src/main.cpp +++ b/source/shoh/src/main.cpp @@ -10,19 +10,22 @@ #include "Rotary.h" #include "Manager.h" #include "UserInterface.h" +#include "Log.h" + int main(void) { + LOG_INFO("Starting system init"); SystemCoreClockUpdate(); Board_Init(); retarget_init(); - printf("Hello there!\r\n"); + LOG_INFO("System init done"); ThreadCommon::ThreadManager* manager = new ThreadCommon::ThreadManager; ThreadCommon::QueueManager* qmanager = new ThreadCommon::QueueManager; - //Creating queues + LOG_INFO("Creating queues"); qmanager->createQueue(100, sizeof(Event), ThreadCommon::QueueManager::master_event_all); @@ -33,7 +36,7 @@ int main(void) sizeof(UserInterface::InterfaceWithData), ThreadCommon::QueueManager::ui_event_manager); - //Creating tasks + LOG_INFO("Creating tasks"); manager->createTask(thread_master, "master", configMINIMAL_STACK_SIZE * 10,tskIDLE_PRIORITY + 1UL, static_cast(qmanager)); @@ -47,7 +50,7 @@ int main(void) configMINIMAL_STACK_SIZE * 10,tskIDLE_PRIORITY + 1UL, static_cast(qmanager)); - // Start the real time kernel with preemption. + LOG_INFO("Start the real time kernel with preemption"); vTaskStartScheduler (); return 1; From 970081991d4c8f3c5fa6a08766842fdbf16007a7 Mon Sep 17 00:00:00 2001 From: Vasily Davydov Date: Fri, 12 May 2023 01:12:26 +0300 Subject: [PATCH 06/13] peripherals: add logging --- source/shoh/src/peripherals/DigitalIoPin.cpp | 4 ++++ source/shoh/src/peripherals/EEPROMio.cpp | 4 ++++ 2 files changed, 8 insertions(+) diff --git a/source/shoh/src/peripherals/DigitalIoPin.cpp b/source/shoh/src/peripherals/DigitalIoPin.cpp index 1028d3c..0110997 100644 --- a/source/shoh/src/peripherals/DigitalIoPin.cpp +++ b/source/shoh/src/peripherals/DigitalIoPin.cpp @@ -6,6 +6,7 @@ */ #include "DigitalIoPin.h" +#include "Log.h" DigitalIoPin::DigitalIoPin (int port, int pin, bool input, bool pullup, bool invert, bool isr, IRQn_Type isr_index) @@ -39,6 +40,8 @@ DigitalIoPin::~DigitalIoPin () void DigitalIoPin::setIoPin () { + LOG_INFO("P%d_%d set as %s", _io._port, _io._port, + _io._input ? "input" : "output"); bool direction = true; if (_io._input) { @@ -62,6 +65,7 @@ DigitalIoPin::setIoPin () void DigitalIoPin::setIsr () { + LOG_INFO("P%d_%d set as ISR", _io._port, _io._port); bool direction = true; if (_io._input) { diff --git a/source/shoh/src/peripherals/EEPROMio.cpp b/source/shoh/src/peripherals/EEPROMio.cpp index 26135a0..2e149e3 100644 --- a/source/shoh/src/peripherals/EEPROMio.cpp +++ b/source/shoh/src/peripherals/EEPROMio.cpp @@ -6,6 +6,7 @@ */ #include +#include "Log.h" static void e_memcpy (void *from, void *to, unsigned int n) @@ -57,6 +58,7 @@ EEPROMio::write_to (uint32_t addr, std::string str) { std::copy (str.begin (), str.end (), std::begin (buffer)); eeprom_use (buffer, addr, str.length (), WRITE); + LOG_INFO("%dB written to EEPROM", str.length ()); } void * @@ -64,6 +66,7 @@ EEPROMio::read_from (uint32_t addr, uint32_t amount) { eeprom_use (buffer, addr, amount, READ); void *data = (void *)buffer; + LOG_INFO("%dB read from EEPROM", amount); return data; } void @@ -72,5 +75,6 @@ EEPROMio::write_to (uint32_t addr, void *data, uint32_t size_of_data) assert (size_of_data < EEPROM_MAX_BUFER_SIZE); e_memcpy (data, buffer, size_of_data); eeprom_use (buffer, addr, size_of_data, WRITE); + LOG_INFO("%dB written to EEPROM", size_of_data); } From 398030afe8a122f1fb23cf387e9cbaba9f0be1d7 Mon Sep 17 00:00:00 2001 From: Vasily Davydov Date: Fri, 12 May 2023 01:16:55 +0300 Subject: [PATCH 07/13] log: add a comment regarding mts --- source/shoh/src/threads/common/Log.h | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/source/shoh/src/threads/common/Log.h b/source/shoh/src/threads/common/Log.h index 6dfaf9d..fc4d1ab 100644 --- a/source/shoh/src/threads/common/Log.h +++ b/source/shoh/src/threads/common/Log.h @@ -6,6 +6,13 @@ #include #include +/* + This simlpe logging framework is dependant + on std lib's multithread support, thus + if needed on different platforms, please + wrap it with mutexes. +*/ + /* ================= Settings ================== */ #define LOG_COLORED_OUTPUT #define HIGH_PRIORITY_DEBUG From 2c3e1a8dc8003c3f30aa7b4678dfcd078b7994f7 Mon Sep 17 00:00:00 2001 From: Vasily Davydov Date: Fri, 12 May 2023 13:59:49 +0300 Subject: [PATCH 08/13] logging: don't ask... --- source/shoh/.cproject | 2 + source/shoh/src/main.cpp | 41 +++------------- .../shoh/src/threads/common/QueueManager.cpp | 3 -- source/shoh/src/threads/common/ThreadCommon.h | 10 +++- .../shoh/src/threads/common/ThreadManager.cpp | 9 +--- .../src/threads/{common => logging}/Log.h | 24 ++++----- source/shoh/src/threads/logging/Logging.cpp | 35 +++++++++++++ source/shoh/src/threads/logging/Logging.h | 27 ++++++++++ source/shoh/src/threads/manager/Manager.cpp | 3 +- source/shoh/src/threads/master/Master.cpp | 49 ++++++++++++++++++- source/shoh/src/threads/master/Master.h | 2 + source/shoh/src/threads/rotary/Rotary.cpp | 3 +- .../threads/user_interface/UserInterface.cpp | 7 +-- 13 files changed, 150 insertions(+), 65 deletions(-) rename source/shoh/src/threads/{common => logging}/Log.h (88%) create mode 100644 source/shoh/src/threads/logging/Logging.cpp create mode 100644 source/shoh/src/threads/logging/Logging.h diff --git a/source/shoh/.cproject b/source/shoh/.cproject index ff20bcd..b0b54ab 100644 --- a/source/shoh/.cproject +++ b/source/shoh/.cproject @@ -53,6 +53,7 @@ + @@ -257,6 +258,7 @@ + diff --git a/source/shoh/src/main.cpp b/source/shoh/src/main.cpp index 30bee65..8495385 100644 --- a/source/shoh/src/main.cpp +++ b/source/shoh/src/main.cpp @@ -17,11 +17,14 @@ int main(void) retarget_init(); - ThreadCommon::CommonManagers manager = {new ThreadCommon::ThreadManager, - new ThreadCommon::QueueManager}; - manager.tm->createTask(thread_master, "master", + ThreadCommon::ThreadManager *tm = new ThreadCommon::ThreadManager(); + ThreadCommon::QueueManager *qm = new ThreadCommon::QueueManager(); + ThreadCommon::CommonManagers *manager = new ThreadCommon::CommonManagers; + manager->tm = tm; + manager->qm = qm; + manager->tm->createTask(thread_master, "master", configMINIMAL_STACK_SIZE * 10,tskIDLE_PRIORITY + 1UL, - static_cast(&manager)); + static_cast(manager)); vTaskStartScheduler (); return 1; diff --git a/source/shoh/src/peripherals/retarget_uart.cpp b/source/shoh/src/peripherals/retarget_uart.cpp index f30510d..7396211 100644 --- a/source/shoh/src/peripherals/retarget_uart.cpp +++ b/source/shoh/src/peripherals/retarget_uart.cpp @@ -11,7 +11,7 @@ static LpcDebugUart *dbgu; void retarget_init() { - LpcPinMap none = {-1, -1}; // unused pin has negative values in it + //LpcPinMap none = {-1, -1}; // unused pin has negative values in it //Sadly, it seems that only USART0 is redirected to USB. //It means that those are pins PIO0_18 and PIO0_19 LpcPinMap txpin = { 0, 19 }; // transmit pin that goes to debugger's UART->USB converter diff --git a/source/shoh/src/threads/common/ThreadCommon.h b/source/shoh/src/threads/common/ThreadCommon.h index 7d6b85c..0aa05c0 100644 --- a/source/shoh/src/threads/common/ThreadCommon.h +++ b/source/shoh/src/threads/common/ThreadCommon.h @@ -77,15 +77,6 @@ namespace ThreadCommon ThreadManager * tm; QueueManager * qm; } CommonManagers; - - /* global variables */ - /* 'receiver'_'what'_'sender'_q */ - /* - extern QueueHandle_t master_event_all_q; - extern QueueHandle_t relay_event_master_q; - extern QueueHandle_t manager_event_master_q; - extern QueueHandle_t ui_event_manager_q; - */ } #endif /*__THREAD_COMMON_H_*/ diff --git a/source/shoh/src/threads/logging/Log.h b/source/shoh/src/threads/logging/Log.h index 65536b6..714eb62 100644 --- a/source/shoh/src/threads/logging/Log.h +++ b/source/shoh/src/threads/logging/Log.h @@ -37,7 +37,7 @@ extern QueueHandle_t logging_queue; #define C_ERROR "ERROR" #endif -#define LOG_BUFFER_MAX_CAP 500 +#define LOG_BUFFER_MAX_CAP 256 #define LOG_MESSAGE_MAX_CAP 150 #define _LOG_STREAMOUT(message, message_length) \ @@ -58,7 +58,7 @@ static void create_log_line(const char * _status, va_end(args); char buffer [LOG_BUFFER_MAX_CAP] = {0}; int buffer_len = snprintf(buffer, LOG_BUFFER_MAX_CAP, - "[%s] [File: %s] [Line: %ld] %.*s", + "[%s] [File: %s] [Line: %d] %.*s", _status, _location, _line, diff --git a/source/shoh/src/threads/logging/Logging.cpp b/source/shoh/src/threads/logging/Logging.cpp index ab1176c..731968e 100644 --- a/source/shoh/src/threads/logging/Logging.cpp +++ b/source/shoh/src/threads/logging/Logging.cpp @@ -20,11 +20,14 @@ Logging::~Logging() { void Logging::taskFunction() { - char data[LOG_BUFFER_MAX_CAP] = {0}; - xQueueReceive(q, static_cast(data), portMAX_DELAY); - mutex.lock(); - printf("%s\n", data); - mutex.unlock(); + for(;;) + { + char data[LOG_BUFFER_MAX_CAP] = {0}; + xQueueReceive(q, static_cast(data), portMAX_DELAY); + mutex.lock(); + printf("%s\n", data); + mutex.unlock(); + } } void thread_logging(void* pvParams) diff --git a/source/shoh/src/threads/master/Master.cpp b/source/shoh/src/threads/master/Master.cpp index ba16029..2e49314 100644 --- a/source/shoh/src/threads/master/Master.cpp +++ b/source/shoh/src/threads/master/Master.cpp @@ -86,7 +86,7 @@ void Master::taskFunction() { void thread_master(void* pvParams) { ThreadCommon::CommonManagers * manager = static_cast(pvParams); - manager->qm->createQueue(50, + manager->qm->createQueue(5, LOG_BUFFER_MAX_CAP, ThreadCommon::QueueManager::logging_message_all); logging_queue = manager->qm->getQueue(ThreadCommon::QueueManager::logging_message_all); @@ -111,9 +111,6 @@ void thread_master(void* pvParams) { LOG_INFO("Master is creating tasks"); - manager->tm->createTask(thread_master, "master", - configMINIMAL_STACK_SIZE * 10,tskIDLE_PRIORITY + 1UL, - static_cast(manager)); manager->tm->createTask(thread_manager, "manager", configMINIMAL_STACK_SIZE * 10,tskIDLE_PRIORITY + 1UL, static_cast(manager)); diff --git a/source/shoh/src/threads/user_interface/UserInterface.cpp b/source/shoh/src/threads/user_interface/UserInterface.cpp index 2668308..a58a6f7 100644 --- a/source/shoh/src/threads/user_interface/UserInterface.cpp +++ b/source/shoh/src/threads/user_interface/UserInterface.cpp @@ -68,7 +68,7 @@ void UserInterface::handleLCD(LiquidCrystal *lcd, const char *str) { lcd->setCursor(0, 0); lcd->print(str); - LOG_INFO("Printing [%s] on LCD"); + LOG_INFO("Printing [%s] on LCD", str); } } From d1d90a553a3289f9dd2434d5ad00813573e4b68a Mon Sep 17 00:00:00 2001 From: RedHawk Date: Fri, 12 May 2023 16:55:18 +0300 Subject: [PATCH 10/13] logging: LOG_DEBUG should print C_DEBUG. --- source/shoh/src/threads/logging/Log.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/source/shoh/src/threads/logging/Log.h b/source/shoh/src/threads/logging/Log.h index 714eb62..9c64851 100644 --- a/source/shoh/src/threads/logging/Log.h +++ b/source/shoh/src/threads/logging/Log.h @@ -79,7 +79,7 @@ static void create_log_line(const char * _status, #if LOG_DEBUG_MESSAGES #define LOG_DEBUG(fmt, ...) \ - create_log_line(C_INFO, __FILE__, __LINE__, fmt, ##__VA_ARGS__); + create_log_line(C_DEBUG, __FILE__, __LINE__, fmt, ##__VA_ARGS__); #else #define LOG_DEBUG(fmt, ...) #endif From e5bb200789103795c25c4371f99f42fd4d296bda Mon Sep 17 00:00:00 2001 From: RedHawk Date: Fri, 12 May 2023 17:08:01 +0300 Subject: [PATCH 11/13] logging: Better logging. Fixed pins printout. --- source/shoh/src/peripherals/DigitalIoPin.cpp | 4 ++-- source/shoh/src/threads/master/Master.cpp | 2 ++ source/shoh/src/threads/user_interface/UserInterface.cpp | 7 ++++--- 3 files changed, 8 insertions(+), 5 deletions(-) diff --git a/source/shoh/src/peripherals/DigitalIoPin.cpp b/source/shoh/src/peripherals/DigitalIoPin.cpp index 0110997..56f4d23 100644 --- a/source/shoh/src/peripherals/DigitalIoPin.cpp +++ b/source/shoh/src/peripherals/DigitalIoPin.cpp @@ -40,7 +40,7 @@ DigitalIoPin::~DigitalIoPin () void DigitalIoPin::setIoPin () { - LOG_INFO("P%d_%d set as %s", _io._port, _io._port, + LOG_DEBUG("P%d_%d set as %s", _io._port, _io._pin, _io._input ? "input" : "output"); bool direction = true; if (_io._input) @@ -65,7 +65,7 @@ DigitalIoPin::setIoPin () void DigitalIoPin::setIsr () { - LOG_INFO("P%d_%d set as ISR", _io._port, _io._port); + LOG_DEBUG("P%d_%d set as ISR", _io._port, _io._pin); bool direction = true; if (_io._input) { diff --git a/source/shoh/src/threads/master/Master.cpp b/source/shoh/src/threads/master/Master.cpp index 2e49314..dbc1774 100644 --- a/source/shoh/src/threads/master/Master.cpp +++ b/source/shoh/src/threads/master/Master.cpp @@ -108,6 +108,7 @@ void thread_master(void* pvParams) { manager->qm->createQueue(20, sizeof(UserInterface::InterfaceWithData), ThreadCommon::QueueManager::ui_event_manager); + LOG_INFO("Master created queues"); LOG_INFO("Master is creating tasks"); @@ -120,5 +121,6 @@ void thread_master(void* pvParams) { manager->tm->createTask(thread_user_interface, "user_interface", configMINIMAL_STACK_SIZE * 10,tskIDLE_PRIORITY + 1UL, static_cast(manager)); + LOG_INFO("Master created tasks"); m.taskFunction(); } diff --git a/source/shoh/src/threads/user_interface/UserInterface.cpp b/source/shoh/src/threads/user_interface/UserInterface.cpp index a58a6f7..4ea61c0 100644 --- a/source/shoh/src/threads/user_interface/UserInterface.cpp +++ b/source/shoh/src/threads/user_interface/UserInterface.cpp @@ -62,13 +62,14 @@ void UserInterface::handleLCD(LiquidCrystal *lcd, const char *str) //Interpret empty string as clear. if(!strlen(str)){ lcd->clear(); - LOG_INFO("Clear up LCD"); + LOG_DEBUG("Clear up LCD"); //Print the text otherwise. - }else + } + else { lcd->setCursor(0, 0); lcd->print(str); - LOG_INFO("Printing [%s] on LCD", str); + LOG_DEBUG("Printing [%s] on LCD", str); } } From 3012ee1b204fdfa940a6a60ab5af3887e0182920 Mon Sep 17 00:00:00 2001 From: RedHawk Date: Fri, 12 May 2023 17:08:01 +0300 Subject: [PATCH 12/13] logging: Better logging. Fixed pins printout. --- source/shoh/src/peripherals/EEPROMio.cpp | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/source/shoh/src/peripherals/EEPROMio.cpp b/source/shoh/src/peripherals/EEPROMio.cpp index 2e149e3..649809d 100644 --- a/source/shoh/src/peripherals/EEPROMio.cpp +++ b/source/shoh/src/peripherals/EEPROMio.cpp @@ -58,7 +58,7 @@ EEPROMio::write_to (uint32_t addr, std::string str) { std::copy (str.begin (), str.end (), std::begin (buffer)); eeprom_use (buffer, addr, str.length (), WRITE); - LOG_INFO("%dB written to EEPROM", str.length ()); + LOG_DEBUG("%dB written to EEPROM", str.length ()); } void * @@ -66,7 +66,7 @@ EEPROMio::read_from (uint32_t addr, uint32_t amount) { eeprom_use (buffer, addr, amount, READ); void *data = (void *)buffer; - LOG_INFO("%dB read from EEPROM", amount); + LOG_DEBUG("%dB read from EEPROM", amount); return data; } void @@ -75,6 +75,6 @@ EEPROMio::write_to (uint32_t addr, void *data, uint32_t size_of_data) assert (size_of_data < EEPROM_MAX_BUFER_SIZE); e_memcpy (data, buffer, size_of_data); eeprom_use (buffer, addr, size_of_data, WRITE); - LOG_INFO("%dB written to EEPROM", size_of_data); + LOG_DEBUG("%dB written to EEPROM", size_of_data); } From feb2a3d08dd152fe7d5be319b6a08d068228ecaa Mon Sep 17 00:00:00 2001 From: RedHawk Date: Fri, 12 May 2023 17:23:27 +0300 Subject: [PATCH 13/13] FreeRTOS: Task monitoring. --- source/shoh/freertos/FreeRTOSConfig.h | 13 ++++++++++++- source/shoh/src/main.cpp | 13 +++++++++++++ 2 files changed, 25 insertions(+), 1 deletion(-) diff --git a/source/shoh/freertos/FreeRTOSConfig.h b/source/shoh/freertos/FreeRTOSConfig.h index ec2abf9..da1e190 100644 --- a/source/shoh/freertos/FreeRTOSConfig.h +++ b/source/shoh/freertos/FreeRTOSConfig.h @@ -91,7 +91,8 @@ #define configUSE_MALLOC_FAILED_HOOK 1 #define configUSE_APPLICATION_TASK_TAG 0 #define configUSE_COUNTING_SEMAPHORES 1 -#define configGENERATE_RUN_TIME_STATS 0 +#define configGENERATE_RUN_TIME_STATS 1 +#define configRECORD_STACK_HIGH_ADDRESS 1 #define configUSE_TICKLESS_IDLE 1 @@ -119,6 +120,16 @@ to exclude the API function. */ #define INCLUDE_vTaskDelay 1 #define INCLUDE_xTaskGetCurrentTaskHandle 1 +/* NOTE: we need to provide implementation of vConfigureTimerForRunTimeStats() + * It is called to set up high resolution timer that is needed for accurate runtime + * measurement. I assume that we use LPC_SCT1 in unified mode so this function + * must set up LPC_SCT1. + */ +void vConfigureTimerForRunTimeStats(void); +#define portCONFIGURE_TIMER_FOR_RUN_TIME_STATS() vConfigureTimerForRunTimeStats() +/* The value is read directly from the counter register for efficiency and low overhead. */ +#define portGET_RUN_TIME_COUNTER_VALUE() LPC_SCT1->COUNT_U + /* Cortex-M specific definitions. */ #ifdef __NVIC_PRIO_BITS /* __BVIC_PRIO_BITS will be specified when CMSIS is being used. */ diff --git a/source/shoh/src/main.cpp b/source/shoh/src/main.cpp index 8495385..f054cb4 100644 --- a/source/shoh/src/main.cpp +++ b/source/shoh/src/main.cpp @@ -29,3 +29,16 @@ int main(void) return 1; } + +extern "C" +{ + void + vConfigureTimerForRunTimeStats (void) + { + Chip_SCT_Init (LPC_SCT1); + LPC_SCT1->CONFIG = SCT_CONFIG_32BIT_COUNTER; + LPC_SCT1->CTRL_U = SCT_CTRL_PRE_L (255) + | SCT_CTRL_CLRCTR_L; // set prescaler to 256 (255 + + // 1), and start timer + } +}