Hendrik/esphome-truma_inetbox
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

fiddle with logging

Browse Source
This commit is contained in:
Your Name 2023-03-22 22:17:12 +01:00
parent a97f8ad31d
commit a9115c0d9a
5 changed files with 133 additions and 70 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
.github/workflows/main.yml vendored
View File

@ -34,6 +34,10 @@ jobs:
file: tests/test.esp32_ard.uart.yaml
name: Test tests/test.esp32_ard.uart.yaml
pio_cache_key: test.esp32_ard.uart
- id: test
file: tests/test.esp32_ard.vv_log.yaml
name: Test tests/test.esp32_ard.vv_log.yaml
pio_cache_key: test.esp32_ard.vv_log
- id: test
file: tests/test.esp32_ard.yaml
name: Test tests/test.esp32_ard.yaml

53
components/truma_inetbox/LinBusListener.cpp
View File

@ -54,18 +54,20 @@ void LinBusListener::setup() {
this->fault_pin_->setup();
}
assert(this->log_queue_ != 0);
// call device specific function
this->setup_framework();
#if ESPHOME_LOG_LEVEL > ESPHOME_LOG_LEVEL_NONE
assert(this->log_queue_ != 0);
// Register interval to submit log messages
this->set_interval("logmsg", 50, [this]() { this->process_log_queue(QUEUE_WAIT_DONT_BLOCK); });
#endif // ESPHOME_LOG_LEVEL > ESPHOME_LOG_LEVEL_NONE
if (this->cs_pin_ != nullptr) {
// Enable LIN driver if not in oberserver mode.
this->cs_pin_->digital_write(!this->observer_mode_);
}
// Register interval to submit log messages
this->set_interval("logmsg", 50, [this]() { this->process_log_queue(QUEUE_WAIT_DONT_BLOCK); });
}
void LinBusListener::update() { this->check_for_lin_fault_(); }
@ -74,13 +76,13 @@ void LinBusListener::write_lin_answer_(const u_int8_t *data, u_int8_t len) {
QUEUE_LOG_MSG log_msg = QUEUE_LOG_MSG();
if (!this->can_write_lin_answer_) {
log_msg.type = QUEUE_LOG_MSG_TYPE::ERROR_LIN_ANSWER_CAN_WRITE_LIN_ANSWER;
xQueueSend(this->log_queue_, (void *) &log_msg, QUEUE_WAIT_DONT_BLOCK);
TRUMA_LOGE(log_msg);
return;
}
this->can_write_lin_answer_ = false;
if (len > 8) {
log_msg.type = QUEUE_LOG_MSG_TYPE::ERROR_LIN_ANSWER_TOO_LONG;
xQueueSend(this->log_queue_, (void *) &log_msg, QUEUE_WAIT_DONT_BLOCK);
TRUMA_LOGE(log_msg);
return;
}
@ -105,7 +107,6 @@ void LinBusListener::write_lin_answer_(const u_int8_t *data, u_int8_t len) {
this->write(data_CRC);
}
#ifdef ESPHOME_LOG_HAS_VERBOSE
log_msg.type = QUEUE_LOG_MSG_TYPE::VERBOSE_LIN_ANSWER_RESPONSE;
log_msg.current_PID = this->current_PID_;
for (u_int8_t i = 0; i < len; i++) {
@ -113,8 +114,7 @@ void LinBusListener::write_lin_answer_(const u_int8_t *data, u_int8_t len) {
}
log_msg.data[len] = data_CRC;
log_msg.len = len++;
xQueueSend(this->log_queue_, (void *) &log_msg, QUEUE_WAIT_DONT_BLOCK);
#endif // ESPHOME_LOG_HAS_VERBOSE
TRUMA_LOGV(log_msg);
}
bool LinBusListener::check_for_lin_fault_() {
@ -130,13 +130,13 @@ bool LinBusListener::check_for_lin_fault_() {
if (this->fault_on_lin_bus_reported_ % 3 == 0) {
QUEUE_LOG_MSG log_msg = QUEUE_LOG_MSG();
log_msg.type = QUEUE_LOG_MSG_TYPE::ERROR_CHECK_FOR_LIN_FAULT_DETECTED;
xQueueSend(this->log_queue_, (void *) &log_msg, QUEUE_WAIT_DONT_BLOCK);
TRUMA_LOGE(log_msg);
}
} else if (this->get_lin_bus_fault()) {
this->fault_on_lin_bus_reported_ = 0;
QUEUE_LOG_MSG log_msg = QUEUE_LOG_MSG();
log_msg.type = QUEUE_LOG_MSG_TYPE::INFO_CHECK_FOR_LIN_FAULT_FIXED;
xQueueSend(this->log_queue_, (void *) &log_msg, QUEUE_WAIT_DONT_BLOCK);
TRUMA_LOGI(log_msg);
} else {
this->fault_on_lin_bus_reported_ = 0;
}
@ -180,7 +180,7 @@ void LinBusListener::read_lin_frame_() {
}
log_msg.len = this->current_data_count_;
}
xQueueSendFromISR(this->log_queue_, (void *) &log_msg, QUEUE_WAIT_DONT_BLOCK);
TRUMA_LOGE_ISR(log_msg);
}
}
@ -189,11 +189,9 @@ void LinBusListener::read_lin_frame_() {
// First is Break expected
if (!this->read_byte(&buf) || buf != LIN_BREAK) {
#ifdef ESPHOME_LOG_HAS_VERY_VERBOSE
log_msg.type = QUEUE_LOG_MSG_TYPE::VV_READ_LIN_FRAME_BREAK_EXPECTED;
log_msg.current_PID = buf;
xQueueSendFromISR(this->log_queue_, (void *) &log_msg, QUEUE_WAIT_DONT_BLOCK);
#endif // ESPHOME_LOG_HAS_VERY_VERBOSE
TRUMA_LOGVV_ISR(log_msg);
} else {
// ESP_LOGVV(TAG, "%02X BREAK received.", buf);
this->current_state_ = READ_STATE_SYNC;
@ -202,11 +200,9 @@ void LinBusListener::read_lin_frame_() {
case READ_STATE_SYNC:
// Second is Sync expected
if (!this->read_byte(&buf) || buf != LIN_SYNC) {
#ifdef ESPHOME_LOG_HAS_VERY_VERBOSE
log_msg.type = QUEUE_LOG_MSG_TYPE::VV_READ_LIN_FRAME_SYNC_EXPECTED;
log_msg.current_PID = buf;
xQueueSendFromISR(this->log_queue_, (void *) &log_msg, QUEUE_WAIT_DONT_BLOCK);
#endif // ESPHOME_LOG_HAS_VERY_VERBOSE
TRUMA_LOGVV_ISR(log_msg);
this->current_state_ = buf == LIN_BREAK ? READ_STATE_SYNC : READ_STATE_BREAK;
} else {
// ESP_LOGVV(TAG, "%02X SYNC found.", buf);
@ -220,7 +216,7 @@ void LinBusListener::read_lin_frame_() {
if (this->current_PID_with_parity_ != (this->current_PID_ | (addr_parity(this->current_PID_) << 6))) {
log_msg.type = QUEUE_LOG_MSG_TYPE::WARN_READ_LIN_FRAME_SID_CRC;
log_msg.current_PID = this->current_PID_with_parity_;
xQueueSendFromISR(this->log_queue_, (void *) &log_msg, QUEUE_WAIT_DONT_BLOCK);
TRUMA_LOGW_ISR(log_msg);
this->current_data_valid = false;
}
}
@ -267,7 +263,7 @@ void LinBusListener::read_lin_frame_() {
(this->current_PID_ == DIAGNOSTIC_FRAME_MASTER || this->current_PID_ == DIAGNOSTIC_FRAME_SLAVE)) {
if (data_CRC != data_checksum(this->current_data_, data_length, 0)) {
log_msg.type = QUEUE_LOG_MSG_TYPE::WARN_READ_LIN_FRAME_LINv1_CRC;
xQueueSendFromISR(this->log_queue_, (void *) &log_msg, QUEUE_WAIT_DONT_BLOCK);
TRUMA_LOGW_ISR(log_msg);
this->current_data_valid = false;
}
if (this->current_PID_ == DIAGNOSTIC_FRAME_MASTER) {
@ -282,7 +278,7 @@ void LinBusListener::read_lin_frame_() {
u_int8_t data_CRC_slave = data_checksum(this->current_data_, data_length, this->current_PID_with_parity_);
if (data_CRC != data_CRC_master && data_CRC != data_CRC_slave) {
log_msg.type = QUEUE_LOG_MSG_TYPE::WARN_READ_LIN_FRAME_LINv2_CRC;
xQueueSendFromISR(this->log_queue_, (void *) &log_msg, QUEUE_WAIT_DONT_BLOCK);
TRUMA_LOGW_ISR(log_msg);
this->current_data_valid = false;
}
message_source_know = true;
@ -301,7 +297,7 @@ void LinBusListener::read_lin_frame_() {
log_msg.current_data_valid = this->current_data_valid;
log_msg.message_source_know = message_source_know;
log_msg.message_from_master = message_from_master;
xQueueSendFromISR(this->log_queue_, (void *) &log_msg, QUEUE_WAIT_DONT_BLOCK);
TRUMA_LOGV_ISR(log_msg);
#endif // ESPHOME_LOG_HAS_VERBOSE
if (this->current_data_valid && message_from_master) {
@ -331,6 +327,7 @@ void LinBusListener::process_lin_msg_queue(TickType_t xTicksToWait) {
}
void LinBusListener::process_log_queue(TickType_t xTicksToWait) {
#if ESPHOME_LOG_LEVEL > ESPHOME_LOG_LEVEL_NONE
QUEUE_LOG_MSG log_msg;
while (xQueueReceive(this->log_queue_, &log_msg, xTicksToWait) == pdPASS) {
auto current_PID = log_msg.current_PID;
@ -341,7 +338,6 @@ void LinBusListener::process_log_queue(TickType_t xTicksToWait) {
case QUEUE_LOG_MSG_TYPE::ERROR_LIN_ANSWER_TOO_LONG:
ESP_LOGE(TAG, "LIN answer cannot be longer than 8 bytes.");
break;
#ifdef ESPHOME_LOG_HAS_VERBOSE
case QUEUE_LOG_MSG_TYPE::VERBOSE_LIN_ANSWER_RESPONSE:
if (!this->observer_mode_) {
ESP_LOGV(TAG, "RESPONSE %02X %s", current_PID, format_hex_pretty(log_msg.data, log_msg.len).c_str());
@ -350,19 +346,15 @@ void LinBusListener::process_log_queue(TickType_t xTicksToWait) {
format_hex_pretty(log_msg.data, log_msg.len).c_str());
}
break;
#endif // ESPHOME_LOG_HAS_VERBOSE
case QUEUE_LOG_MSG_TYPE::ERROR_CHECK_FOR_LIN_FAULT_DETECTED:
ESP_LOGE(TAG, "Fault on LIN BUS detected.");
break;
case QUEUE_LOG_MSG_TYPE::INFO_CHECK_FOR_LIN_FAULT_FIXED:
ESP_LOGI(TAG, "Fault on LIN BUS fixed.");
break;
case QUEUE_LOG_MSG_TYPE::ERROR_READ_LIN_FRAME_UNABLE_TO_ANSWER:
ESP_LOGE(TAG, "PID %02X order - unable to send response", current_PID);
break;
case QUEUE_LOG_MSG_TYPE::ERROR_READ_LIN_FRAME_LOST_MSG:
if (log_msg.len == 0) {
ESP_LOGV(TAG, "PID %02X order no answer", current_PID);
@ -371,14 +363,12 @@ void LinBusListener::process_log_queue(TickType_t xTicksToWait) {
format_hex_pretty(log_msg.data, log_msg.len).c_str());
}
break;
#ifdef ESPHOME_LOG_HAS_VERY_VERBOSE
case QUEUE_LOG_MSG_TYPE::VV_READ_LIN_FRAME_BREAK_EXPECTED:
ESP_LOGVV(TAG, "0x%02X Expected BREAK not received.", current_PID);
break;
case QUEUE_LOG_MSG_TYPE::VV_READ_LIN_FRAME_SYNC_EXPECTED:
ESP_LOGVV(TAG, "0x%02X Expected SYNC not found.", current_PID);
break;
#endif // ESPHOME_LOG_HAS_VERY_VERBOSE
case QUEUE_LOG_MSG_TYPE::WARN_READ_LIN_FRAME_SID_CRC:
ESP_LOGW(TAG, "0x%02X LIN CRC error on SID.", current_PID);
break;
@ -388,7 +378,6 @@ void LinBusListener::process_log_queue(TickType_t xTicksToWait) {
case QUEUE_LOG_MSG_TYPE::WARN_READ_LIN_FRAME_LINv2_CRC:
ESP_LOGW(TAG, "LIN v2 CRC error");
break;
#ifdef ESPHOME_LOG_HAS_VERBOSE
case QUEUE_LOG_MSG_TYPE::VERBOSE_READ_LIN_FRAME_MSG:
// Mark the PID of the TRUMA Combi heater as very verbose message.
if (current_PID == 0x20 || current_PID == 0x21 || current_PID == 0x22 ||
@ -403,11 +392,11 @@ void LinBusListener::process_log_queue(TickType_t xTicksToWait) {
log_msg.current_data_valid ? "" : "INVALID");
}
break;
#endif // ESPHOME_LOG_HAS_VERBOSE
default:
break;
}
}
#endif // ESPHOME_LOG_LEVEL > ESPHOME_LOG_LEVEL_NONE
}
#undef LIN_BREAK

41
components/truma_inetbox/LinBusListener.h
View File

@ -1,5 +1,6 @@
#pragma once
#include "LinBusLog.h"
#include "esphome/core/component.h"
#include "esphome/components/uart/uart.h"
@ -25,44 +26,6 @@ struct QUEUE_LIN_MSG {
u_int8_t len;
};
enum class QUEUE_LOG_MSG_TYPE {
UNKNOWN,
ERROR_LIN_ANSWER_CAN_WRITE_LIN_ANSWER,
ERROR_LIN_ANSWER_TOO_LONG,
#ifdef ESPHOME_LOG_HAS_VERBOSE
VERBOSE_LIN_ANSWER_RESPONSE,
#endif // ESPHOME_LOG_HAS_VERBOSE
ERROR_CHECK_FOR_LIN_FAULT_DETECTED,
INFO_CHECK_FOR_LIN_FAULT_FIXED,
ERROR_READ_LIN_FRAME_UNABLE_TO_ANSWER,
ERROR_READ_LIN_FRAME_LOST_MSG,
#ifdef ESPHOME_LOG_HAS_VERY_VERBOSE
VV_READ_LIN_FRAME_BREAK_EXPECTED,
VV_READ_LIN_FRAME_SYNC_EXPECTED,
#endif // ESPHOME_LOG_HAS_VERY_VERBOSE
WARN_READ_LIN_FRAME_SID_CRC,
WARN_READ_LIN_FRAME_LINv1_CRC,
WARN_READ_LIN_FRAME_LINv2_CRC,
#ifdef ESPHOME_LOG_HAS_VERBOSE
VERBOSE_READ_LIN_FRAME_MSG,
#endif // ESPHOME_LOG_HAS_VERBOSE
};
// Log messages generated during interrupt are pushed to log queue.
struct QUEUE_LOG_MSG {
QUEUE_LOG_MSG_TYPE type;
u_int8_t current_PID;
u_int8_t data[9];
u_int8_t len;
#ifdef ESPHOME_LOG_HAS_VERBOSE
bool current_data_valid;
bool message_source_know;
bool message_from_master;
#endif // ESPHOME_LOG_HAS_VERBOSE
};
class LinBusListener : public PollingComponent, public uart::UARTDevice {
public:
float get_setup_priority() const override { return setup_priority::DATA; }
@ -153,12 +116,14 @@ class LinBusListener : public PollingComponent, public uart::UARTDevice {
/* uxItemSize */ sizeof(QUEUE_LIN_MSG),
/* pucQueueStorageBuffer */ lin_msg_static_queue_storage, &lin_msg_static_queue_);
#if ESPHOME_LOG_LEVEL > ESPHOME_LOG_LEVEL_NONE
uint8_t log_static_queue_storage[6 * sizeof(QUEUE_LOG_MSG)];
StaticQueue_t log_static_queue_;
QueueHandle_t log_queue_ =
xQueueCreateStatic(/* uxQueueLength */ 6,
/* uxItemSize */ sizeof(QUEUE_LOG_MSG),
/* pucQueueStorageBuffer */ log_static_queue_storage, &log_static_queue_);
#endif
#ifdef USE_ESP32
TaskHandle_t eventTaskHandle_;

77
components/truma_inetbox/LinBusLog.h Normal file
View File

@ -0,0 +1,77 @@
#pragma once
#include "esphome/core/log.h"
#define truma_log(_log_msg_) xQueueSend(this->log_queue_, (void *) &_log_msg_, QUEUE_WAIT_DONT_BLOCK);
#define truma_logfromisr(_log_msg_) xQueueSendFromISR(this->log_queue_, (void *) &_log_msg_, QUEUE_WAIT_DONT_BLOCK);
#if ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_VERY_VERBOSE
#define TRUMA_LOGVV(_log_msg_) truma_log(_log_msg_)
#define TRUMA_LOGVV_ISR(_log_msg_) truma_logfromisr(_log_msg_)
#else
#define TRUMA_LOGVV(_log_msg_)
#define TRUMA_LOGVV_ISR(_log_msg_)
#endif
#if ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_VERBOSE
#define TRUMA_LOGV(_log_msg_) truma_log(_log_msg_)
#define TRUMA_LOGV_ISR(_log_msg_) truma_logfromisr(_log_msg_)
#else
#define TRUMA_LOGV(_log_msg_)
#define TRUMA_LOGV_ISR(_log_msg_)
#endif
#if ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_INFO
#define TRUMA_LOGI(_log_msg_) truma_log(_log_msg_)
#define TRUMA_LOGI_ISR(_log_msg_) truma_logfromisr(_log_msg_)
#else
#define TRUMA_LOGI(_log_msg_)
#define TRUMA_LOGI_ISR(_log_msg_)
#endif
#if ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_WARN
#define TRUMA_LOGW(_log_msg_) truma_log(_log_msg_)
#define TRUMA_LOGW_ISR(_log_msg_) truma_logfromisr(_log_msg_)
#else
#define TRUMA_LOGW(_log_msg_)
#define TRUMA_LOGW_ISR(_log_msg_)
#endif
#if ESPHOME_LOG_LEVEL >= ESPHOME_LOG_LEVEL_ERROR
#define TRUMA_LOGE(_log_msg_) truma_log(_log_msg_)
#define TRUMA_LOGE_ISR(_log_msg_) truma_logfromisr(_log_msg_)
#else
#define TRUMA_LOGE(_log_msg_)
#define TRUMA_LOGE_ISR(_log_msg_)
#endif
enum class QUEUE_LOG_MSG_TYPE {
UNKNOWN,
ERROR_LIN_ANSWER_CAN_WRITE_LIN_ANSWER,
ERROR_LIN_ANSWER_TOO_LONG,
VERBOSE_LIN_ANSWER_RESPONSE,
ERROR_CHECK_FOR_LIN_FAULT_DETECTED,
INFO_CHECK_FOR_LIN_FAULT_FIXED,
ERROR_READ_LIN_FRAME_UNABLE_TO_ANSWER,
ERROR_READ_LIN_FRAME_LOST_MSG,
VV_READ_LIN_FRAME_BREAK_EXPECTED,
VV_READ_LIN_FRAME_SYNC_EXPECTED,
WARN_READ_LIN_FRAME_SID_CRC,
WARN_READ_LIN_FRAME_LINv1_CRC,
WARN_READ_LIN_FRAME_LINv2_CRC,
VERBOSE_READ_LIN_FRAME_MSG,
};
// Log messages generated during interrupt are pushed to log queue.
struct QUEUE_LOG_MSG {
QUEUE_LOG_MSG_TYPE type;
u_int8_t current_PID;
u_int8_t data[9];
u_int8_t len;
#ifdef ESPHOME_LOG_HAS_VERBOSE
bool current_data_valid;
bool message_source_know;
bool message_from_master;
#endif // ESPHOME_LOG_HAS_VERBOSE
};

28
tests/test.esp32_ard.vv_log.yaml Normal file
View File

@ -0,0 +1,28 @@
esphome:
name: "esp32-ard-vv-log"
external_components:
- source:
type: local
path: ../components
components: ["truma_inetbox", "uart"]
esp32:
board: esp32dev
framework:
type: arduino
logger:
level: VERY_VERBOSE
uart: !include test.common.uart.yaml
truma_inetbox:
uart_id: lin_uart_bus
cs_pin: 5
fault_pin: 18
binary_sensor: !include test.common.binary_sensor.yaml
button: !include test.common.button.yaml
climate: !include test.common.climate.yaml
number: !include test.common.number.yaml
sensor: !include test.common.sensor.yaml
switch: !include test.common.switch.yaml