time routines refactor (#4563)

* Extract time helpers from engine_controller_misc to efitime.cpp

* Rename currentTimeMillis() to getTimeNowMs()

We have getTimeNowNt(), getTimeNowUs(), currentTimeMillis() and getTimeNowSeconds()
Align a bit.

find . -type f -name '*.c*' -exec sed -i 's/currentTimeMillis/getTimeNowMs/g' {} \;

* Rename getTimeNowSeconds() to getTimeNowS()

To align with Nt, Us, Ms versions.

* Some comments about getTimeNowLowerNt()
This commit is contained in:
Andrey G 2022-09-11 20:06:03 +03:00 committed by GitHub
parent 0780a3f719
commit 1ca5988877
21 changed files with 126 additions and 115 deletions

View File

@ -230,7 +230,7 @@ void TunerStudio::handleWriteValueCommand(TsChannelBase* tsChannel, ts_response_
return;
}
efitimems_t nowMs = currentTimeMillis();
efitimems_t nowMs = getTimeNowMs();
if (nowMs - previousWriteReportMs > 5) {
previousWriteReportMs = nowMs;
efiPrintf("offset %d: value=%d", offset, value);
@ -294,7 +294,7 @@ static void sendResponseCode(ts_response_format_e mode, TsChannelBase *tsChannel
* 'Burn' command is a command to commit the changes
*/
static void handleBurnCommand(TsChannelBase* tsChannel, ts_response_format_e mode) {
efitimems_t nowMs = currentTimeMillis();
efitimems_t nowMs = getTimeNowMs();
tsState.burnCommandCounter++;
efiPrintf("got B (Burn) %s", mode == TS_PLAIN ? "plain" : "CRC");
@ -305,7 +305,7 @@ static void handleBurnCommand(TsChannelBase* tsChannel, ts_response_format_e mod
}
sendResponseCode(mode, tsChannel, TS_RESPONSE_BURN_OK);
efiPrintf("BURN in %dms", currentTimeMillis() - nowMs);
efiPrintf("BURN in %dms", getTimeNowMs() - nowMs);
}
#if EFI_TUNER_STUDIO && (EFI_PROD_CODE || EFI_SIMULATOR)
@ -342,7 +342,7 @@ static void handleTestCommand(TsChannelBase* tsChannel) {
chsnprintf(testOutputBuffer, sizeof(testOutputBuffer), " %d %d", engine->engineState.warnings.lastErrorCode, tsState.testCommandCounter);
tsChannel->write((const uint8_t*)testOutputBuffer, strlen(testOutputBuffer));
chsnprintf(testOutputBuffer, sizeof(testOutputBuffer), " uptime=%ds ", (int)getTimeNowSeconds());
chsnprintf(testOutputBuffer, sizeof(testOutputBuffer), " uptime=%ds ", (int)getTimeNowS());
tsChannel->write((const uint8_t*)testOutputBuffer, strlen(testOutputBuffer));
chsnprintf(testOutputBuffer, sizeof(testOutputBuffer), __DATE__ " %s\r\n", PROTOCOL_TEST_RESPONSE_TAG);

View File

@ -87,7 +87,7 @@ size_t writeBlock(char* buffer) {
buffer[2] = timestamp >> 8;
buffer[3] = timestamp & 0xFF;
packedTime = currentTimeMillis() * 1.0 / TIME_PRECISION;
packedTime = getTimeNowMs() * 1.0 / TIME_PRECISION;
// Offset 4 = field data
const char* dataBlockStart = buffer + 4;

View File

@ -158,7 +158,7 @@ static void printRusefiVersion(const char *engineTypeName, const char *firmwareB
getRusEfiVersion(), VCS_VERSION,
firmwareBuildId,
engineTypeName,
getTimeNowSeconds());
getTimeNowS());
}
// Inform the console about the mapping between a pin's logical name (for example, injector 3)
@ -270,7 +270,7 @@ void updateDevConsoleState(void) {
printFullAdcReportIfNeeded();
#endif /* HAL_USE_ADC */
systime_t nowSeconds = getTimeNowSeconds();
systime_t nowSeconds = getTimeNowS();
#if EFI_ENGINE_CONTROL && EFI_SHAFT_POSITION_INPUT
int currentCkpEventCounter = engine->triggerCentral.triggerState.getTotalEventCounter();
@ -761,7 +761,7 @@ void updateTunerStudioState() {
#endif
// 224
efitimesec_t timeSeconds = getTimeNowSeconds();
efitimesec_t timeSeconds = getTimeNowS();
tsOutputChannels->seconds = timeSeconds;
// 252

View File

@ -9,7 +9,7 @@ static Deadband<5> maxCltDeadband;
static Deadband<5> maxTpsDeadband;
bool AcController::getAcState() {
latest_usage_ac_control = getTimeNowSeconds();
latest_usage_ac_control = getTimeNowS();
auto rpm = Sensor::getOrZero(SensorType::Rpm);
engineTooSlow = rpm < 500;

View File

@ -236,7 +236,7 @@ void Engine::periodicSlowCallback() {
#if ANALOG_HW_CHECK_MODE
efiAssertVoid(OBD_PCM_Processor_Fault, isAdcChannelValid(engineConfiguration->clt.adcChannel), "No CLT setting");
efitimesec_t secondsNow = getTimeNowSeconds();
efitimesec_t secondsNow = getTimeNowS();
#if ! HW_CHECK_ALWAYS_STIMULATE
fail("HW_CHECK_ALWAYS_STIMULATE required to have self-stimulation")
@ -454,7 +454,7 @@ void Engine::efiWatchdog() {
if (engine->configBurnTimer.hasElapsedSec(5) && engineConfiguration->tempBooleanForVerySpecialLogic) {
static efitimems_t mostRecentMs = 0;
efitimems_t msNow = currentTimeMillis();
efitimems_t msNow = getTimeNowMs();
if (mostRecentMs != 0) {
efitimems_t gapInMs = msNow - mostRecentMs;
if (gapInMs > 500) {

View File

@ -163,21 +163,6 @@ class EngineStateBlinkingTask : public PeriodicTimerController {
static EngineStateBlinkingTask engineStateBlinkingTask;
/**
* 32 bit return type overflows in 23(or46?) days. tag#4554. I think we do not expect rusEFI to run for 23 days straight days any time soon?
*/
efitimems_t currentTimeMillis(void) {
return US2MS(getTimeNowUs());
}
/**
* Integer number of seconds since ECU boot.
* 31,710 years - would not overflow during our life span.
*/
efitimesec_t getTimeNowSeconds(void) {
return getTimeNowUs() / US_PER_SECOND;
}
static void resetAccel() {
engine->tpsAccelEnrichment.resetAE();

View File

@ -36,23 +36,6 @@ void irqExitHook() {}
void contextSwitchHook() {}
#endif /* ENABLE_PERF_TRACE */
#if !EFI_UNIT_TEST
/**
* 64-bit result would not overflow, but that's complex stuff for our 32-bit MCU
*/
efitimeus_t getTimeNowUs() {
ScopePerf perf(PE::GetTimeNowUs);
return NT2US(getTimeNowNt());
}
static WrapAround62 timeNt;
efitick_t getTimeNowNt() {
return timeNt.update(getTimeNowLowerNt());
}
#endif /* !EFI_UNIT_TEST */
static void onStartStopButtonToggle() {
engine->startStopStateToggleCounter++;

View File

@ -143,7 +143,7 @@ static void showLine(lcd_line_e line, int /*screenY*/) {
return;
case LL_RPM:
{
int seconds = minI(9999, getTimeNowSeconds());
int seconds = minI(9999, getTimeNowS());
lcdPrintf("RPM %d %d ", (int)Sensor::getOrZero(SensorType::Rpm), seconds);
}
#if EFI_FILE_LOGGING
@ -326,7 +326,7 @@ void updateHD44780lcd(void) {
// return;
// }
//
// int index = (getTimeNowSeconds() / 2) % (NUMBER_OF_DIFFERENT_LINES / 2);
// int index = (getTimeNowS() / 2) % (NUMBER_OF_DIFFERENT_LINES / 2);
//
// prepareCurrentSecondLine(engine, index);
// buffer[LCD_WIDTH] = 0;

View File

@ -49,7 +49,7 @@ void configureRusefiLuaUtilHooks(lua_State* l) {
/*
* todo: shall we? same for milliseconds?
lua_register(l, "getNowSeconds", [](lua_State* l) -> int {
int result = getTimeNowSeconds();
int result = getTimeNowS();
lua_pushnumber(l, result);
return 1;
});

View File

@ -139,7 +139,7 @@ bool PID_AutoTune::Runtime(Logging *logger)
this->logger = logger; // a bit lazy but good enough
// check ready for new input
unsigned long now = currentTimeMillis();
unsigned long now = getTimeNowMs();
if (state == AUTOTUNER_OFF)
{

View File

@ -641,7 +641,7 @@ expected<TriggerDecodeResult> TriggerDecoderBase::decodeTriggerEvent(
prefix,
triggerConfiguration.PrintPrefix,
(int)Sensor::getOrZero(SensorType::Rpm),
/* cast is needed to make sure we do not put 64 bit value to stack*/ (int)getTimeNowSeconds(),
/* cast is needed to make sure we do not put 64 bit value to stack*/ (int)getTimeNowS(),
currentCycle.current_index,
i,
gapOk ? "Y" : "n",

View File

@ -106,7 +106,7 @@ static void updateTriggerWaveformIfNeeded(PwmConfig *state) {
if (atTriggerVersion < engine->triggerCentral.triggerShape.version) {
atTriggerVersion = engine->triggerCentral.triggerShape.version;
efiPrintf("Stimulator: updating trigger shape: %d/%d %d", atTriggerVersion,
engine->getGlobalConfigurationVersion(), currentTimeMillis());
engine->getGlobalConfigurationVersion(), getTimeNowMs());
TriggerWaveform *s = &engine->triggerCentral.triggerShape;

View File

@ -23,26 +23,26 @@ static void testSystemCalls(const int count) {
time_t start, time;
long result = 0;
start = currentTimeMillis();
start = getTimeNowMs();
for (int i = 0; i < count / 2; i++) {
// setPinValue(&testOutput, 0);
// setPinValue(&testOutput, 1);
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
// Finished 100000 iterations of 'setPinValue()' in 120ms
// prin("Finished %d iterations of 'setPinValue()' in %dms\r\n", count, time);
start = currentTimeMillis();
start = getTimeNowMs();
for (int i = 0; i < count; i++)
result += chTimeNow();
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (result != 0) {
// Finished 100000 iterations of 'chTimeNow()' in 33ms
efiPrintf("Finished %d iterations of 'chTimeNow()' in %dms", count, time);
}
start = currentTimeMillis();
start = getTimeNowMs();
for (int i = 0; i < count; i++) {
chSysLock()
;
@ -50,18 +50,18 @@ static void testSystemCalls(const int count) {
chSysUnlock()
;
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (result != 0) {
// Finished 100000 iterations of 'chTimeNow()' with chSysLock in 144ms
efiPrintf("Finished %d iterations of 'chTimeNow()' with chSysLock in %dms", count, time);
}
start = currentTimeMillis();
start = getTimeNowMs();
for (int i = 0; i < count; i++)
result += currentTimeMillis();
time = currentTimeMillis() - start;
result += getTimeNowMs();
time = getTimeNowMs() - start;
if (result != 0)
efiPrintf("Finished %d iterations of 'currentTimeMillis' in %dms", count, time);
efiPrintf("Finished %d iterations of 'getTimeNowMs' in %dms", count, time);
}
static Engine testEngine;
@ -70,25 +70,25 @@ static void testRusefiMethods(const int count) {
time_t start, time;
int tempi = 1;
start = currentTimeMillis();
start = getTimeNowMs();
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (tempi != 0)
efiPrintf("Finished %d iterations of getBaseFuel in %dms", count, time);
// start = currentTimeMillis();
// start = getTimeNowMs();
// for (int i = 0; i < count; i++)
// tempi += getInjectionDuration(1200, NULL); // todo
// time = currentTimeMillis() - start;
// time = getTimeNowMs() - start;
// if (tempi != 0)
// efiPrintf("Finished %d iterations of getFuelMs in %dms", count, time);
start = currentTimeMillis();
start = getTimeNowMs();
for (int i = 0; i < count; i++) {
testEngine.updateSlowSensors();
tempi += testEngine.engineState.clt;
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (tempi != 0)
efiPrintf("Finished %d iterations of updateSlowSensors in %dms", count, time);
}
@ -97,37 +97,37 @@ static void testMath(const int count) {
time_t start, time;
int64_t temp64 = 0;
start = currentTimeMillis();
start = getTimeNowMs();
for (int64_t i = 0; i < count; i++) {
temp64 += i;
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (temp64 != 0) {
efiPrintf("Finished %d iterations of int64_t summation in %dms", count, time);
}
temp64 = 1;
start = currentTimeMillis();
start = getTimeNowMs();
for (int64_t i = 0; i < count; i++) {
temp64 *= i;
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (temp64 == 0) {
efiPrintf("Finished %d iterations of int64_t multiplication in %dms", count, time);
}
start = currentTimeMillis();
start = getTimeNowMs();
for (int i = 0; i < count; i++)
;
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
efiPrintf("Finished %d iterations of empty loop in %dms", count, time);
uint32_t tempi = 1;
start = currentTimeMillis();
start = getTimeNowMs();
for (int i = 0; i < count; i++) {
tempi += tempi;
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (tempi == 0) {
// 11ms is 1848000 ticks
// 18.48 ticks per iteration
@ -135,55 +135,55 @@ static void testMath(const int count) {
efiPrintf("Finished %d iterations of uint32_t summation in %dms", count, time);
}
start = currentTimeMillis();
start = getTimeNowMs();
tempi = 1;
for (int i = 0; i < count; i++) {
tempi += (tempi + 100) / 130;
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (tempi != 0) {
// Finished 100000 iterations of uint32_t division in 16ms
efiPrintf("Finished %d iterations of uint32_t division in %dms", count, time);
}
start = currentTimeMillis();
start = getTimeNowMs();
temp64 = 1;
for (int i = 0; i < count; i++) {
temp64 += temp64;
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (temp64 == 0) {
// Finished 100000 iterations of int64_t summation in 21ms
efiPrintf("Finished %d iterations of int64_t summation in %dms", count, time);
}
start = currentTimeMillis();
start = getTimeNowMs();
temp64 = 1;
for (int i = 0; i < count; i++) {
temp64 += (temp64 + 100) / 130;
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (temp64 != 0) {
// Finished 100000 iterations of int64_t division in 181ms
efiPrintf("Finished %d iterations of int64_t division in %dms", count, time);
}
start = currentTimeMillis();
start = getTimeNowMs();
float tempf = 1;
for (int i = 0; i < count; i++) {
tempf += tempf;
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (tempf != 0) {
efiPrintf("Finished %d iterations of float summation in %dms", count, time);
}
start = currentTimeMillis();
start = getTimeNowMs();
tempf = 1;
for (int i = 0; i < count; i++) {
tempf += tempf * 130.0f;
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (tempf != 0) {
// ms = ticks
// ticks per iteration
@ -191,12 +191,12 @@ static void testMath(const int count) {
efiPrintf("Finished %d iterations of float multiplication in %dms", count, time);
}
start = currentTimeMillis();
start = getTimeNowMs();
tempf = 1;
for (int i = 0; i < count; i++) {
tempf += (tempf + 100) / 130.0;
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (tempf != 0) {
// 65 ms = 10920000 ticks
// 109.2 ticks per iteration
@ -204,43 +204,43 @@ static void testMath(const int count) {
efiPrintf("Finished %d iterations of float division in %dms", count, time);
}
start = currentTimeMillis();
start = getTimeNowMs();
tempf = 1;
for (int i = 0; i < count; i++) {
tempf += logf(tempf);
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (tempf != 0) {
// Finished 100000 iterations of float log in 191ms
efiPrintf("Finished %d iterations of float log in %dms", count, time);
}
start = currentTimeMillis();
start = getTimeNowMs();
double tempd = 1;
for (int i = 0; i < count; i++)
tempd += tempd / 2;
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (tempd != 0) {
// Finished 100000 iterations of double summation in 80ms
efiPrintf("Finished %d iterations of double summation in %dms", count, time);
}
start = currentTimeMillis();
start = getTimeNowMs();
tempd = 1;
for (int i = 0; i < count; i++)
tempd += (tempd + 100) / 130.0;
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (tempd != 0) {
// Finished 100000 iterations of double division in 497ms
efiPrintf("Finished %d iterations of double division in %dms", count, time);
}
start = currentTimeMillis();
start = getTimeNowMs();
tempd = 1;
for (int i = 0; i < count; i++) {
tempd += log(tempd);
}
time = currentTimeMillis() - start;
time = getTimeNowMs() - start;
if (tempd != 0) {
// Finished 100000 iterations of double log in 242ms
efiPrintf("Finished %d iterations of double log in %dms", count, time);
@ -263,7 +263,7 @@ static int rtcStartTime;
#include "chrtclib.h"
static void timeInfo() {
efiPrintf("chTimeNow as seconds = %d", getTimeNowSeconds());
efiPrintf("chTimeNow as seconds = %d", getTimeNowS());
efiPrintf("hal seconds = %d", halTime.get() / (long)CORE_CLOCK);
#if EFI_RTC

View File

@ -140,7 +140,7 @@ static efitimems_t testSchedulingStart;
static void timerValidationCallback(void*) {
testSchedulingHappened = true;
efitimems_t actualTimeSinceScheduling = (currentTimeMillis() - testSchedulingStart);
efitimems_t actualTimeSinceScheduling = (getTimeNowMs() - testSchedulingStart);
if (absI(actualTimeSinceScheduling - TEST_CALLBACK_DELAY) > TEST_CALLBACK_DELAY * TIMER_PRECISION_THRESHOLD) {
firmwareError(CUSTOM_ERR_TIMER_TEST_CALLBACK_WRONG_TIME, "hwTimer broken precision: %ld ms", actualTimeSinceScheduling);
@ -155,7 +155,7 @@ static void validateHardwareTimer() {
if (hasFirmwareError()) {
return;
}
testSchedulingStart = currentTimeMillis();
testSchedulingStart = getTimeNowMs();
// to save RAM let's use 'watchDogBuddy' here once before we enable watchdog
engine->executor.scheduleForLater("hw-validate", &watchDogBuddy, MS2US(TEST_CALLBACK_DELAY), timerValidationCallback);

View File

@ -46,7 +46,7 @@ static void printGpsInfo() {
efiPrintf("m=%d,e=%d: vehicle speed = %.2f", gpsMesagesCount, uartErrors, getCurrentSpeed());
float sec = currentTimeMillis() / 1000.0;
float sec = getTimeNowMs() / 1000.0;
efiPrintf("communication speed: %.2f", gpsMesagesCount / sec);
print("GPS latitude = %.2f\r\n", GPSdata.latitude);

37
firmware/util/efitime.cpp Normal file
View File

@ -0,0 +1,37 @@
#include "pch.h"
#if !EFI_UNIT_TEST
static WrapAround62 timeNt;
/**
* 64-bit counter CPU/timer cycles since MCU reset
*/
efitick_t getTimeNowNt() {
return timeNt.update(getTimeNowLowerNt());
}
/**
* 64-bit result would not overflow, but that's complex stuff for our 32-bit MCU
*/
efitimeus_t getTimeNowUs() {
ScopePerf perf(PE::GetTimeNowUs);
return NT2US(getTimeNowNt());
}
/**
* 32 bit return type overflows in 23(or46?) days. tag#4554. I think we do not expect rusEFI to run for 23 days straight days any time soon?
*/
efitimems_t getTimeNowMs(void) {
return US2MS(getTimeNowUs());
}
/**
* Integer number of seconds since ECU boot.
* 31,710 years - would not overflow during our life span.
*/
efitimesec_t getTimeNowS(void) {
return getTimeNowUs() / US_PER_SECOND;
}
#endif /* !EFI_UNIT_TEST */

View File

@ -12,6 +12,9 @@
#include "efifeatures.h"
#include "rusefi_types.h"
// for US_TO_NT_MULTIPLIER which is port-specific
#include "port_mpu_util.h"
#define MS_PER_SECOND 1000
#define US_PER_SECOND 1000000
#define US_PER_SECOND_F 1000000.0
@ -30,7 +33,6 @@
// If converting a floating point time period, use this macro to avoid
// the expensive conversions from int64 <-> float
#define USF2NT(us_float) ((us_float) * US_TO_NT_MULTIPLIER)
#define USF2MS(us_float) (0.001f * (us_float))
// And back
@ -73,6 +75,21 @@ private:
volatile uint32_t m_upper = 0;
};
/**
* Get a monotonically increasing (but wrapping) 32-bit timer value
* Implemented at port level, based on timer or CPU tick counter
* Main source of EFI clock, SW-extended to 64bits
*/
uint32_t getTimeNowLowerNt();
/**
* 64-bit counter CPU/timer cycles since MCU reset
*
* See getTimeNowLowerNt for a quicker version which returns only lower 32 bits
* Lower 32 bits are enough if all we need is to measure relatively short time durations
* (BTW 2^32 cpu cycles at 168MHz is 25.59 seconds)
*/
efitick_t getTimeNowNt();
/**
* 64-bit counter of microseconds (1/1 000 000 of a second) since MCU reset
@ -85,27 +102,15 @@ private:
*/
efitimeus_t getTimeNowUs();
/**
* 64-bit counter CPU cycles since MCU reset
*
* See getTimeNowLowerNt for a quicker version which returns only lower 32 bits
* Lower 32 bits are enough if all we need is to measure relatively short time durations
* (BTW 2^32 cpu cycles at 168MHz is 25.59 seconds)
*/
efitick_t getTimeNowNt();
/**
* @brief Returns the number of milliseconds since the board initialization.
*/
efitimems_t currentTimeMillis();
efitimems_t getTimeNowMs();
/**
* @brief Current system time in seconds.
*/
efitimesec_t getTimeNowSeconds();
// Get a monotonically increasing (but wrapping) 32-bit timer value
uint32_t getTimeNowLowerNt();
efitimesec_t getTimeNowS();
#endif /* __cplusplus */

View File

@ -5,6 +5,7 @@ UTILSRC = \
UTILSRC_CPP = \
$(UTIL_DIR)/histogram.cpp \
$(UTIL_DIR)/efitime.cpp \
$(UTIL_DIR)/containers/listener_array.cpp \
$(UTIL_DIR)/containers/local_version_holder.cpp \
$(UTIL_DIR)/math/biquad.cpp \

View File

@ -9,7 +9,7 @@ static Deadband<5> maxCltDeadband;
static Deadband<5> maxTpsDeadband;
bool AcController::getAcState() {
latest_usage_ac_control = getTimeNowSeconds();
latest_usage_ac_control = getTimeNowS();
auto rpm = Sensor::getOrZero(SensorType::Rpm);
engineTooSlow = rpm < 500;

View File

@ -15,7 +15,7 @@ efitimeus_t getTimeNowUs() {
return timeNowUs;
}
efitimesec_t getTimeNowSeconds() {
efitimesec_t getTimeNowS() {
return getTimeNowUs() / 1000 / 1000;
}

View File

@ -10,7 +10,7 @@
efitimems_t mockTimeMs = 0;
efitimems_t currentTimeMillis(void) {
efitimems_t getTimeNowMs(void) {
return mockTimeMs;
}