rusefi
/
rusefi
mirror of https://github.com/rusefi/rusefi.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

Revert "logging simplification: switch bare functions to member functions (#1788)" 

This reverts commit d941bdc5
This commit is contained in:
rusefi 2020-09-12 04:36:24 -04:00
parent d38cb3fabe
commit 256a4a2637
14 changed files with 165 additions and 119 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
firmware/console/status_loop.cpp
View File

@ -176,7 +176,7 @@ static systime_t timeOfPreviousPrintVersion = (systime_t) -1;
#if EFI_PROD_CODE
static void printOutPin(const char *pinName, brain_pin_e hwPin) {
if (hwPin != GPIO_UNASSIGNED) {
logger.appendPrintf("%s%s%s@%s%s", PROTOCOL_OUTPIN, DELIMETER, pinName, hwPortname(hwPin), DELIMETER);
appendPrintf(&logger, "%s%s%s@%s%s", PROTOCOL_OUTPIN, DELIMETER, pinName, hwPortname(hwPin), DELIMETER);
}
}
#endif /* EFI_PROD_CODE */

4
firmware/controllers/core/error_handling.cpp
View File

@ -119,7 +119,7 @@ static void printToStream(MemoryStream *stream, const char *fmt, va_list ap) {
}
static void printWarning(const char *fmt, va_list ap) {
logger.reset(); // todo: is 'reset' really needed here?
resetLogging(&logger); // todo: is 'reset' really needed here?
appendMsgPrefix(&logger);
logger.append(WARNING_PREFIX);
@ -137,7 +137,7 @@ static void printWarning(const char *fmt, va_list ap) {
}
logger.append(warningBuffer);
logger.append(DELIMETER);
append(&logger, DELIMETER);
scheduleLogging(&logger);
}

33
firmware/development/engine_sniffer.cpp
View File

