From 9914cccae2b955db50178d05189e3e8c831eedf0 Mon Sep 17 00:00:00 2001 From: Matthias Bolte Date: Mon, 16 Dec 2024 16:07:51 +0100 Subject: [PATCH] meters-modbus-tcp: Move debug output to trace log --- .../meters_modbus_tcp/meter_modbus_tcp.cpp | 168 +++++++++++------- .../meters_modbus_tcp/meter_modbus_tcp.h | 5 +- .../meters_modbus_tcp/meters_modbus_tcp.cpp | 4 +- .../meters_modbus_tcp/meters_modbus_tcp.h | 2 + 4 files changed, 108 insertions(+), 71 deletions(-) diff --git a/software/src/modules/meters_modbus_tcp/meter_modbus_tcp.cpp b/software/src/modules/meters_modbus_tcp/meter_modbus_tcp.cpp index 85012e8d9..136f16add 100644 --- a/software/src/modules/meters_modbus_tcp/meter_modbus_tcp.cpp +++ b/software/src/modules/meters_modbus_tcp/meter_modbus_tcp.cpp @@ -19,6 +19,7 @@ */ #define EVENT_LOG_PREFIX "meters_mbtcp" +#define TRACE_LOG_PREFIX nullptr #include "meter_modbus_tcp.h" @@ -30,7 +31,7 @@ #include "gcc_warnings.h" -//#define DEBUG_LOG_ALL_VALUES +//#define DEBUG_VALUES_TO_TRACE_LOG #define NUMBER_TO_ADDRESS(number) ((number) - 1u) @@ -963,7 +964,7 @@ bool MeterModbusTCP::prepare_read() bool overflow = false; while ( -#ifndef DEBUG_LOG_ALL_VALUES +#ifndef DEBUG_VALUES_TO_TRACE_LOG table->index[read_index] == VALUE_INDEX_DEBUG || #endif table->specs[read_index].start_address == START_ADDRESS_VIRTUAL) { @@ -1075,6 +1076,14 @@ bool MeterModbusTCP::is_carlo_gavazzi_em510() const void MeterModbusTCP::read_done_callback() { if (generic_read_request.result != TFModbusTCPClientTransactionResult::Success) { + logger.tracefln(trace_buffer_index, + "m%u t%u i%zu e%u a%zu", + slot, + static_cast(table_id), + read_index, + static_cast(generic_read_request.result), + table->specs[read_index].start_address); + if (generic_read_request.result == TFModbusTCPClientTransactionResult::Timeout) { auto timeout = errors->get("timeout"); timeout->updateUint(timeout->asUint() + 1); @@ -1088,6 +1097,15 @@ void MeterModbusTCP::read_done_callback() if (is_sungrow_inverter_meter() && generic_read_request.start_address == SUNGROW_INVERTER_OUTPUT_TYPE_ADDRESS) { if (sungrow_inverter_output_type < 0) { + logger.tracefln(trace_buffer_index, + "m%u t%u i%zu u16 a%zu r%u v%u", + slot, + static_cast(table_id), + read_index, + table->specs[read_index].start_address, + register_buffer[register_buffer_index], + register_buffer[register_buffer_index]); + switch (register_buffer[register_buffer_index]) { case 0: if (table_id == MeterModbusTCPTableID::SungrowHybridInverter) { @@ -1126,13 +1144,6 @@ void MeterModbusTCP::read_done_callback() sungrow_inverter_output_type = register_buffer[register_buffer_index]; -#ifdef DEBUG_LOG_ALL_VALUES - logger.printfln("%s / Output Type (%u): %d", - get_meter_modbus_tcp_table_id_name(table_id), - SUNGROW_INVERTER_OUTPUT_TYPE_ADDRESS, - sungrow_inverter_output_type); -#endif - meters.declare_value_ids(slot, table->ids, table->ids_length); } @@ -1148,6 +1159,15 @@ void MeterModbusTCP::read_done_callback() if (is_deye_hybrid_inverter_battery_meter() && generic_read_request.start_address == DEYE_HYBRID_INVERTER_DEVICE_TYPE_ADDRESS) { if (deye_hybrid_inverter_device_type < 0) { + logger.tracefln(trace_buffer_index, + "m%u t%u i%zu u16 a%zu r%u v%u", + slot, + static_cast(table_id), + read_index, + table->specs[read_index].start_address, + register_buffer[register_buffer_index], + register_buffer[register_buffer_index]); + switch (register_buffer[register_buffer_index]) { case 0x0002: case 0x0003: @@ -1171,13 +1191,6 @@ void MeterModbusTCP::read_done_callback() deye_hybrid_inverter_device_type = register_buffer[register_buffer_index]; -#ifdef DEBUG_LOG_ALL_VALUES - logger.printfln("%s / Device Type (%u): %d", - get_meter_modbus_tcp_table_id_name(table_id), - DEYE_HYBRID_INVERTER_DEVICE_TYPE_ADDRESS, - deye_hybrid_inverter_device_type); -#endif - meters.declare_value_ids(slot, table->ids, table->ids_length); } @@ -1205,6 +1218,7 @@ void MeterModbusTCP::read_done_callback() float value = NAN; ModbusValueType value_type = table->specs[read_index].value_type; size_t register_count = MODBUS_VALUE_TYPE_TO_REGISTER_COUNT(value_type); + const char *endian = "?"; switch (register_count) { case 1: @@ -1212,10 +1226,12 @@ void MeterModbusTCP::read_done_callback() case 2: if (MODBUS_VALUE_TYPE_TO_REGISTER_ORDER_LE(value_type)) { + endian = "le"; c32.r[0] = register_buffer[register_buffer_index + 0]; c32.r[1] = register_buffer[register_buffer_index + 1]; } else { + endian = "be"; c32.r[0] = register_buffer[register_buffer_index + 1]; c32.r[1] = register_buffer[register_buffer_index + 0]; } @@ -1224,12 +1240,14 @@ void MeterModbusTCP::read_done_callback() case 4: if (MODBUS_VALUE_TYPE_TO_REGISTER_ORDER_LE(value_type)) { + endian = "le"; c64.r[0] = register_buffer[register_buffer_index + 0]; c64.r[1] = register_buffer[register_buffer_index + 1]; c64.r[2] = register_buffer[register_buffer_index + 2]; c64.r[3] = register_buffer[register_buffer_index + 3]; } else { + endian = "be"; c64.r[0] = register_buffer[register_buffer_index + 3]; c64.r[1] = register_buffer[register_buffer_index + 2]; c64.r[2] = register_buffer[register_buffer_index + 1]; @@ -1245,124 +1263,138 @@ void MeterModbusTCP::read_done_callback() switch (value_type) { case ModbusValueType::None: + logger.tracefln(trace_buffer_index, + "m%u t%u i%zu n a%zu", + slot, + static_cast(table_id), + read_index, + table->specs[read_index].start_address); break; case ModbusValueType::U16: -#ifdef DEBUG_LOG_ALL_VALUES - logger.printfln("%s / %s (%zu): %u", - get_meter_modbus_tcp_table_id_name(table_id), - table->specs[read_index].name, + logger.tracefln(trace_buffer_index, + "m%u t%u i%zu u16 a%zu r%u v%u", + slot, + static_cast(table_id), + read_index, table->specs[read_index].start_address, + register_buffer[register_buffer_index], register_buffer[register_buffer_index]); -#endif value = static_cast(register_buffer[register_buffer_index]); break; case ModbusValueType::S16: -#ifdef DEBUG_LOG_ALL_VALUES - logger.printfln("%s / %s (%zu): %d", - get_meter_modbus_tcp_table_id_name(table_id), - table->specs[read_index].name, + logger.tracefln(trace_buffer_index, + "m%u t%u i%zu s16 a%zu r%u v%d", + slot, + static_cast(table_id), + read_index, table->specs[read_index].start_address, + register_buffer[register_buffer_index], static_cast(register_buffer[register_buffer_index])); -#endif value = static_cast(static_cast(register_buffer[register_buffer_index])); break; case ModbusValueType::U32BE: case ModbusValueType::U32LE: -#ifdef DEBUG_LOG_ALL_VALUES - logger.printfln("%s / %s (%zu): %u (%u %u)", - get_meter_modbus_tcp_table_id_name(table_id), - table->specs[read_index].name, + logger.tracefln(trace_buffer_index, + "m%u t%u i%zu u32%s a%zu r%u,%u v%u", + slot, + static_cast(table_id), + read_index, + endian, table->specs[read_index].start_address, - c32.u, register_buffer[register_buffer_index + 0], - register_buffer[register_buffer_index + 1]); -#endif + register_buffer[register_buffer_index + 1], + c32.u); value = static_cast(c32.u); break; case ModbusValueType::S32BE: case ModbusValueType::S32LE: -#ifdef DEBUG_LOG_ALL_VALUES - logger.printfln("%s / %s (%zu): %d (%u %u)", - get_meter_modbus_tcp_table_id_name(table_id), - table->specs[read_index].name, + logger.tracefln(trace_buffer_index, + "m%u t%u i%zu s32%s a%zu r%u,%u v%d", + slot, + static_cast(table_id), + read_index, + endian, table->specs[read_index].start_address, - static_cast(c32.u), register_buffer[register_buffer_index + 0], - register_buffer[register_buffer_index + 1]); -#endif + register_buffer[register_buffer_index + 1], + static_cast(c32.u)); value = static_cast(static_cast(c32.u)); break; case ModbusValueType::F32BE: case ModbusValueType::F32LE: -#ifdef DEBUG_LOG_ALL_VALUES - logger.printfln("%s / %s (%zu): %f (%u %u)", - get_meter_modbus_tcp_table_id_name(table_id), - table->specs[read_index].name, + logger.tracefln(trace_buffer_index, + "m%u t%u i%zu f32%s a%zu r%u,%u v%f", + slot, + static_cast(table_id), + read_index, + endian, table->specs[read_index].start_address, - static_cast(c32.f), register_buffer[register_buffer_index + 0], - register_buffer[register_buffer_index + 1]); -#endif + register_buffer[register_buffer_index + 1], + static_cast(c32.f)); value = c32.f; break; case ModbusValueType::U64BE: case ModbusValueType::U64LE: -#ifdef DEBUG_LOG_ALL_VALUES - logger.printfln("%s / %s (%zu): %llu (%u %u %u %u)", - get_meter_modbus_tcp_table_id_name(table_id), - table->specs[read_index].name, + logger.tracefln(trace_buffer_index, + "m%u t%u i%zu u64%s a%zu r%u,%u,%u,%u v%llu", + slot, + static_cast(table_id), + read_index, + endian, table->specs[read_index].start_address, - c64.u, register_buffer[register_buffer_index + 0], register_buffer[register_buffer_index + 1], register_buffer[register_buffer_index + 2], - register_buffer[register_buffer_index + 3]); -#endif + register_buffer[register_buffer_index + 3], + c64.u); value = static_cast(c64.u); break; case ModbusValueType::S64BE: case ModbusValueType::S64LE: -#ifdef DEBUG_LOG_ALL_VALUES - logger.printfln("%s / %s (%zu): %lld (%u %u %u %u)", - get_meter_modbus_tcp_table_id_name(table_id), - table->specs[read_index].name, + logger.tracefln(trace_buffer_index, + "m%u t%u i%zu s64%s a%zu r%u,%u,%u,%u v%lld", + slot, + static_cast(table_id), + read_index, + endian, table->specs[read_index].start_address, - static_cast(c64.u), register_buffer[register_buffer_index + 0], register_buffer[register_buffer_index + 1], register_buffer[register_buffer_index + 2], - register_buffer[register_buffer_index + 3]); -#endif + register_buffer[register_buffer_index + 3], + static_cast(c64.u)); value = static_cast(static_cast(c64.u)); break; case ModbusValueType::F64BE: case ModbusValueType::F64LE: -#ifdef DEBUG_LOG_ALL_VALUES - logger.printfln("%s / %s (%zu): %f (%u %u %u %u)", - get_meter_modbus_tcp_table_id_name(table_id), - table->specs[read_index].name, + logger.tracefln(trace_buffer_index, + "m%u t%u i%zu f64%s a%zu r%u,%u,%u,%u v%f", + slot, + static_cast(table_id), + read_index, + endian, table->specs[read_index].start_address, - c64.f, register_buffer[register_buffer_index + 0], register_buffer[register_buffer_index + 1], register_buffer[register_buffer_index + 2], - register_buffer[register_buffer_index + 3]); -#endif + register_buffer[register_buffer_index + 3], + c64.f); value = static_cast(c64.f); break; diff --git a/software/src/modules/meters_modbus_tcp/meter_modbus_tcp.h b/software/src/modules/meters_modbus_tcp/meter_modbus_tcp.h index bc55b8daa..9394d7048 100644 --- a/software/src/modules/meters_modbus_tcp/meter_modbus_tcp.h +++ b/software/src/modules/meters_modbus_tcp/meter_modbus_tcp.h @@ -77,8 +77,8 @@ class MeterModbusTCP final : protected GenericModbusTCPClient, public IMeter const uint32_t *index; }; - MeterModbusTCP(uint32_t slot_, Config *state_, Config *errors_, TFModbusTCPClientPool *pool_) : - GenericModbusTCPClient("meters_mbtcp", pool_), slot(slot_), state(state_), errors(errors_) {} + MeterModbusTCP(uint32_t slot_, Config *state_, Config *errors_, TFModbusTCPClientPool *pool_, size_t trace_buffer_index_) : + GenericModbusTCPClient("meters_mbtcp", pool_), slot(slot_), state(state_), errors(errors_), trace_buffer_index(trace_buffer_index_) {} [[gnu::const]] MeterClassID get_class() const override; void setup(const Config &ephemeral_config) override; @@ -112,6 +112,7 @@ class MeterModbusTCP final : protected GenericModbusTCPClient, public IMeter uint32_t slot; Config *state; Config *errors; + size_t trace_buffer_index; MeterModbusTCPTableID table_id; const ValueTable *table = nullptr; diff --git a/software/src/modules/meters_modbus_tcp/meters_modbus_tcp.cpp b/software/src/modules/meters_modbus_tcp/meters_modbus_tcp.cpp index ad80a5374..597715f22 100644 --- a/software/src/modules/meters_modbus_tcp/meters_modbus_tcp.cpp +++ b/software/src/modules/meters_modbus_tcp/meters_modbus_tcp.cpp @@ -32,6 +32,8 @@ void MetersModbusTCP::pre_setup() { + this->trace_buffer_index = logger.alloc_trace_buffer("meters_mbtcp", 8192); + table_prototypes.push_back({MeterModbusTCPTableID::None, *Config::Null()}); table_custom_registers_prototype = Config::Object({ @@ -189,7 +191,7 @@ MeterClassID MetersModbusTCP::get_class() const IMeter *MetersModbusTCP::new_meter(uint32_t slot, Config *state, Config *errors) { - return new MeterModbusTCP(slot, state, errors, modbus_tcp_client.get_pool()); + return new MeterModbusTCP(slot, state, errors, modbus_tcp_client.get_pool(), trace_buffer_index); } const Config *MetersModbusTCP::get_config_prototype() diff --git a/software/src/modules/meters_modbus_tcp/meters_modbus_tcp.h b/software/src/modules/meters_modbus_tcp/meters_modbus_tcp.h index 1a0dcbbe2..3545bd624 100644 --- a/software/src/modules/meters_modbus_tcp/meters_modbus_tcp.h +++ b/software/src/modules/meters_modbus_tcp/meters_modbus_tcp.h @@ -52,6 +52,8 @@ class MetersModbusTCP final : public IModule, public IMeterGenerator Config table_custom_registers_prototype; std::vector> table_prototypes; Config errors_prototype; + + size_t trace_buffer_index; }; #if defined(__GNUC__)