nanohub: add VERBOSE log level and move some logging to it
Move frequently logged messages to VERBOSE level
Test: build
Change-Id: Idc17d45711d6c8d06ff8bab04f99677909a00ce2
Signed-off-by: Ben Fennema <[email protected]>
diff --git a/firmware/os/drivers/bosch_bmi160/bosch_bmi160.c b/firmware/os/drivers/bosch_bmi160/bosch_bmi160.c
index f27a9e9..61c3d23 100644
--- a/firmware/os/drivers/bosch_bmi160/bosch_bmi160.c
+++ b/firmware/os/drivers/bosch_bmi160/bosch_bmi160.c
@@ -75,6 +75,10 @@
#include <stdlib.h>
#include <string.h>
+#define VERBOSE_PRINT(fmt, ...) do { \
+ osLog(LOG_VERBOSE, "%s " fmt, "[BMI160]", ##__VA_ARGS__); \
+ } while (0);
+
#define INFO_PRINT(fmt, ...) do { \
osLog(LOG_INFO, "%s " fmt, "[BMI160]", ##__VA_ARGS__); \
} while (0);
@@ -85,13 +89,13 @@
#define DEBUG_PRINT(fmt, ...) do { \
if (DBG_ENABLE) { \
- INFO_PRINT(fmt, ##__VA_ARGS__); \
+ osLog(LOG_DEBUG, "%s " fmt, "[BMI160]", ##__VA_ARGS__); \
} \
} while (0);
#define DEBUG_PRINT_IF(cond, fmt, ...) do { \
if ((cond) && DBG_ENABLE) { \
- INFO_PRINT(fmt, ##__VA_ARGS__); \
+ osLog(LOG_DEBUG, "%s " fmt, "[BMI160]", ##__VA_ARGS__); \
} \
} while (0);
@@ -1313,7 +1317,7 @@
{
TDECL();
- INFO_PRINT("accPower: on=%d, state=%" PRI_STATE "\n", on, getStateName(GET_STATE()));
+ VERBOSE_PRINT("accPower: on=%d, state=%" PRI_STATE "\n", on, getStateName(GET_STATE()));
if (trySwitchState(on ? SENSOR_POWERING_UP : SENSOR_POWERING_DOWN)) {
if (on) {
// set ACC power mode to NORMAL
@@ -1336,7 +1340,7 @@
static bool gyrPower(bool on, void *cookie)
{
TDECL();
- INFO_PRINT("gyrPower: on=%d, state=%" PRI_STATE "\n", on, getStateName(GET_STATE()));
+ VERBOSE_PRINT("gyrPower: on=%d, state=%" PRI_STATE "\n", on, getStateName(GET_STATE()));
if (trySwitchState(on ? SENSOR_POWERING_UP : SENSOR_POWERING_DOWN)) {
if (on) {
@@ -1369,7 +1373,7 @@
static bool magPower(bool on, void *cookie)
{
TDECL();
- INFO_PRINT("magPower: on=%d, state=%" PRI_STATE "\n", on, getStateName(GET_STATE()));
+ VERBOSE_PRINT("magPower: on=%d, state=%" PRI_STATE "\n", on, getStateName(GET_STATE()));
if (trySwitchState(on ? SENSOR_POWERING_UP : SENSOR_POWERING_DOWN)) {
if (on) {
// set MAG power mode to NORMAL
@@ -1665,7 +1669,7 @@
TDECL();
int odr, osr = 0;
int osr_mode = 2; // normal
- INFO_PRINT("gyrSetRate: rate=%ld, latency=%lld, state=%" PRI_STATE "\n",
+ VERBOSE_PRINT("gyrSetRate: rate=%ld, latency=%lld, state=%" PRI_STATE "\n",
rate, latency, getStateName(GET_STATE()));
if (trySwitchState(SENSOR_CONFIG_CHANGING)) {
@@ -1732,7 +1736,7 @@
if (rate == SENSOR_RATE_ONCHANGE)
rate = SENSOR_HZ(100);
- INFO_PRINT("magSetRate: rate=%ld, latency=%lld, state=%" PRI_STATE "\n",
+ VERBOSE_PRINT("magSetRate: rate=%ld, latency=%lld, state=%" PRI_STATE "\n",
rate, latency, getStateName(GET_STATE()));
if (trySwitchState(SENSOR_CONFIG_CHANGING)) {
@@ -3922,7 +3926,7 @@
// XXX: this consumes too much memeory, need to optimize
T(mDataSlab) = slabAllocatorNew(slabSize, 4, 20);
if (!T(mDataSlab)) {
- INFO_PRINT("slabAllocatorNew() failed\n");
+ ERROR_PRINT("slabAllocatorNew() failed\n");
return false;
}
T(mWbufCnt) = 0;
diff --git a/firmware/os/drivers/rohm_rpr0521/rohm_rpr0521.c b/firmware/os/drivers/rohm_rpr0521/rohm_rpr0521.c
index 8f2f16a..3fb6ee8 100644
--- a/firmware/os/drivers/rohm_rpr0521/rohm_rpr0521.c
+++ b/firmware/os/drivers/rohm_rpr0521/rohm_rpr0521.c
@@ -143,6 +143,10 @@
osLog(LOG_INFO, "[Rohm RPR-0521] " fmt, ##__VA_ARGS__); \
} while (0);
+#define ERROR_PRINT(fmt, ...) do { \
+ osLog(LOG_ERROR, "[Rohm RPR-0521] " fmt, ##__VA_ARGS__); \
+ } while (0);
+
#define DEBUG_PRINT(fmt, ...) do { \
if (enable_debug) { \
osLog(LOG_INFO, "[Rohm RPR-0521] " fmt, ##__VA_ARGS__); \
@@ -298,7 +302,7 @@
osEnqueuePrivateEvt(EVT_SENSOR_I2C, cookie, NULL, mTask.tid);
if (err != 0)
- INFO_PRINT("i2c error (tx: %d, rx: %d, err: %d)\n", tx, rx, err);
+ ERROR_PRINT("i2c error (tx: %d, rx: %d, err: %d)\n", tx, rx, err);
}
static void alsTimerCallback(uint32_t timerId, void *cookie)
@@ -385,7 +389,7 @@
static bool sensorPowerAls(bool on, void *cookie)
{
- DEBUG_PRINT("sensorPowerAls: %d\n", on);
+ VERBOSE_PRINT("sensorPowerAls: %d\n", on);
if (on && !mTask.alsTimerHandle) {
mTask.alsTimerHandle = timTimerSet(ROHM_RPR0521_ALS_TIMER_DELAY, 0, 50, alsTimerCallback, NULL, false);
@@ -411,7 +415,7 @@
if (rate == SENSOR_RATE_ONCHANGE)
rate = ROHM_RPR0521_DEFAULT_RATE;
- DEBUG_PRINT("sensorRateAls: rate=%ld Hz latency=%lld ns\n", rate/1024, latency);
+ VERBOSE_PRINT("sensorRateAls: rate=%ld Hz latency=%lld ns\n", rate/1024, latency);
return sensorSignalInternalEvt(mTask.alsHandle, SENSOR_INTERNAL_EVT_RATE_CHG, rate, latency);
}
@@ -434,7 +438,7 @@
static bool sensorPowerProx(bool on, void *cookie)
{
- DEBUG_PRINT("sensorPowerProx: %d\n", on);
+ VERBOSE_PRINT("sensorPowerProx: %d\n", on);
if (on) {
extiClearPendingGpio(mTask.pin);
@@ -461,7 +465,7 @@
if (rate == SENSOR_RATE_ONCHANGE)
rate = ROHM_RPR0521_DEFAULT_RATE;
- DEBUG_PRINT("sensorRateProx: rate=%ld Hz latency=%lld ns\n", rate/1024, latency);
+ VERBOSE_PRINT("sensorRateProx: rate=%ld Hz latency=%lld ns\n", rate/1024, latency);
return sensorSignalInternalEvt(mTask.proxHandle, SENSOR_INTERNAL_EVT_RATE_CHG, rate, latency);
}
@@ -475,8 +479,6 @@
{
struct I2cTransfer *xfer;
- DEBUG_PRINT("sensorCfgDataProx");
-
int32_t offset = *(int32_t*)data;
INFO_PRINT("Received cfg data: %d\n", (int)offset);
diff --git a/firmware/os/drivers/synaptics_s3708/synaptics_s3708.c b/firmware/os/drivers/synaptics_s3708/synaptics_s3708.c
index df1afce..62f364a 100644
--- a/firmware/os/drivers/synaptics_s3708/synaptics_s3708.c
+++ b/firmware/os/drivers/synaptics_s3708/synaptics_s3708.c
@@ -76,10 +76,11 @@
#define ENABLE_DEBUG 0
+#define VERBOSE_PRINT(fmt, ...) osLog(LOG_VERBOSE, "[DoubleTouch] " fmt, ##__VA_ARGS__)
#define INFO_PRINT(fmt, ...) osLog(LOG_INFO, "[DoubleTouch] " fmt, ##__VA_ARGS__)
#define ERROR_PRINT(fmt, ...) osLog(LOG_ERROR, "[DoubleTouch] " fmt, ##__VA_ARGS__)
#if ENABLE_DEBUG
-#define DEBUG_PRINT(fmt, ...) INFO_PRINT(fmt, ##__VA_ARGS__)
+#define DEBUG_PRINT(fmt, ...) osLog(LOG_DEBUG, "[DoubleTouch] " fmt, ##__VA_ARGS__)
#else
#define DEBUG_PRINT(fmt, ...) ((void)0)
#endif
@@ -303,7 +304,7 @@
bool ret;
size_t i;
- INFO_PRINT("gesture: %d", enable);
+ VERBOSE_PRINT("gesture: %d", enable);
// Cancel any pending I2C transactions by changing the callback state
for (i = 0; i < ARRAY_SIZE(mTask.transfers); i++) {
@@ -360,7 +361,7 @@
{
uint32_t enabledSeconds, proxEnabledSeconds, proxFarSeconds;
- INFO_PRINT("power: %d", on);
+ VERBOSE_PRINT("power: %d", on);
if (on) {
mTask.stats.enabledTimestamp = sensorGetTime();
@@ -371,7 +372,7 @@
enabledSeconds = U64_DIV_BY_U64_CONSTANT(mTask.stats.totalEnabledTime, 1000000000);
proxEnabledSeconds = U64_DIV_BY_U64_CONSTANT(mTask.stats.totalProxEnabledTime, 1000000000);
proxFarSeconds = U64_DIV_BY_U64_CONSTANT(mTask.stats.totalProxFarTime, 1000000000);
- INFO_PRINT("STATS: enabled %02" PRIu32 ":%02" PRIu32 ":%02" PRIu32
+ VERBOSE_PRINT("STATS: enabled %02" PRIu32 ":%02" PRIu32 ":%02" PRIu32
", prox enabled %02" PRIu32 ":%02" PRIu32 ":%02" PRIu32
", prox far %02" PRIu32 ":%02" PRIu32 ":%02" PRIu32
", prox *->f %" PRIu32
diff --git a/firmware/os/drivers/vsync/vsync.c b/firmware/os/drivers/vsync/vsync.c
index 68147b0..9d76759 100644
--- a/firmware/os/drivers/vsync/vsync.c
+++ b/firmware/os/drivers/vsync/vsync.c
@@ -49,6 +49,10 @@
#error "VSYNC_IRQ is not defined; please define in variant.h"
#endif
+#define VERBOSE_PRINT(fmt, ...) do { \
+ osLog(LOG_VERBOSE, "%s " fmt, "[VSYNC]", ##__VA_ARGS__); \
+ } while (0);
+
#define INFO_PRINT(fmt, ...) do { \
osLog(LOG_INFO, "%s " fmt, "[VSYNC]", ##__VA_ARGS__); \
} while (0);
@@ -149,7 +153,7 @@
static bool vsyncPower(bool on, void *cookie)
{
- INFO_PRINT("power %d\n", on);
+ VERBOSE_PRINT("power %d\n", on);
if (on) {
extiClearPendingGpio(mTask.pin);
@@ -171,13 +175,13 @@
static bool vsyncSetRate(uint32_t rate, uint64_t latency, void *cookie)
{
- INFO_PRINT("setRate\n");
+ VERBOSE_PRINT("setRate\n");
return sensorSignalInternalEvt(mTask.sensorHandle, SENSOR_INTERNAL_EVT_RATE_CHG, rate, latency);
}
static bool vsyncFlush(void *cookie)
{
- INFO_PRINT("flush\n");
+ VERBOSE_PRINT("flush\n");
return osEnqueueEvt(sensorGetMyEventType(SENS_TYPE_VSYNC), SENSOR_DATA_EVENT_FLUSH, NULL);
}
diff --git a/firmware/os/drivers/window_orientation/window_orientation.c b/firmware/os/drivers/window_orientation/window_orientation.c
index 067649a..c81d8a6 100644
--- a/firmware/os/drivers/window_orientation/window_orientation.c
+++ b/firmware/os/drivers/window_orientation/window_orientation.c
@@ -34,6 +34,10 @@
#define LOG_TAG "[WO]"
+#define LOGV(fmt, ...) do { \
+ osLog(LOG_VERBOSE, LOG_TAG " " fmt, ##__VA_ARGS__); \
+ } while (0);
+
#define LOGW(fmt, ...) do { \
osLog(LOG_WARN, LOG_TAG " " fmt, ##__VA_ARGS__); \
} while (0);
@@ -618,7 +622,7 @@
rotation_changed = add_samples(ev);
if (rotation_changed) {
- LOGI("rotation changed to: ******* %d *******\n",
+ LOGV("rotation changed to: ******* %d *******\n",
(int)mTask.proposed_rotation);
// send a single int32 here so no memory alloc/free needed.
diff --git a/firmware/os/inc/seos.h b/firmware/os/inc/seos.h
index 7b17889..7979d76 100644
--- a/firmware/os/inc/seos.h
+++ b/firmware/os/inc/seos.h
@@ -270,10 +270,11 @@
/* Logging */
enum LogLevel {
- LOG_ERROR = 'E',
- LOG_WARN = 'W',
- LOG_INFO = 'I',
- LOG_DEBUG = 'D',
+ LOG_ERROR = 'E',
+ LOG_WARN = 'W',
+ LOG_INFO = 'I',
+ LOG_DEBUG = 'D',
+ LOG_VERBOSE = 'V',
};
void osLogv(char clevel, uint32_t flags, const char *str, va_list vl);
diff --git a/firmware/os/platform/stm32/platform.c b/firmware/os/platform/stm32/platform.c
index befafe9..313f1bd 100644
--- a/firmware/os/platform/stm32/platform.c
+++ b/firmware/os/platform/stm32/platform.c
@@ -110,7 +110,7 @@
#ifdef DEBUG_LOG_EVT
#ifndef EARLY_LOG_BUF_SIZE
-#define EARLY_LOG_BUF_SIZE 1024
+#define EARLY_LOG_BUF_SIZE 2048
#endif
#define HOSTINTF_HEADER_SIZE 4
uint8_t *mEarlyLogBuffer;