@ -58,7 +58,7 @@ int waveChartUsedSize;
//#define DEBUG_WAVE 1
#if DEBUG_WAVE
static LoggingWithStorage debugLogging("debug");
static Logging debugLogging;
#endif /* DEBUG_WAVE */
static LoggingWithStorage logger("wave info");
@ -76,10 +76,11 @@ static void resetNow(void) {
}
#endif
WaveChart::WaveChart() : logging("wave chart", WAVE_LOGGING_BUFFER, sizeof(WAVE_LOGGING_BUFFER)) {
WaveChart::WaveChart() {
}
void WaveChart::init() {
logging.initLoggingExt("wave chart", WAVE_LOGGING_BUFFER, sizeof(WAVE_LOGGING_BUFFER));
isInitialized = true;
reset();
}
@ -88,11 +89,11 @@ void WaveChart::reset() {
#if DEBUG_WAVE
scheduleSimpleMsg(&debugLogging, "reset while at ", counter);
#endif /* DEBUG_WAVE */
logging.reset();
resetLogging(&logging);
counter = 0;
startTimeNt = 0;
collectingData = false;
logging.appendPrintf( "%s%s", PROTOCOL_ENGINE_SNIFFER, DELIMETER);
appendPrintf(&logging, "%s%s", PROTOCOL_ENGINE_SNIFFER, DELIMETER);
}
void WaveChart::startDataCollection() {
@ -143,8 +144,8 @@ void WaveChart::publishIfFull() {
}
void WaveChart::publish() {
logging.appendPrintf( DELIMETER);
waveChartUsedSize = logging.loggingSize();
appendPrintf(&logging, DELIMETER);
waveChartUsedSize = loggingSize(&logging);
#if DEBUG_WAVE
Logging *l = &chart->logging;
scheduleSimpleMsg(&debugLogging, "IT'S TIME", strlen(l->buffer));
@ -210,20 +211,20 @@ void WaveChart::addEvent3(const char *name, const char * msg) {
uint32_t diffNt = nowNt - startTimeNt;
uint32_t time100 = NT2US(diffNt / ENGINE_SNIFFER_UNIT_US);
if (logging.remainingSize() > 35) {
if (remainingSize(&logging) > 35) {
/**
* printf is a heavy method, append is used here as a performance optimization
*/
logging.appendFast(name);
logging.appendChar(CHART_DELIMETER);
logging.appendFast(msg);
logging.appendChar(CHART_DELIMETER);
appendFast(&logging, name);
appendChar(&logging, CHART_DELIMETER);
appendFast(&logging, msg);
appendChar(&logging, CHART_DELIMETER);
// time100 -= startTime100;
itoa10(timeBuffer, time100);
logging.appendFast(timeBuffer);
logging.appendChar(CHART_DELIMETER);
logging.appendChar('\0');
appendFast(&logging, timeBuffer);
appendChar(&logging, CHART_DELIMETER);
logging.linePointer[0] = 0;
}
if (!alreadyLocked) {
unlockOutputBuffer();
@ -239,6 +240,10 @@ void initWaveChart(WaveChart *chart) {
printStatus();
#if DEBUG_WAVE
initLoggingExt(&debugLogging, "wave chart debug", &debugLogging.DEFAULT_BUFFER, sizeof(debugLogging.DEFAULT_BUFFER));
#endif
#if EFI_HISTOGRAMS
initHistogram(&engineSnifferHisto, "wave chart");
#endif /* EFI_HISTOGRAMS */

30
firmware/development/logic_analyzer.cpp
View File

@ -171,38 +171,38 @@ static void reportWave(Logging *logging, int index) {
float dwellMs = getSignalOnTime(index);
float periodMs = getSignalPeriodMs(index);
logging->appendPrintf("duty%d%s", index, DELIMETER);
logging->appendFloat(100.0f * dwellMs / periodMs, 2);
logging->appendPrintf("%s", DELIMETER);
appendPrintf(logging, "duty%d%s", index, DELIMETER);
appendFloat(logging, 100.0f * dwellMs / periodMs, 2);
appendPrintf(logging, "%s", DELIMETER);
/**
* that's the ON time of the LAST signal
*/
logging->appendPrintf("dwell%d%s", index, DELIMETER);
logging->appendFloat(dwellMs, 2);
logging->appendPrintf("%s", DELIMETER);
appendPrintf(logging, "dwell%d%s", index, DELIMETER);
appendFloat(logging, dwellMs, 2);
appendPrintf(logging, "%s", DELIMETER);
/**
* that's the total ON time during the previous engine cycle
*/
logging->appendPrintf("total_dwell%d%s", index, DELIMETER);
logging->appendFloat(readers[index].prevTotalOnTimeUs / 1000.0f, 2);
logging->appendPrintf("%s", DELIMETER);
appendPrintf(logging, "total_dwell%d%s", index, DELIMETER);
appendFloat(logging, readers[index].prevTotalOnTimeUs / 1000.0f, 2);
appendPrintf(logging, "%s", DELIMETER);
logging->appendPrintf("period%d%s", index, DELIMETER);
logging->appendFloat(periodMs, 2);
logging->appendPrintf("%s", DELIMETER);
appendPrintf(logging, "period%d%s", index, DELIMETER);
appendFloat(logging, periodMs, 2);
appendPrintf(logging, "%s", DELIMETER);
uint32_t offsetUs = getWaveOffset(index);
int rpm = GET_RPM();
if (rpm != 0) {
float oneDegreeUs = getOneDegreeTimeUs(rpm);
logging->appendPrintf("advance%d%s", index, DELIMETER);
appendPrintf(logging, "advance%d%s", index, DELIMETER);
float angle = (offsetUs / oneDegreeUs) - tdcPosition();
fixAngle(angle, "waveAn", CUSTOM_ERR_6564);
logging->appendFloat(angle, 3);
logging->appendPrintf("%s", DELIMETER);
appendFloat(logging, angle, 3);
appendPrintf(logging, "%s", DELIMETER);
}
}
}

10
firmware/development/sensor_chart.cpp
View File

@ -49,7 +49,7 @@ void scAddData(float angle, float value) {
* data after we have added some data - meaning it's time to flush
*/
// message terminator
scLogging.appendPrintf(DELIMETER);
appendPrintf(&scLogging, DELIMETER);
// output pending data
scheduleLogging(&scLogging);
pendingData = false;
@ -58,13 +58,13 @@ void scAddData(float angle, float value) {
}
if (!pendingData) {
pendingData = true;
scLogging.reset();
resetLogging(&scLogging);
// message header
scLogging.appendPrintf( "%s%s", PROTOCOL_ANALOG_CHART, DELIMETER);
appendPrintf(&scLogging, "%s%s", PROTOCOL_ANALOG_CHART, DELIMETER);
}
if (scLogging.remainingSize() > 100) {
scLogging.appendPrintf( "%.2f|%.2f|", angle, value);
if (remainingSize(&scLogging) > 100) {
appendPrintf(&scLogging, "%.2f|%.2f|", angle, value);
}
#endif /* EFI_TEXT_LOGGING */
}

12
firmware/hw_layer/adc/adc_inputs.cpp
View File

@ -385,10 +385,10 @@ static void printFullAdcReport(Logging *logger) {
int pin = getAdcChannelPin(hwIndex);
int adcValue = getAvgAdcValue(hwIndex, fastAdc.samples, ADC_BUF_DEPTH_FAST, fastAdc.size());
logger->appendPrintf(" F ch%d %s%d", index, portname(port), pin);
logger->appendPrintf(" ADC%d 12bit=%d", hwIndex, adcValue);
appendPrintf(logger, " F ch%d %s%d", index, portname(port), pin);
appendPrintf(logger, " ADC%d 12bit=%d", hwIndex, adcValue);
float volts = adcToVolts(adcValue);
logger->appendPrintf(" v=%.2f", volts);
appendPrintf(logger, " v=%.2f", volts);
appendMsgPostfix(logger);
scheduleLogging(logger);
@ -405,10 +405,10 @@ static void printFullAdcReport(Logging *logger) {
int pin = getAdcChannelPin(hwIndex);
int adcValue = slowAdc.getAdcValueByIndex(index);
logger->appendPrintf(" S ch%d %s%d", index, portname(port), pin);
logger->appendPrintf(" ADC%d 12bit=%d", hwIndex, adcValue);
appendPrintf(logger, " S ch%d %s%d", index, portname(port), pin);
appendPrintf(logger, " ADC%d 12bit=%d", hwIndex, adcValue);
float volts = adcToVolts(adcValue);
logger->appendPrintf(" v=%.2f", volts);
appendPrintf(logger, " v=%.2f", volts);
appendMsgPostfix(logger);
scheduleLogging(logger);

2
firmware/hw_layer/rtc_helper.cpp
View File

@ -145,7 +145,7 @@ void printDateTime(void) {
date_get_tm(&timp);
appendMsgPrefix(&logger);
logger.appendPrintf( "Current RTC localtime is: %04u-%02u-%02u %02u:%02u:%02u w=%d", timp.tm_year + 1900, timp.tm_mon + 1, timp.tm_mday, timp.tm_hour,
appendPrintf(&logger, "Current RTC localtime is: %04u-%02u-%02u %02u:%02u:%02u w=%d", timp.tm_year + 1900, timp.tm_mon + 1, timp.tm_mday, timp.tm_hour,
timp.tm_min, timp.tm_sec, rtcWorks);
appendMsgPostfix(&logger);
scheduleLogging(&logger);

107
firmware/util/datalogging.cpp
View File

@ -73,22 +73,26 @@ static IntermediateLogging intermediateLogging;
/**
* @returns true if data does not fit into this buffer
*/
bool Logging::validateBuffer(const char *text, uint32_t extraLen) {
if (remainingSize() < extraLen + 1) {
#if EFI_PROD_CODE
const char * msg = extraLen > 50 ? "(long)" : text;
warning(CUSTOM_LOGGING_BUFFER_OVERFLOW, "output overflow %s %d [%s]", name, extraLen, msg);
#endif /* EFI_PROD_CODE */
static ALWAYS_INLINE bool validateBuffer(Logging *logging, const char *text, uint32_t extraLen) {
if (logging->buffer == NULL) {
firmwareError(CUSTOM_ERR_LOGGING_NOT_READY, "Logging not initialized: %s", logging->name);
return true;
}
if (remainingSize(logging) < extraLen + 1) {
#if EFI_PROD_CODE
const char * msg = extraLen > 50 ? "(long)" : text;
warning(CUSTOM_LOGGING_BUFFER_OVERFLOW, "output overflow %s %d [%s]", logging->name, extraLen, msg);
#endif /* EFI_PROD_CODE */
return true;
}
return false;
}
void Logging::append(const char *text) {
efiAssertVoid(CUSTOM_APPEND_NULL, text != NULL, "append NULL");
uint32_t extraLen = efiStrlen(text);
bool isCapacityProblem = validateBuffer(text, extraLen);
bool isCapacityProblem = validateBuffer(this, text, extraLen);
if (isCapacityProblem) {
return;
}
@ -99,14 +103,20 @@ void Logging::append(const char *text) {
linePointer += extraLen;
}
// todo: inline
void append(Logging *logging, const char *text) {
logging->append(text);
}
/**
* @note This method if fast because it does not validate much, be sure what you are doing
*/
void Logging::appendFast(const char *text) {
char *s = linePointer;
void appendFast(Logging *logging, const char *text) {
char *s;
s = logging->linePointer;
while ((*s++ = *text++) != 0)
;
linePointer = s - 1;
logging->linePointer = s - 1;
}
/**
@ -128,6 +138,15 @@ void Logging::vappendPrintf(const char *fmt, va_list arg) {
#endif // EFI_UNIT_TEST
}
// todo: replace with logging->appendPrintf
void appendPrintf(Logging *logging, const char *fmt, ...) {
efiAssertVoid(CUSTOM_APPEND_STACK, getCurrentRemainingStack() > 128, "lowstck#4");
va_list ap;
va_start(ap, fmt);
logging->vappendPrintf(fmt, ap);
va_end(ap);
}
void Logging::appendPrintf(const char *fmt, ...) {
#if EFI_UNIT_TEST
va_list ap;
@ -143,7 +162,19 @@ void Logging::appendPrintf(const char *fmt, ...) {
#endif // EFI_UNIT_TEST
}
void Logging::appendFloat(float value, int precision) {
void Logging::initLoggingExt(const char *name, char *buffer, int bufferSize) {
this->name = name;
this->buffer = buffer;
this->bufferSize = bufferSize;
resetLogging(this);
this->isInitialized = true;
}
int isInitialized(Logging *logging) {
return logging->isInitialized;
}
void appendFloat(Logging *logging, float value, int precision) {
/**
* todo: #1 this implementation is less than perfect
* todo: #2 The only way to avoid double promotion would probably be using *float instead of float
@ -151,26 +182,26 @@ void Logging::appendFloat(float value, int precision) {
*/
switch (precision) {
case 1:
appendPrintf("%.1f", value);
appendPrintf(logging, "%.1f", value);
break;
case 2:
appendPrintf("%.2f", value);
appendPrintf(logging, "%.2f", value);
break;
case 3:
appendPrintf("%.3f", value);
appendPrintf(logging, "%.3f", value);
break;
case 4:
appendPrintf("%.4f", value);
appendPrintf(logging, "%.4f", value);
break;
case 5:
appendPrintf("%.5f", value);
appendPrintf(logging, "%.5f", value);
break;
case 6:
appendPrintf("%.6f", value);
appendPrintf(logging, "%.6f", value);
break;
default:
appendPrintf("%.2f", value);
appendPrintf(logging, "%.2f", value);
}
}
@ -179,7 +210,7 @@ static char header[16];
/**
* this method should invoked on the main thread only
*/
static void printWithLength(char *line) {
void printWithLength(char *line) {
#if ! EFI_UNIT_TEST
int len;
char *p;
@ -217,16 +248,21 @@ static void printWithLength(char *line) {
}
void appendMsgPrefix(Logging *logging) {
logging->append(PROTOCOL_MSG DELIMETER);
append(logging, PROTOCOL_MSG DELIMETER);
}
void appendMsgPostfix(Logging *logging) {
logging->append(DELIMETER);
append(logging, DELIMETER);
}
void Logging::reset() {
linePointer = buffer;
*linePointer = 0;
void resetLogging(Logging *logging) {
char *buffer = logging->buffer;
if (buffer == NULL) {
firmwareError(ERROR_NULL_BUFFER, "Null buffer: %s", logging->name);
return;
}
logging->linePointer = buffer;
logging->linePointer[0] = 0;
}
/**
@ -243,17 +279,24 @@ void printMsg(Logging *logger, const char *fmt, ...) {
logger->vappendPrintf(fmt, ap);
va_end(ap);
logger->append(DELIMETER);
append(logger, DELIMETER);
printWithLength(logger->buffer);
logger->reset();
resetLogging(logger);
}
Logging::Logging(char const *name, char *buffer, int bufferSize)
: name(name)
, buffer(buffer)
, bufferSize(bufferSize)
{
reset();
uint32_t remainingSize(Logging *logging) {
return logging->bufferSize - loggingSize(logging);
}
Logging::Logging() {
}
Logging::Logging(char const *name, char *buffer, int bufferSize) : Logging() {
#if ! EFI_UNIT_TEST
initLoggingExt(name, buffer, bufferSize);
#else
this->buffer = buffer;
#endif /* ! EFI_UNIT_TEST */
}
LoggingWithStorage::LoggingWithStorage(const char *name) : Logging(name, DEFAULT_BUFFER, sizeof(DEFAULT_BUFFER)) {

58
firmware/util/datalogging.h
View File

@ -17,51 +17,28 @@
// size of buffers?
class Logging {
public:
Logging() = delete;
Logging();
Logging(const char *name, char *buffer, int bufferSize);
void reset();
void initLoggingExt(const char *name, char *buffer, int bufferSize);
void vappendPrintf(const char *fmt, va_list arg);
void append(const char *text);
void appendFast(const char *text);
void appendPrintf(const char *fmt, ...);
void appendFloat(float value, int precision);
/**
* This macro breaks the normal zero=termination constraint, please take care of this outside of this function
*/
void appendChar(char c) {
*linePointer = c;
linePointer++;
}
size_t loggingSize() const {
return (uintptr_t)linePointer - (uintptr_t)buffer;
}
size_t remainingSize() const {
return bufferSize - loggingSize();
}
//private:
bool validateBuffer(const char *text, uint32_t extraLen);
const char* const name = nullptr;
const char *name = nullptr;
char SMALL_BUFFER[40];
/**
* Zero-terminated buffer of pending debug message
*
* Unless a larger external buffer is specified, this is just a pointer to DEFAULT_BUFFER
*/
char* const buffer = nullptr;
const int bufferSize = 0;
char *buffer = nullptr;
/**
* This pointer is always pointing at the position within the buffer into which next
* write operation would append additional data
*/
char *linePointer = nullptr;
int bufferSize = 0;
volatile bool isInitialized = false;
};
class LoggingWithStorage : public Logging {
@ -70,8 +47,14 @@ public:
char DEFAULT_BUFFER[200];
};
int isInitialized(Logging *logging);
void initLoggingExt(Logging *logging, const char *name, char *buffer, int bufferSize);
void appendFloat(Logging *logging, float value, int precision);
void resetLogging(Logging *logging);
void appendMsgPrefix(Logging *logging);
void appendMsgPostfix(Logging *logging);
@ -84,7 +67,20 @@ extern "C"
#define lockOutputBuffer lockAnyContext
#define unlockOutputBuffer unlockAnyContext
uint32_t remainingSize(Logging *logging);
#define loggingSize(logging) ((int) (logging)->linePointer - (int) ((logging)->buffer))
void printMsg(Logging *logging, const char *fmt, ...);
void appendPrintf(Logging *logging, const char *fmt, ...);
void append(Logging *logging, const char *text);
void appendFast(Logging *logging, const char *text);
/**
* This macro breaks the normal zero=termination constraint, please take care of this outside of this macro
*/
#define appendChar(logging, symbol) {(logging)->linePointer[0] = (symbol);(logging)->linePointer++;}
/**
* this method copies the line into the intermediate buffer for later output by
@ -95,3 +91,5 @@ void scheduleLogging(Logging *logging);
#ifdef __cplusplus
}
#endif /* __cplusplus */
void printWithLength(char *line);

8
firmware/util/efilib.cpp
View File

@ -312,12 +312,12 @@ void printHistogram(Logging *logging, histogram_s *histogram) {
int report[5];
int len = hsReport(histogram, report);
logging->reset();
resetLogging(logging);
appendMsgPrefix(logging);
logging.appendPrintf("histogram %s *", histogram->name);
appendPrintf(logging, "histogram %s *", histogram->name);
for (int i = 0; i < len; i++)
logging.appendPrintf("%d ", report[i]);
logging.appendPrintf("*");
appendPrintf(logging, "%d ", report[i]);
appendPrintf(logging, "*");
appendMsgPostfix(logging);
scheduleLogging(logging);
#else

6
firmware/util/loggingcentral.cpp
View File

@ -82,7 +82,7 @@ void scheduleLogging(Logging *logging) {
if (!alreadyLocked) {
unlockOutputBuffer();
}
logging->reset();
resetLogging(logging);
return;
}
// memcpy is faster then strcpy because it is not looking for line terminator
@ -91,7 +91,7 @@ void scheduleLogging(Logging *logging) {
if (!alreadyLocked) {
unlockOutputBuffer();
}
logging->reset();
resetLogging(logging);
#endif /* EFI_TEXT_LOGGING */
}
@ -167,7 +167,7 @@ void scheduleMsg(Logging *logging, const char *format, ...) {
return;
}
int wasLocked = lockAnyContext();
logging->reset(); // todo: is 'reset' really needed here?
resetLogging(logging); // todo: is 'reset' really needed here?
appendMsgPrefix(logging);
va_list ap;

8
simulator/simulator/rusEfiFunctionalTest.cpp
View File

@ -69,20 +69,20 @@ static void runChprintfTest() {
{
LoggingWithStorage testLogging("test");
testLogging.appendFloat(1.23, 5);
testLogging.appendFloat(1.234, 2);
appendFloat(&testLogging, 1.23, 5);
appendFloat(&testLogging, 1.234, 2);
assertString(testLogging.buffer, "1.230001.23");
}
{
LoggingWithStorage testLogging("test");
testLogging.appendFloat(-1.23, 5);
appendFloat(&testLogging, -1.23, 5);
assertString(testLogging.buffer, "-1.23000");
}
{
LoggingWithStorage testLogging("test");
testLogging.appendPrintf( "a%.2fb%fc", -1.2, -3.4);
appendPrintf(&testLogging, "a%.2fb%fc", -1.2, -3.4);
assertString(testLogging.buffer, "a-1.20b-3.400000095c");
}

2
unit_tests/tests/test_accel_enrichment.cpp
View File

@ -104,7 +104,7 @@ TEST(fuel, testAccelEnrichmentFractionalTps) {
}
}
LoggingWithStorage logger("test");
Logging logger;
initAccelEnrichment(&logger PASS_ENGINE_PARAMETER_SUFFIX);
engine->rpmCalculator.setRpmValue(600);

2
unit_tests/tests/test_pid_auto.cpp
View File

@ -16,7 +16,7 @@ efitimems_t currentTimeMillis(void) {
return mockTimeMs;
}
LoggingWithStorage logging("test");
Logging logging;
static float zigZagOffset = 0;