From 45fcd8ac833a5c806696e32e1489e1d113e7949e Mon Sep 17 00:00:00 2001 From: Theo Arends <11044339+arendst@users.noreply.github.com> Date: Fri, 29 Oct 2021 18:49:29 +0200 Subject: [PATCH] Add optional profiling --- tasmota/support.ino | 17 ++++--- tasmota/support_profiling.ino | 86 +++++++++++++++++++++++++++++++++++ tasmota/support_tasmota.ino | 4 +- tasmota/tasmota.h | 2 +- tasmota/xdrv_interface.ino | 11 ++++- tasmota/xsns_interface.ino | 29 +++--------- 6 files changed, 115 insertions(+), 34 deletions(-) create mode 100644 tasmota/support_profiling.ino diff --git a/tasmota/support.ino b/tasmota/support.ino index 81eb25f1c..c5f6078ed 100644 --- a/tasmota/support.ino +++ b/tasmota/support.ino @@ -1997,22 +1997,25 @@ const uint8_t I2C_RETRY_COUNTER = 3; uint32_t i2c_active[4] = { 0 }; uint32_t i2c_buffer = 0; -void I2cBegin(int sda, int scl, uint32_t frequency = 100000); -void I2cBegin(int sda, int scl, uint32_t frequency) { +bool I2cBegin(int sda, int scl, uint32_t frequency = 100000); +bool I2cBegin(int sda, int scl, uint32_t frequency) { + bool result = true; #ifdef ESP8266 Wire.begin(sda, scl); #endif #ifdef ESP32 - bool result = Wire.begin(sda, scl, frequency); - AddLog(LOG_LEVEL_DEBUG, PSTR("I2C: Begin %d"), result); + result = Wire.begin(sda, scl, frequency); #endif +// AddLog(LOG_LEVEL_DEBUG, PSTR("I2C: Bus1 %d"), result); + return result; } #ifdef ESP32 -void I2c2Begin(int sda, int scl, uint32_t frequency = 100000); -void I2c2Begin(int sda, int scl, uint32_t frequency) { +bool I2c2Begin(int sda, int scl, uint32_t frequency = 100000); +bool I2c2Begin(int sda, int scl, uint32_t frequency) { bool result = Wire1.begin(sda, scl, frequency); - AddLog(LOG_LEVEL_DEBUG, PSTR("I2C: Bus 2 begin %d"), result); +// AddLog(LOG_LEVEL_DEBUG, PSTR("I2C: Bus2 %d"), result); + return result; } bool I2cValidRead(uint8_t addr, uint8_t reg, uint8_t size, uint32_t bus = 0); diff --git a/tasmota/support_profiling.ino b/tasmota/support_profiling.ino new file mode 100644 index 000000000..f45ba2549 --- /dev/null +++ b/tasmota/support_profiling.ino @@ -0,0 +1,86 @@ +/* + support_profiling.ino - profiling support for Tasmota + + Copyright (C) 2021 Theo Arends + + This program is free software: you can redistribute it and/or modify + it under the terms of the GNU General Public License as published by + the Free Software Foundation, either version 3 of the License, or + (at your option) any later version. + + This program is distributed in the hope that it will be useful, + but WITHOUT ANY WARRANTY; without even the implied warranty of + MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + GNU General Public License for more details. + + You should have received a copy of the GNU General Public License + along with this program. If not, see . +*/ + +//#define USE_PROFILING + +#define PROFILE_THRESHOLD 70 // Minimum duration in milliseconds to start logging +//#define USE_PROFILE_DRIVER +#define USE_PROFILE_FUNCTION + +/*********************************************************************************************\ + * Profiling features +\*********************************************************************************************/ + +#ifndef USE_PROFILING +#undef USE_PROFILE_DRIVER +#undef USE_PROFILE_FUNCTION +#endif + +#ifdef USE_PROFILE_DRIVER +#define PROFILE_DRIVER(DRIVER, FUNCTION, START) AddLogDriver(DRIVER, FUNCTION, START) +#else +#define PROFILE_DRIVER(DRIVER, FUNCTION, START) +#endif // USE_PROFILE_DRIVER + +#ifdef USE_PROFILE_FUNCTION +#define PROFILE_FUNCTION(DRIVER, INDEX, FUNCTION, START) AddLogFunction(DRIVER, INDEX, FUNCTION, START) +#else +#define PROFILE_FUNCTION(DRIVER, INDEX, FUNCTION, START) +#endif // USE_PROFILE_DRIVER + +/*********************************************************************************************\ + * Profiling services +\*********************************************************************************************/ + +#ifdef USE_PROFILING + +// Below needs to be inline with enum XsnsFunctions +const char kXSnsFunctions[] PROGMEM = "SETTINGS_OVERRIDE|PIN_STATE|MODULE_INIT|PRE_INIT|INIT|" + "LOOP|EVERY_50_MSECOND|EVERY_100_MSECOND|EVERY_200_MSECOND|EVERY_250_MSECOND|EVERY_SECOND|" + "SAVE_SETTINGS|SAVE_AT_MIDNIGHT|SAVE_BEFORE_RESTART|" + "AFTER_TELEPERIOD|JSON_APPEND|WEB_SENSOR|COMMAND|COMMAND_SENSOR|COMMAND_DRIVER|" + "MQTT_SUBSCRIBE|MQTT_INIT|MQTT_DATA|" + "SET_POWER|SET_DEVICE_POWER|SHOW_SENSOR|ANY_KEY|" + "ENERGY_EVERY_SECOND|ENERGY_RESET|" + "RULES_PROCESS|TELEPERIOD_RULES_PROCESS|SERIAL|FREE_MEM|BUTTON_PRESSED|" + "WEB_ADD_BUTTON|WEB_ADD_CONSOLE_BUTTON|WEB_ADD_MANAGEMENT_BUTTON|WEB_ADD_MAIN_BUTTON|" + "WEB_ADD_HANDLER|SET_CHANNELS|SET_SCHEME|HOTPLUG_SCAN|" + "DEVICE_GROUP_ITEM"; + +#ifdef USE_PROFILE_DRIVER +void AddLogDriver(const char *driver, uint8_t function, uint32_t start) { + uint32_t profile_millis = millis() - start; + if (profile_millis > PROFILE_THRESHOLD) { + char stemp1[20]; + AddLog(LOG_LEVEL_DEBUG, PSTR("PRF: *** %s FUNC_%s (%d ms)"), driver, GetTextIndexed(stemp1, sizeof(stemp1), function, kXSnsFunctions), profile_millis); + } +} +#endif // USE_PROFILE_DRIVER + +#ifdef USE_PROFILE_FUNCTION +void AddLogFunction(const char *driver, uint8_t index, uint8_t function, uint32_t start) { + uint32_t profile_millis = millis() - start; + if (profile_millis > PROFILE_THRESHOLD) { + char stemp1[20]; + AddLog(LOG_LEVEL_DEBUG, PSTR("PRF: *** %s_%02d FUNC_%s (%d ms)"), driver, index, GetTextIndexed(stemp1, sizeof(stemp1), function, kXSnsFunctions), profile_millis); + } +} +#endif // USE_PROFILE_DRIVER + +#endif // USE_PROFILING diff --git a/tasmota/support_tasmota.ino b/tasmota/support_tasmota.ino index 344a0c625..4e30671d6 100644 --- a/tasmota/support_tasmota.ino +++ b/tasmota/support_tasmota.ino @@ -1901,12 +1901,12 @@ void GpioInit(void) #ifdef USE_I2C TasmotaGlobal.i2c_enabled = (PinUsed(GPIO_I2C_SCL) && PinUsed(GPIO_I2C_SDA)); if (TasmotaGlobal.i2c_enabled) { - I2cBegin(Pin(GPIO_I2C_SDA), Pin(GPIO_I2C_SCL)); + TasmotaGlobal.i2c_enabled = I2cBegin(Pin(GPIO_I2C_SDA), Pin(GPIO_I2C_SCL)); } #ifdef ESP32 TasmotaGlobal.i2c_enabled_2 = (PinUsed(GPIO_I2C_SCL, 1) && PinUsed(GPIO_I2C_SDA, 1)); if (TasmotaGlobal.i2c_enabled_2) { - I2c2Begin(Pin(GPIO_I2C_SDA, 1), Pin(GPIO_I2C_SCL, 1)); + TasmotaGlobal.i2c_enabled_2 = I2c2Begin(Pin(GPIO_I2C_SDA, 1), Pin(GPIO_I2C_SCL, 1)); } #endif #endif // USE_I2C diff --git a/tasmota/tasmota.h b/tasmota/tasmota.h index 393da4c96..ea858c21b 100644 --- a/tasmota/tasmota.h +++ b/tasmota/tasmota.h @@ -294,7 +294,7 @@ enum UploadTypes { UPL_TASMOTA = 1, UPL_SETTINGS, UPL_EFM8BB1, UPL_TASMOTACLIENT enum ExecuteCommandPowerOptions { POWER_OFF, POWER_ON, POWER_TOGGLE, POWER_BLINK, POWER_BLINK_STOP, POWER_OFF_NO_STATE = 8, POWER_ON_NO_STATE, POWER_TOGGLE_NO_STATE, POWER_SHOW_STATE = 16 }; -enum SendKeyPowerOptions { POWER_HOLD = 3, POWER_INCREMENT = 4, POWER_INV = 5, POWER_CLEAR = 6, POWER_RELEASE = 7, +enum SendKeyPowerOptions { POWER_HOLD = 3, POWER_INCREMENT = 4, POWER_INV = 5, POWER_CLEAR = 6, POWER_RELEASE = 7, POWER_100 = 8, CLEAR_RETAIN = 9, POWER_DELAYED = 10 }; enum SendKeyOptions { KEY_BUTTON, KEY_SWITCH }; enum SendKeyMultiClick { SINGLE = 10, DOUBLE = 11, TRIPLE = 12, QUAD = 13, PENTA = 14}; diff --git a/tasmota/xdrv_interface.ino b/tasmota/xdrv_interface.ino index 0444ad11d..7f372af78 100644 --- a/tasmota/xdrv_interface.ino +++ b/tasmota/xdrv_interface.ino @@ -1135,11 +1135,18 @@ bool XdrvCall(uint8_t Function) { bool result = false; - DEBUG_TRACE_LOG(PSTR("DRV: %d"), Function); +// DEBUG_TRACE_LOG(PSTR("DRV: %d"), Function); + + uint32_t profile_driver_start = millis(); for (uint32_t x = 0; x < xdrv_present; x++) { + + uint32_t profile_function_start = millis(); + result = xdrv_func_ptr[x](Function); + PROFILE_FUNCTION(PSTR("xdrv"), kXdrvList[x], Function, profile_function_start); + if (result && ((FUNC_COMMAND == Function) || (FUNC_COMMAND_DRIVER == Function) || (FUNC_MQTT_DATA == Function) || @@ -1155,5 +1162,7 @@ bool XdrvCall(uint8_t Function) } } + PROFILE_DRIVER(PSTR("xdrv"), Function, profile_driver_start); + return result; } diff --git a/tasmota/xsns_interface.ino b/tasmota/xsns_interface.ino index bb9b35e1a..bbbc57bc9 100644 --- a/tasmota/xsns_interface.ino +++ b/tasmota/xsns_interface.ino @@ -1114,29 +1114,19 @@ bool XsnsNextCall(uint8_t Function, uint8_t &xsns_index) { bool XsnsCall(uint8_t Function) { bool result = false; - DEBUG_TRACE_LOG(PSTR("SNS: %d"), Function); +// DEBUG_TRACE_LOG(PSTR("SNS: %d"), Function); -#ifdef PROFILE_XSNS_EVERY_SECOND - uint32_t profile_start_millis = millis(); -#endif // PROFILE_XSNS_EVERY_SECOND + uint32_t profile_driver_start = millis(); for (uint32_t x = 0; x < xsns_present; x++) { if (XsnsEnabled(0, x)) { // Skip disabled sensor if ((FUNC_WEB_SENSOR == Function) && !XsnsEnabled(1, x)) { continue; } // Skip web info for disabled sensors -#ifdef PROFILE_XSNS_SENSOR_EVERY_SECOND - uint32_t profile_start_millis = millis(); -#endif // PROFILE_XSNS_SENSOR_EVERY_SECOND + uint32_t profile_function_start = millis(); + result = xsns_func_ptr[x](Function); -#ifdef PROFILE_XSNS_SENSOR_EVERY_SECOND - uint32_t profile_millis = millis() - profile_start_millis; - if (profile_millis) { - if (FUNC_EVERY_SECOND == Function) { - AddLog(LOG_LEVEL_DEBUG, PSTR("PRF: At %08u XsnsCall %d to Sensor %d took %u mS"), TasmotaGlobal.uptime, Function, x, profile_millis); - } - } -#endif // PROFILE_XSNS_SENSOR_EVERY_SECOND + PROFILE_FUNCTION(PSTR("xsns"), kXsnsList[x], Function, profile_function_start); if (result && ((FUNC_COMMAND == Function) || (FUNC_PIN_STATE == Function) || @@ -1147,14 +1137,7 @@ bool XsnsCall(uint8_t Function) { } } -#ifdef PROFILE_XSNS_EVERY_SECOND - uint32_t profile_millis = millis() - profile_start_millis; - if (profile_millis) { - if (FUNC_EVERY_SECOND == Function) { - AddLog(LOG_LEVEL_DEBUG, PSTR("PRF: At %08u XsnsCall %d took %u mS"), TasmotaGlobal.uptime, Function, profile_millis); - } - } -#endif // PROFILE_XSNS_EVERY_SECOND + PROFILE_DRIVER(PSTR("xsns"), Function, profile_driver_start); return result; }