Redesign syslog and mqttlog using log buffer

Redesign syslog and mqttlog using log buffer (#10164)
This commit is contained in:
Theo Arends 2020-12-18 15:37:20 +01:00
parent 50cb0bf096
commit b7af08c03b
8 changed files with 110 additions and 75 deletions

View File

@ -8,6 +8,9 @@ All notable changes to this project will be documented in this file.
- Milliseconds to console output (#10152)
- Support for P9813 RGB Led MOSFET controller (#10104)
### Fixed
- Redesign syslog and mqttlog using log buffer (#10164)
## [Released]
## [9.2.0] 20201216

View File

@ -61,10 +61,5 @@ The attached binaries can also be downloaded from http://ota.tasmota.com/tasmota
- Milliseconds to console output (#10152)
- Support for P9813 RGB Led MOSFET controller (#10104)
### Breaking Changed
### Changed
### Fixed
### Removed
- Redesign syslog and mqttlog using log buffer (#10164)

View File

@ -1899,32 +1899,6 @@ void SetSyslog(uint32_t loglevel)
TasmotaGlobal.syslog_timer = 0;
}
#ifdef USE_WEBSERVER
void GetLog(uint32_t idx, char** entry_pp, size_t* len_p)
{
char* entry_p = nullptr;
size_t len = 0;
if (idx) {
char* it = TasmotaGlobal.web_log;
do {
uint32_t cur_idx = *it;
it++;
size_t tmp = strchrspn(it, '\1');
tmp++; // Skip terminating '\1'
if (cur_idx == idx) { // Found the requested entry
len = tmp;
entry_p = it;
break;
}
it += tmp;
} while (it < TasmotaGlobal.web_log + WEB_LOG_SIZE && *it != '\0');
}
*entry_pp = entry_p;
*len_p = len;
}
#endif // USE_WEBSERVER
void Syslog(void)
{
// Destroys TasmotaGlobal.log_data
@ -1935,14 +1909,14 @@ void Syslog(void)
WiFi.hostByName(SettingsText(SET_SYSLOG_HOST), syslog_host_addr); // If sleep enabled this might result in exception so try to do it once using hash
}
if (PortUdp.beginPacket(syslog_host_addr, Settings.syslog_port)) {
char syslog_preamble[64]; // Hostname + Id
char syslog_preamble[64]; // Hostname + Id
snprintf_P(syslog_preamble, sizeof(syslog_preamble), PSTR("%s ESP-"), NetworkHostname());
memmove(TasmotaGlobal.log_data + strlen(syslog_preamble), TasmotaGlobal.log_data, sizeof(TasmotaGlobal.log_data) - strlen(syslog_preamble));
TasmotaGlobal.log_data[sizeof(TasmotaGlobal.log_data) -1] = '\0';
memcpy(TasmotaGlobal.log_data, syslog_preamble, strlen(syslog_preamble));
PortUdp_write(TasmotaGlobal.log_data, strlen(TasmotaGlobal.log_data));
PortUdp.endPacket();
delay(1); // Add time for UDP handling (#5512)
delay(1); // Add time for UDP handling (#5512)
} else {
TasmotaGlobal.syslog_level = 0;
TasmotaGlobal.syslog_timer = SYSLOG_TIMER;
@ -1950,8 +1924,57 @@ void Syslog(void)
}
}
void AddLog(uint32_t loglevel)
{
void SyslogAsync(void) {
static uint32_t counter = 1;
if (!TasmotaGlobal.syslog_level ||
(counter == TasmotaGlobal.web_log_index) ||
TasmotaGlobal.global_state.network_down) { return; }
do {
char* tmp;
size_t len;
uint32_t loglevel = GetLog(counter, &tmp, &len);
if ((len > 13) &&
(loglevel <= TasmotaGlobal.syslog_level) &&
(TasmotaGlobal.masterlog_level <= TasmotaGlobal.syslog_level)) {
strlcpy(TasmotaGlobal.log_data, tmp +13, len -13); // Skip mxtime
Syslog();
}
counter++;
counter &= 0xFF;
if (!counter) { counter++; } // Skip 0 as it is not allowed
} while (counter != TasmotaGlobal.web_log_index);
}
uint32_t GetLog(uint32_t idx, char** entry_pp, size_t* len_p) {
char* entry_p = nullptr;
size_t len = 0;
uint32_t loglevel = 0;
if (idx) {
char* it = TasmotaGlobal.web_log;
do {
uint32_t cur_idx = *it;
it++;
size_t tmp = strchrspn(it, '\1');
tmp++; // Skip terminating '\1'
if (cur_idx == idx) { // Found the requested entry
loglevel = *it - '0';
it++; // Skip loglevel
len = tmp -1;
entry_p = it;
break;
}
it += tmp;
} while (it < TasmotaGlobal.web_log + WEB_LOG_SIZE && *it != '\0');
}
*entry_pp = entry_p;
*len_p = len;
return loglevel;
}
void AddLog(uint32_t loglevel) {
// char mxtime[10]; // "13:45:21 "
// snprintf_P(mxtime, sizeof(mxtime), PSTR("%02d" D_HOUR_MINUTE_SEPARATOR "%02d" D_MINUTE_SECOND_SEPARATOR "%02d "), RtcTime.hour, RtcTime.minute, RtcTime.second);
char mxtime[14]; // "13:45:21.999 "
@ -1961,41 +1984,34 @@ void AddLog(uint32_t loglevel)
(TasmotaGlobal.masterlog_level <= TasmotaGlobal.seriallog_level)) {
Serial.printf("%s%s\r\n", mxtime, TasmotaGlobal.log_data);
}
#ifdef USE_WEBSERVER
if (Settings.webserver &&
(loglevel <= Settings.weblog_level) &&
(TasmotaGlobal.masterlog_level <= Settings.weblog_level)) {
uint32_t highest_loglevel = Settings.weblog_level;
if (Settings.mqttlog_level > highest_loglevel) { highest_loglevel = Settings.mqttlog_level; }
if (TasmotaGlobal.syslog_level > highest_loglevel) { highest_loglevel = TasmotaGlobal.syslog_level; }
if ((loglevel <= highest_loglevel) && // Log only when needed
(TasmotaGlobal.masterlog_level <= highest_loglevel)) {
// Delimited, zero-terminated buffer of log lines.
// Each entry has this format: [index][log data]['\1']
// Each entry has this format: [index][loglevel][log data]['\1']
TasmotaGlobal.web_log_index &= 0xFF;
if (!TasmotaGlobal.web_log_index) {
TasmotaGlobal.web_log_index++; // Index 0 is not allowed as it is the end of char string
TasmotaGlobal.web_log_index++; // Index 0 is not allowed as it is the end of char string
}
while (TasmotaGlobal.web_log_index == TasmotaGlobal.web_log[0] || // If log already holds the next index, remove it
strlen(TasmotaGlobal.web_log) + strlen(TasmotaGlobal.log_data) + strlen(mxtime) + 4 > WEB_LOG_SIZE) // 4 = web_log_index + '\1' + '\0'
{
char* it = TasmotaGlobal.web_log;
it++; // Skip web_log_index
it += strchrspn(it, '\1'); // Skip log line
it++; // Skip delimiting "\1"
it++; // Skip web_log_index
it += strchrspn(it, '\1'); // Skip log line
it++; // Skip delimiting "\1"
memmove(TasmotaGlobal.web_log, it, WEB_LOG_SIZE -(it-TasmotaGlobal.web_log)); // Move buffer forward to remove oldest log line
}
snprintf_P(TasmotaGlobal.web_log, sizeof(TasmotaGlobal.web_log), PSTR("%s%c%s%s\1"), TasmotaGlobal.web_log, TasmotaGlobal.web_log_index++, mxtime, TasmotaGlobal.log_data);
snprintf_P(TasmotaGlobal.web_log, sizeof(TasmotaGlobal.web_log), PSTR("%s%c%c%s%s\1"),
TasmotaGlobal.web_log, TasmotaGlobal.web_log_index++, '0'+loglevel, mxtime, TasmotaGlobal.log_data);
TasmotaGlobal.web_log_index &= 0xFF;
if (!TasmotaGlobal.web_log_index) {
TasmotaGlobal.web_log_index++; // Index 0 is not allowed as it is the end of char string
TasmotaGlobal.web_log_index++; // Index 0 is not allowed as it is the end of char string
}
}
#endif // USE_WEBSERVER
if (Settings.flag.mqtt_enabled && // SetOption3 - Enable MQTT
!TasmotaGlobal.global_state.mqtt_down &&
(loglevel <= Settings.mqttlog_level) &&
(TasmotaGlobal.masterlog_level <= Settings.mqttlog_level)) { MqttPublishLogging(mxtime); }
if (!TasmotaGlobal.global_state.network_down &&
(loglevel <= TasmotaGlobal.syslog_level) &&
(TasmotaGlobal.masterlog_level <= TasmotaGlobal.syslog_level)) { Syslog(); }
TasmotaGlobal.prepped_loglevel = 0;
}

View File

@ -392,7 +392,7 @@ void RtcSecond(void)
Rtc.standard_time = RuleToTime(Settings.tflag[0], RtcTime.year);
// Do not use AddLog_P( here (interrupt routine) if syslog or mqttlog is enabled. UDP/TCP will force exception 9
PrepLog_P(LOG_LEVEL_DEBUG, PSTR("RTC: " D_UTC_TIME " %s, " D_DST_TIME " %s, " D_STD_TIME " %s"),
AddLog_P(LOG_LEVEL_DEBUG, PSTR("RTC: " D_UTC_TIME " %s, " D_DST_TIME " %s, " D_STD_TIME " %s"),
GetDateAndTime(DT_UTC).c_str(), GetDateAndTime(DT_DST).c_str(), GetDateAndTime(DT_STD).c_str());
if (Rtc.local_time < START_VALID_TIME) { // 2016-01-01
@ -407,7 +407,7 @@ void RtcSecond(void)
if ((Rtc.utc_time > (2 * 60 * 60)) && (last_sync < Rtc.utc_time - (2 * 60 * 60))) { // Every two hours a warning
// Do not use AddLog_P( here (interrupt routine) if syslog or mqttlog is enabled. UDP/TCP will force exception 9
PrepLog_P(LOG_LEVEL_DEBUG, PSTR("RTC: Not synced"));
AddLog_P(LOG_LEVEL_DEBUG, PSTR("RTC: Not synced"));
last_sync = Rtc.utc_time;
}

View File

@ -845,6 +845,9 @@ void PerformEverySecond(void)
}
}
MqttPublishLoggingAsync();
SyslogAsync();
ResetGlobalValues();
if (Settings.tele_period) {

View File

@ -3028,8 +3028,10 @@ void HandleHttpCommand(void)
do {
char* tmp;
size_t len;
GetLog(counter, &tmp, &len);
if (len) {
uint32_t loglevel = GetLog(counter, &tmp, &len);
if ((len > 0) &&
(loglevel <= Settings.weblog_level) &&
(TasmotaGlobal.masterlog_level <= Settings.weblog_level)) {
// [14:49:36 MQTT: stat/wemos5/RESULT = {"POWER":"OFF"}] > [{"POWER":"OFF"}]
char* JSON = (char*)memchr(tmp, '{', len);
if (JSON) { // Is it a JSON message (and not only [15:26:08 MQT: stat/wemos5/POWER = O])
@ -3105,8 +3107,10 @@ void HandleConsoleRefresh(void)
do {
char* tmp;
size_t len;
GetLog(counter, &tmp, &len);
if (len) {
uint32_t loglevel = GetLog(counter, &tmp, &len);
if ((len > 0) &&
(loglevel <= Settings.weblog_level) &&
(TasmotaGlobal.masterlog_level <= Settings.weblog_level)) {
if (len > sizeof(TasmotaGlobal.mqtt_data) -2) { len = sizeof(TasmotaGlobal.mqtt_data); }
char stemp[len +1];
strlcpy(stemp, tmp, len);

View File

@ -291,18 +291,30 @@ void MqttUnsubscribe(const char *topic)
MqttUnsubscribeLib(topic);
}
void MqttPublishLogging(const char *mxtime)
{
char saved_mqtt_data[strlen(TasmotaGlobal.mqtt_data) +1];
memcpy(saved_mqtt_data, TasmotaGlobal.mqtt_data, sizeof(saved_mqtt_data));
void MqttPublishLoggingAsync(void) {
static uint32_t counter = 1;
// ResponseTime_P(PSTR(",\"Log\":{\"%s\"}}"), TasmotaGlobal.log_data); // Will fail as some messages contain JSON
Response_P(PSTR("%s%s"), mxtime, TasmotaGlobal.log_data); // No JSON and ugly!!
char stopic[TOPSZ];
GetTopic_P(stopic, STAT, TasmotaGlobal.mqtt_topic, PSTR("LOGGING"));
MqttPublishLib(stopic, false);
if (!Settings.flag.mqtt_enabled || // SetOption3 - Enable MQTT
!Settings.mqttlog_level ||
(counter == TasmotaGlobal.web_log_index) ||
TasmotaGlobal.global_state.mqtt_down) { return; }
memcpy(TasmotaGlobal.mqtt_data, saved_mqtt_data, sizeof(saved_mqtt_data));
do {
char* tmp;
size_t len;
uint32_t loglevel = GetLog(counter, &tmp, &len);
if ((len > 0) &&
(loglevel <= Settings.mqttlog_level) &&
(TasmotaGlobal.masterlog_level <= Settings.mqttlog_level)) {
strlcpy(TasmotaGlobal.mqtt_data, tmp, len); // No JSON and ugly!!
char stopic[TOPSZ];
GetTopic_P(stopic, STAT, TasmotaGlobal.mqtt_topic, PSTR("LOGGING"));
MqttPublishLib(stopic, false);
}
counter++;
counter &= 0xFF;
if (!counter) { counter++; } // Skip 0 as it is not allowed
} while (counter != TasmotaGlobal.web_log_index);
}
void MqttPublish(const char* topic, bool retained)

View File

@ -298,8 +298,10 @@ String TelegramExecuteCommand(const char *svalue) {
do {
char* tmp;
size_t len;
GetLog(counter, &tmp, &len);
if (len) {
uint32_t loglevel = GetLog(counter, &tmp, &len);
if ((len > 0) &&
(loglevel <= Settings.weblog_level) &&
(TasmotaGlobal.masterlog_level <= Settings.weblog_level)) {
// [14:49:36 MQTT: stat/wemos5/RESULT = {"POWER":"OFF"}] > [{"POWER":"OFF"}]
char* JSON = (char*)memchr(tmp, '{', len);
if (JSON) { // Is it a JSON message (and not only [15:26:08 MQT: stat/wemos5/POWER = O])