Improve DSMR read timeout handling (#2699)

This commit is contained in:
Maurice Makaay 2021-11-29 16:40:53 +01:00 committed by GitHub
parent cae283dc86
commit adf48246a9
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
6 changed files with 136 additions and 100 deletions

View file

@ -5,6 +5,7 @@ from esphome.components import uart
from esphome.const import ( from esphome.const import (
CONF_ID, CONF_ID,
CONF_UART_ID, CONF_UART_ID,
CONF_RECEIVE_TIMEOUT,
) )
CODEOWNERS = ["@glmnet", "@zuidwijk"] CODEOWNERS = ["@glmnet", "@zuidwijk"]
@ -52,7 +53,12 @@ CONFIG_SCHEMA = cv.All(
cv.Optional(CONF_GAS_MBUS_ID, default=1): cv.int_, cv.Optional(CONF_GAS_MBUS_ID, default=1): cv.int_,
cv.Optional(CONF_MAX_TELEGRAM_LENGTH, default=1500): cv.int_, cv.Optional(CONF_MAX_TELEGRAM_LENGTH, default=1500): cv.int_,
cv.Optional(CONF_REQUEST_PIN): pins.gpio_output_pin_schema, cv.Optional(CONF_REQUEST_PIN): pins.gpio_output_pin_schema,
cv.Optional(CONF_REQUEST_INTERVAL): cv.positive_time_period_milliseconds, cv.Optional(
CONF_REQUEST_INTERVAL, default="0ms"
): cv.positive_time_period_milliseconds,
cv.Optional(
CONF_RECEIVE_TIMEOUT, default="200ms"
): cv.positive_time_period_milliseconds,
} }
).extend(uart.UART_DEVICE_SCHEMA), ).extend(uart.UART_DEVICE_SCHEMA),
cv.only_with_arduino, cv.only_with_arduino,
@ -70,10 +76,8 @@ async def to_code(config):
if CONF_REQUEST_PIN in config: if CONF_REQUEST_PIN in config:
request_pin = await cg.gpio_pin_expression(config[CONF_REQUEST_PIN]) request_pin = await cg.gpio_pin_expression(config[CONF_REQUEST_PIN])
cg.add(var.set_request_pin(request_pin)) cg.add(var.set_request_pin(request_pin))
if CONF_REQUEST_INTERVAL in config: cg.add(var.set_request_interval(config[CONF_REQUEST_INTERVAL].total_milliseconds))
cg.add( cg.add(var.set_receive_timeout(config[CONF_RECEIVE_TIMEOUT].total_milliseconds))
var.set_request_interval(config[CONF_REQUEST_INTERVAL].total_milliseconds)
)
cg.add_define("DSMR_GAS_MBUS_ID", config[CONF_GAS_MBUS_ID]) cg.add_define("DSMR_GAS_MBUS_ID", config[CONF_GAS_MBUS_ID])

View file

@ -24,7 +24,7 @@ void Dsmr::loop() {
if (this->decryption_key_.empty()) { if (this->decryption_key_.empty()) {
this->receive_telegram_(); this->receive_telegram_();
} else { } else {
this->receive_encrypted_(); this->receive_encrypted_telegram_();
} }
} }
} }
@ -57,14 +57,42 @@ bool Dsmr::request_interval_reached_() {
return millis() - this->last_request_time_ > this->request_interval_; return millis() - this->last_request_time_ > this->request_interval_;
} }
bool Dsmr::receive_timeout_reached_() { return millis() - this->last_read_time_ > this->receive_timeout_; }
bool Dsmr::available_within_timeout_() { bool Dsmr::available_within_timeout_() {
uint8_t tries = READ_TIMEOUT_MS / 5; // Data are available for reading on the UART bus?
while (tries--) { // Then we can start reading right away.
if (this->available()) {
this->last_read_time_ = millis();
return true;
}
// When we're not in the process of reading a telegram, then there is
// no need to actively wait for new data to come in.
if (!header_found_) {
return false;
}
// A telegram is being read. The smart meter might not deliver a telegram
// in one go, but instead send it in chunks with small pauses in between.
// When the UART RX buffer cannot hold a full telegram, then make sure
// that the UART read buffer does not overflow while other components
// perform their work in their loop. Do this by not returning control to
// the main loop, until the read timeout is reached.
if (this->parent_->get_rx_buffer_size() < this->max_telegram_len_) {
while (!this->receive_timeout_reached_()) {
delay(5); delay(5);
if (this->available()) { if (this->available()) {
this->last_read_time_ = millis();
return true; return true;
} }
} }
}
// No new data has come in during the read timeout? Then stop reading the
// telegram and start waiting for the next one to arrive.
if (this->receive_timeout_reached_()) {
ESP_LOGW(TAG, "Timeout while reading data for telegram");
this->reset_telegram_();
}
return false; return false;
} }
@ -96,30 +124,31 @@ void Dsmr::stop_requesting_data_() {
} }
} }
void Dsmr::receive_telegram_() { void Dsmr::reset_telegram_() {
while (true) { this->header_found_ = false;
if (!this->available()) { this->footer_found_ = false;
if (!this->header_found_ || !this->available_within_timeout_()) { this->bytes_read_ = 0;
return; this->crypt_bytes_read_ = 0;
} this->crypt_telegram_len_ = 0;
} this->last_read_time_ = 0;
}
void Dsmr::receive_telegram_() {
while (this->available_within_timeout_()) {
const char c = this->read(); const char c = this->read();
// Find a new telegram header, i.e. forward slash. // Find a new telegram header, i.e. forward slash.
if (c == '/') { if (c == '/') {
ESP_LOGV(TAG, "Header of telegram found"); ESP_LOGV(TAG, "Header of telegram found");
this->reset_telegram_();
this->header_found_ = true; this->header_found_ = true;
this->footer_found_ = false;
this->telegram_len_ = 0;
} }
if (!this->header_found_) if (!this->header_found_)
continue; continue;
// Check for buffer overflow. // Check for buffer overflow.
if (this->telegram_len_ >= this->max_telegram_len_) { if (this->bytes_read_ >= this->max_telegram_len_) {
this->header_found_ = false; this->reset_telegram_();
this->footer_found_ = false;
ESP_LOGE(TAG, "Error: telegram larger than buffer (%d bytes)", this->max_telegram_len_); ESP_LOGE(TAG, "Error: telegram larger than buffer (%d bytes)", this->max_telegram_len_);
return; return;
} }
@ -129,9 +158,9 @@ void Dsmr::receive_telegram_() {
// proper parsing, remove these new line characters. // proper parsing, remove these new line characters.
if (c == '(') { if (c == '(') {
while (true) { while (true) {
auto previous_char = this->telegram_[this->telegram_len_ - 1]; auto previous_char = this->telegram_[this->bytes_read_ - 1];
if (previous_char == '\n' || previous_char == '\r') { if (previous_char == '\n' || previous_char == '\r') {
this->telegram_len_--; this->bytes_read_--;
} else { } else {
break; break;
} }
@ -139,8 +168,8 @@ void Dsmr::receive_telegram_() {
} }
// Store the byte in the buffer. // Store the byte in the buffer.
this->telegram_[this->telegram_len_] = c; this->telegram_[this->bytes_read_] = c;
this->telegram_len_++; this->bytes_read_++;
// Check for a footer, i.e. exlamation mark, followed by a hex checksum. // Check for a footer, i.e. exlamation mark, followed by a hex checksum.
if (c == '!') { if (c == '!') {
@ -152,28 +181,14 @@ void Dsmr::receive_telegram_() {
if (this->footer_found_ && c == '\n') { if (this->footer_found_ && c == '\n') {
// Parse the telegram and publish sensor values. // Parse the telegram and publish sensor values.
this->parse_telegram(); this->parse_telegram();
this->reset_telegram_();
this->header_found_ = false;
return; return;
} }
} }
} }
void Dsmr::receive_encrypted_() { void Dsmr::receive_encrypted_telegram_() {
this->encrypted_telegram_len_ = 0; while (this->available_within_timeout_()) {
size_t packet_size = 0;
while (true) {
if (!this->available()) {
if (!this->header_found_) {
return;
}
if (!this->available_within_timeout_()) {
ESP_LOGW(TAG, "Timeout while reading data for encrypted telegram");
return;
}
}
const char c = this->read(); const char c = this->read();
// Find a new telegram start byte. // Find a new telegram start byte.
@ -182,51 +197,59 @@ void Dsmr::receive_encrypted_() {
continue; continue;
} }
ESP_LOGV(TAG, "Start byte 0xDB of encrypted telegram found"); ESP_LOGV(TAG, "Start byte 0xDB of encrypted telegram found");
this->reset_telegram_();
this->header_found_ = true; this->header_found_ = true;
} }
// Check for buffer overflow. // Check for buffer overflow.
if (this->encrypted_telegram_len_ >= this->max_telegram_len_) { if (this->crypt_bytes_read_ >= this->max_telegram_len_) {
this->header_found_ = false; this->reset_telegram_();
ESP_LOGE(TAG, "Error: encrypted telegram larger than buffer (%d bytes)", this->max_telegram_len_); ESP_LOGE(TAG, "Error: encrypted telegram larger than buffer (%d bytes)", this->max_telegram_len_);
return; return;
} }
this->encrypted_telegram_[this->encrypted_telegram_len_++] = c; // Store the byte in the buffer.
this->crypt_telegram_[this->crypt_bytes_read_] = c;
this->crypt_bytes_read_++;
if (packet_size == 0 && this->encrypted_telegram_len_ > 20) { // Read the length of the incoming encrypted telegram.
if (this->crypt_telegram_len_ == 0 && this->crypt_bytes_read_ > 20) {
// Complete header + data bytes // Complete header + data bytes
packet_size = 13 + (this->encrypted_telegram_[11] << 8 | this->encrypted_telegram_[12]); this->crypt_telegram_len_ = 13 + (this->crypt_telegram_[11] << 8 | this->crypt_telegram_[12]);
ESP_LOGV(TAG, "Encrypted telegram size: %d bytes", packet_size); ESP_LOGV(TAG, "Encrypted telegram length: %d bytes", this->crypt_telegram_len_);
}
// Check for the end of the encrypted telegram.
if (this->crypt_telegram_len_ == 0 || this->crypt_bytes_read_ != this->crypt_telegram_len_) {
continue;
} }
if (this->encrypted_telegram_len_ == packet_size && packet_size > 0) {
ESP_LOGV(TAG, "End of encrypted telegram found"); ESP_LOGV(TAG, "End of encrypted telegram found");
// Decrypt the encrypted telegram.
GCM<AES128> *gcmaes128{new GCM<AES128>()}; GCM<AES128> *gcmaes128{new GCM<AES128>()};
gcmaes128->setKey(this->decryption_key_.data(), gcmaes128->keySize()); gcmaes128->setKey(this->decryption_key_.data(), gcmaes128->keySize());
// the iv is 8 bytes of the system title + 4 bytes frame counter // the iv is 8 bytes of the system title + 4 bytes frame counter
// system title is at byte 2 and frame counter at byte 15 // system title is at byte 2 and frame counter at byte 15
for (int i = 10; i < 14; i++) for (int i = 10; i < 14; i++)
this->encrypted_telegram_[i] = this->encrypted_telegram_[i + 4]; this->crypt_telegram_[i] = this->crypt_telegram_[i + 4];
constexpr uint16_t iv_size{12}; constexpr uint16_t iv_size{12};
gcmaes128->setIV(&this->encrypted_telegram_[2], iv_size); gcmaes128->setIV(&this->crypt_telegram_[2], iv_size);
gcmaes128->decrypt(reinterpret_cast<uint8_t *>(this->telegram_), gcmaes128->decrypt(reinterpret_cast<uint8_t *>(this->telegram_),
// the ciphertext start at byte 18 // the ciphertext start at byte 18
&this->encrypted_telegram_[18], &this->crypt_telegram_[18],
// cipher size // cipher size
this->encrypted_telegram_len_ - 17); this->crypt_bytes_read_ - 17);
delete gcmaes128; // NOLINT(cppcoreguidelines-owning-memory) delete gcmaes128; // NOLINT(cppcoreguidelines-owning-memory)
this->telegram_len_ = strnlen(this->telegram_, this->max_telegram_len_); this->bytes_read_ = strnlen(this->telegram_, this->max_telegram_len_);
ESP_LOGV(TAG, "Decrypted telegram size: %d bytes", this->telegram_len_); ESP_LOGV(TAG, "Decrypted telegram size: %d bytes", this->bytes_read_);
ESP_LOGVV(TAG, "Decrypted telegram: %s", this->telegram_); ESP_LOGVV(TAG, "Decrypted telegram: %s", this->telegram_);
// Parse the decrypted telegram and publish sensor values.
this->parse_telegram(); this->parse_telegram();
this->reset_telegram_();
this->header_found_ = false;
this->telegram_len_ = 0;
return; return;
} }
}
} }
bool Dsmr::parse_telegram() { bool Dsmr::parse_telegram() {
@ -234,11 +257,11 @@ bool Dsmr::parse_telegram() {
ESP_LOGV(TAG, "Trying to parse telegram"); ESP_LOGV(TAG, "Trying to parse telegram");
this->stop_requesting_data_(); this->stop_requesting_data_();
::dsmr::ParseResult<void> res = ::dsmr::ParseResult<void> res =
::dsmr::P1Parser::parse(&data, this->telegram_, this->telegram_len_, false, ::dsmr::P1Parser::parse(&data, this->telegram_, this->bytes_read_, false,
this->crc_check_); // Parse telegram according to data definition. Ignore unknown values. this->crc_check_); // Parse telegram according to data definition. Ignore unknown values.
if (res.err) { if (res.err) {
// Parsing error, show it // Parsing error, show it
auto err_str = res.fullError(this->telegram_, this->telegram_ + this->telegram_len_); auto err_str = res.fullError(this->telegram_, this->telegram_ + this->bytes_read_);
ESP_LOGE(TAG, "%s", err_str.c_str()); ESP_LOGE(TAG, "%s", err_str.c_str());
return false; return false;
} else { } else {
@ -251,7 +274,7 @@ bool Dsmr::parse_telegram() {
void Dsmr::dump_config() { void Dsmr::dump_config() {
ESP_LOGCONFIG(TAG, "DSMR:"); ESP_LOGCONFIG(TAG, "DSMR:");
ESP_LOGCONFIG(TAG, " Max telegram length: %d", this->max_telegram_len_); ESP_LOGCONFIG(TAG, " Max telegram length: %d", this->max_telegram_len_);
ESP_LOGCONFIG(TAG, " Receive timeout: %.1fs", this->receive_timeout_ / 1e3f);
if (this->request_pin_ != nullptr) { if (this->request_pin_ != nullptr) {
LOG_PIN(" Request Pin: ", this->request_pin_); LOG_PIN(" Request Pin: ", this->request_pin_);
} }
@ -270,9 +293,9 @@ void Dsmr::set_decryption_key(const std::string &decryption_key) {
if (decryption_key.length() == 0) { if (decryption_key.length() == 0) {
ESP_LOGI(TAG, "Disabling decryption"); ESP_LOGI(TAG, "Disabling decryption");
this->decryption_key_.clear(); this->decryption_key_.clear();
if (this->encrypted_telegram_ != nullptr) { if (this->crypt_telegram_ != nullptr) {
delete[] this->encrypted_telegram_; delete[] this->crypt_telegram_;
this->encrypted_telegram_ = nullptr; this->crypt_telegram_ = nullptr;
} }
return; return;
} }
@ -293,13 +316,11 @@ void Dsmr::set_decryption_key(const std::string &decryption_key) {
this->decryption_key_.push_back(std::strtoul(temp, nullptr, 16)); this->decryption_key_.push_back(std::strtoul(temp, nullptr, 16));
} }
if (this->encrypted_telegram_ == nullptr) { if (this->crypt_telegram_ == nullptr) {
this->encrypted_telegram_ = new uint8_t[this->max_telegram_len_]; // NOLINT this->crypt_telegram_ = new uint8_t[this->max_telegram_len_]; // NOLINT
} }
} }
void Dsmr::set_max_telegram_length(size_t length) { max_telegram_len_ = length; }
} // namespace dsmr } // namespace dsmr
} // namespace esphome } // namespace esphome

View file

@ -16,8 +16,6 @@
namespace esphome { namespace esphome {
namespace dsmr { namespace dsmr {
static constexpr uint32_t READ_TIMEOUT_MS = 200;
using namespace ::dsmr::fields; using namespace ::dsmr::fields;
// DSMR_**_LIST generated by ESPHome and written in esphome/core/defines // DSMR_**_LIST generated by ESPHome and written in esphome/core/defines
@ -71,11 +69,10 @@ class Dsmr : public Component, public uart::UARTDevice {
void dump_config() override; void dump_config() override;
void set_decryption_key(const std::string &decryption_key); void set_decryption_key(const std::string &decryption_key);
void set_max_telegram_length(size_t length) { this->max_telegram_len_ = length; }
void set_max_telegram_length(size_t length);
void set_request_pin(GPIOPin *request_pin) { this->request_pin_ = request_pin; } void set_request_pin(GPIOPin *request_pin) { this->request_pin_ = request_pin; }
void set_request_interval(uint32_t interval) { this->request_interval_ = interval; } void set_request_interval(uint32_t interval) { this->request_interval_ = interval; }
void set_receive_timeout(uint32_t timeout) { this->receive_timeout_ = timeout; }
// Sensor setters // Sensor setters
#define DSMR_SET_SENSOR(s) \ #define DSMR_SET_SENSOR(s) \
@ -88,7 +85,8 @@ class Dsmr : public Component, public uart::UARTDevice {
protected: protected:
void receive_telegram_(); void receive_telegram_();
void receive_encrypted_(); void receive_encrypted_telegram_();
void reset_telegram_();
/// Wait for UART data to become available within the read timeout. /// Wait for UART data to become available within the read timeout.
/// ///
@ -101,24 +99,26 @@ class Dsmr : public Component, public uart::UARTDevice {
/// lost in the process. /// lost in the process.
bool available_within_timeout_(); bool available_within_timeout_();
// Data request // Request telegram
uint32_t request_interval_;
bool request_interval_reached_();
GPIOPin *request_pin_{nullptr}; GPIOPin *request_pin_{nullptr};
uint32_t request_interval_{0};
uint32_t last_request_time_{0}; uint32_t last_request_time_{0};
bool requesting_data_{false}; bool requesting_data_{false};
bool ready_to_request_data_(); bool ready_to_request_data_();
bool request_interval_reached_();
void start_requesting_data_(); void start_requesting_data_();
void stop_requesting_data_(); void stop_requesting_data_();
// Telegram buffer // Read telegram
uint32_t receive_timeout_;
bool receive_timeout_reached_();
size_t max_telegram_len_; size_t max_telegram_len_;
char *telegram_{nullptr}; char *telegram_{nullptr};
int telegram_len_{0}; int bytes_read_{0};
uint8_t *encrypted_telegram_{nullptr}; uint8_t *crypt_telegram_{nullptr};
int encrypted_telegram_len_{0}; size_t crypt_telegram_len_{0};
int crypt_bytes_read_{0};
// Serial parser uint32_t last_read_time_{0};
bool header_found_{false}; bool header_found_{false};
bool footer_found_{false}; bool footer_found_{false};

View file

@ -52,6 +52,7 @@ class UARTComponent {
void set_tx_pin(InternalGPIOPin *tx_pin) { this->tx_pin_ = tx_pin; } void set_tx_pin(InternalGPIOPin *tx_pin) { this->tx_pin_ = tx_pin; }
void set_rx_pin(InternalGPIOPin *rx_pin) { this->rx_pin_ = rx_pin; } void set_rx_pin(InternalGPIOPin *rx_pin) { this->rx_pin_ = rx_pin; }
void set_rx_buffer_size(size_t rx_buffer_size) { this->rx_buffer_size_ = rx_buffer_size; } void set_rx_buffer_size(size_t rx_buffer_size) { this->rx_buffer_size_ = rx_buffer_size; }
size_t get_rx_buffer_size() { return this->rx_buffer_size_; }
void set_stop_bits(uint8_t stop_bits) { this->stop_bits_ = stop_bits; } void set_stop_bits(uint8_t stop_bits) { this->stop_bits_ = stop_bits; }
uint8_t get_stop_bits() const { return this->stop_bits_; } uint8_t get_stop_bits() const { return this->stop_bits_; }

View file

@ -90,6 +90,11 @@ void UARTDummyReceiver::loop() {
} }
} }
// In the upcoming log functions, a delay was added after all log calls.
// This is done to allow the system to ship the log lines via the API
// TCP connection(s). Without these delays, debug log lines could go
// missing when UART devices block the main loop for too long.
void UARTDebug::log_hex(UARTDirection direction, std::vector<uint8_t> bytes, uint8_t separator) { void UARTDebug::log_hex(UARTDirection direction, std::vector<uint8_t> bytes, uint8_t separator) {
std::string res; std::string res;
if (direction == UART_DIRECTION_RX) { if (direction == UART_DIRECTION_RX) {
@ -107,6 +112,7 @@ void UARTDebug::log_hex(UARTDirection direction, std::vector<uint8_t> bytes, uin
res += buf; res += buf;
} }
ESP_LOGD(TAG, "%s", res.c_str()); ESP_LOGD(TAG, "%s", res.c_str());
delay(10);
} }
void UARTDebug::log_string(UARTDirection direction, std::vector<uint8_t> bytes) { void UARTDebug::log_string(UARTDirection direction, std::vector<uint8_t> bytes) {
@ -150,6 +156,7 @@ void UARTDebug::log_string(UARTDirection direction, std::vector<uint8_t> bytes)
} }
res += '"'; res += '"';
ESP_LOGD(TAG, "%s", res.c_str()); ESP_LOGD(TAG, "%s", res.c_str());
delay(10);
} }
void UARTDebug::log_int(UARTDirection direction, std::vector<uint8_t> bytes, uint8_t separator) { void UARTDebug::log_int(UARTDirection direction, std::vector<uint8_t> bytes, uint8_t separator) {
@ -167,6 +174,7 @@ void UARTDebug::log_int(UARTDirection direction, std::vector<uint8_t> bytes, uin
res += to_string(bytes[i]); res += to_string(bytes[i]);
} }
ESP_LOGD(TAG, "%s", res.c_str()); ESP_LOGD(TAG, "%s", res.c_str());
delay(10);
} }
void UARTDebug::log_binary(UARTDirection direction, std::vector<uint8_t> bytes, uint8_t separator) { void UARTDebug::log_binary(UARTDirection direction, std::vector<uint8_t> bytes, uint8_t separator) {
@ -186,6 +194,7 @@ void UARTDebug::log_binary(UARTDirection direction, std::vector<uint8_t> bytes,
res += buf; res += buf;
} }
ESP_LOGD(TAG, "%s", res.c_str()); ESP_LOGD(TAG, "%s", res.c_str());
delay(10);
} }
} // namespace uart } // namespace uart

View file

@ -1313,6 +1313,7 @@ dsmr:
max_telegram_length: 1000 max_telegram_length: 1000
request_pin: D5 request_pin: D5
request_interval: 20s request_interval: 20s
receive_timeout: 100ms
daly_bms: daly_bms:
update_interval: 20s update_interval: 20s