GPStracker/soft/syslog.c

#ifdef PC_BUILD
#include "../gps-test-tool/main.h"
#else
#include "main.h"
#endif

#ifndef FW_VERSION
#define FW_VERSION "unknown"
#endif

__flash const char reject_reason_kalman[] = "kalman";
__flash const char reject_reason_distdiff[] = "distdiff";
__flash const char reject_reason_mindist[] = "mindist";
__flash const char reject_reason_altdiff[] = "altdiff";

__flash const char *reject_reason_names[] = {
	[REJECT_REASON_KALMAN] = reject_reason_kalman,
	[REJECT_REASON_DISTDIFF] = reject_reason_distdiff,
	[REJECT_REASON_MINDIST] = reject_reason_mindist,
	[REJECT_REASON_ALTDIFF] = reject_reason_altdiff,
};

__flash const char status_no_power[] = "no power";
__flash const char status_no_disk[] = "no card";
__flash const char status_no_gps[] = "waiting for GPS";
__flash const char status_ok[] = "ok";
__flash const char status_disk_error[] = "card mount failed";
__flash const char status_file_write_error[] = "write failed";
__flash const char status_file_sync_error[] = "sync failed";
__flash const char status_file_close_error[] = "close failed";
__flash const char status_file_open_error[] = "open failed";
__flash const char status_unknown[] = "unknown";

__flash const char *status_names[] = {
	status_no_power,
	status_no_disk,
	status_no_gps,
	status_ok,
	status_disk_error,
	status_file_write_error,
	status_file_sync_error,
	status_file_close_error,
	status_file_open_error,
};

static struct {
	unsigned char reason;
	unsigned char count;
	unsigned int hdop_x100;
	unsigned char sats;
	unsigned char fix_type;
} reject_coalesce;

static unsigned char fix_had_first;
static unsigned long int gps_on_uptime;

void log_prefix(void) {
	if (utc)
		xprintf(PSTR("%s up=%lu "), get_iso_time(utc, 0), get_uptime_ms());
	else
		xprintf(PSTR("NOTIME up=%lu "), get_uptime_ms());
}

void log_config(void) {
	log_prefix();
	xputs_P(PSTR("CFG filt="));
	xputs_P(get_flag(CONFFLAG_DISABLE_FILTERS) ? PSTR("off") : PSTR("on"));
	xprintf(PSTR(" skip=%u gate_sats=%u pause_t=%us pause_d=%um pause_v=%ukmh sbas_search="),
		(unsigned int)System.conf.skip_points, (unsigned int)System.conf.min_sats,
		(unsigned int)System.conf.auto_pause_time, (unsigned int)System.conf.auto_pause_dist,
		(unsigned int)System.conf.auto_pause_speed);
	xputs_P(get_flag(CONFFLAG_ENABLE_SBAS) ? PSTR("on") : PSTR("off"));
	xputs_P(PSTR(" auto_pause="));
	xputs_P(get_flag(CONFFLAG_AUTO_PAUSE) ? PSTR("on") : PSTR("off"));
	xputs_P(PSTR(" gnss="));
	xputs_P(gnss_names[System.conf.gnss_mode]);
	xputs_P(PSTR(" uart_log="));
	xputs_P(uart_log_mode_names[System.conf.uart_log_mode]);
	xputs_P(PSTR(" verbose="));
	xputs_P(get_flag(CONFFLAG_VERBOSE_LOG) ? PSTR("on") : PSTR("off"));
	xputs_P(PSTR(" reset_new_file="));
	xputs_P(get_flag(CONFFLAG_RESET_ON_NEW_FILE) ? PSTR("on") : PSTR("off"));
	xputs_P(PSTR("\r\n"));
}

void log_boot_record(void) {
	log_prefix();
	xputs_P(PSTR("BOOT fw="));
	xputs_P(PSTR(FW_VERSION));
	xputs_P(PSTR(" reset="));
	if (reset_cause & _BV(WDRF))
		xputs_P(PSTR("WDT"));
	else if (reset_cause & _BV(BORF))
		xputs_P(PSTR("BOR"));
	else if (reset_cause & _BV(EXTRF))
		xputs_P(PSTR("EXT"));
	else if (reset_cause & _BV(PORF))
		xputs_P(PSTR("POR"));
	else
		xputs_P(PSTR("UNKNOWN"));
	xputs_P(PSTR(" rx="));
	xputs_P(gnss_names[System.conf.gnss_mode]);
	xputs_P(PSTR("\r\n"));
	log_config();
}

void log_loop_status(unsigned char status) {
	log_prefix();
	xprintf(PSTR("LOOP err=%u ("), (unsigned int)status);
	if (status < sizeof(status_names)/sizeof(status_names[0]))
		xputs_P(status_names[status]);
	else
		xputs_P(status_unknown);
	xputs_P(PSTR(")\r\n"));
}

void gps_powered_on(void) {
	gps_on_uptime = get_uptime_ms();
	fix_had_first = 0;
}

void log_fix_event(void) {
	log_prefix();
	xprintf(PSTR("FIX %uD"), (unsigned int)System.fix_type);
	xputs_P(System.dgps ? PSTR("/D") : PSTR(""));
	if (!fix_had_first) {
		unsigned long int ttff = get_uptime_ms() - gps_on_uptime;
		xprintf(PSTR(" ttff=%lu.%01lus"), ttff/1000, (ttff%1000)/100);
		fix_had_first = 1;
	} else {
		xputs_P(PSTR(" regained"));
	}
	xprintf(PSTR(" sats=%u hdop=%.2f\r\n"), (unsigned int)System.satellites_used, (double)System.hdop_x100/100.0);
}

void log_fix_lost(void) {
	log_prefix();
	xprintf(PSTR("FIX LOST sats=%u\r\n"), (unsigned int)System.satellites_used);
}

void log_dgps_transition(void) {
	log_prefix();
	xputs_P(PSTR("DGPS "));
	xputs_P(System.dgps ? PSTR("on") : PSTR("off"));
	xputs_P(PSTR("\r\n"));
}

void log_pause_event(unsigned char started) {
	log_prefix();
	xputs_P(started ? PSTR("PAUSE\r\n") : PSTR("RESUME\r\n"));
}

void log_reject_flush(void) {
	if (!reject_coalesce.count)
		return;
	log_prefix();
	xputs_P(PSTR("REJ reason="));
	xputs_P(reject_reason_names[reject_coalesce.reason]);
	xprintf(PSTR(" hdop=%.2f sats=%u fix=%uD"), (double)reject_coalesce.hdop_x100/100.0,
		(unsigned int)reject_coalesce.sats, (unsigned int)reject_coalesce.fix_type);
	if (reject_coalesce.count > 1)
		xprintf(PSTR(" x%u"), (unsigned int)reject_coalesce.count);
	xputs_P(PSTR("\r\n"));
	reject_coalesce.count = 0;
}

void log_reject(unsigned char reason) {
	System.rejected_count++;
	if (reject_coalesce.count && reject_coalesce.reason == reason && reject_coalesce.count < 255) {
		reject_coalesce.count++;
		reject_coalesce.hdop_x100 = System.hdop_x100;
		reject_coalesce.sats = System.satellites_used;
		reject_coalesce.fix_type = System.fix_type;
		return;
	}
	log_reject_flush();
	reject_coalesce.reason = reason;
	reject_coalesce.count = 1;
	reject_coalesce.hdop_x100 = System.hdop_x100;
	reject_coalesce.sats = System.satellites_used;
	reject_coalesce.fix_type = System.fix_type;
}

void log_jump(unsigned char is_alt, float meters) {
	log_prefix();
	xputs_P(PSTR("JUMP "));
	xputs_P(is_alt ? PSTR("alt=") : PSTR("pos="));
	xprintf(PSTR("%.1fm\r\n"), (double)meters);
}

/* Voltage->percent breakpoints for a rough Li-ion/LiPo discharge curve,
 * anchored so VI_LVL (the level that forces an immediate shutdown, see
 * main.h) reads 0% - not just happens to clamp there. Precision isn't the
 * goal (a straight line between points is a rough approximation), only
 * getting the empty end right, since that's exactly when this number matters
 * most. Voltages are millivolts to keep the table integer. */
__flash const unsigned int batt_lut_mv[] = { 3100, 3400, 3550, 3700, 3850, 4000, 4100, 4200 };
__flash const unsigned char batt_lut_pct[] = {   0,   10,   25,   45,   65,   80,   90,  100 };
#define BATT_LUT_LEN	(sizeof(batt_lut_mv)/sizeof(batt_lut_mv[0]))

static unsigned char battery_percent(float bat_volt) {
	unsigned int mv = (unsigned int)(bat_volt*1000.0 + 0.5);
	unsigned char i;

	if (mv <= batt_lut_mv[0])
		return batt_lut_pct[0];
	if (mv >= batt_lut_mv[BATT_LUT_LEN-1])
		return batt_lut_pct[BATT_LUT_LEN-1];
	for (i = 1; i < BATT_LUT_LEN; i++) {
		if (mv <= batt_lut_mv[i]) {
			unsigned int span_mv = batt_lut_mv[i] - batt_lut_mv[i-1];
			unsigned char span_pct = batt_lut_pct[i] - batt_lut_pct[i-1];
			return batt_lut_pct[i-1] + (unsigned char)((unsigned long int)(mv - batt_lut_mv[i-1]) * span_pct / span_mv);
		}
	}
	return batt_lut_pct[BATT_LUT_LEN-1]; /* unreachable */
}

void log_status_line(void) {
	unsigned char batpct = battery_percent(System.bat_volt);

	log_reject_flush();
	log_prefix();
	xprintf(PSTR("ST v=%.3f bat%%=%d"), (double)System.bat_volt, batpct);
	if (System.temperature_ok)
		xprintf(PSTR(" t=%.1f"), (double)System.temperature);
	xprintf(PSTR(" sats=%u hdop=%.2f fix=%u"), (unsigned int)System.satellites_used,
		(double)System.hdop_x100/100.0, (unsigned int)System.fix_type);
	xputs_P(System.dgps ? PSTR("D") : PSTR(""));
	xprintf(PSTR(" dist=%.2f gain=%.1f/raw%.1f loss=%.1f/raw%.1f wr=%lu rej=%lu"),
		(double)System.distance/100.0, (double)System.elevation_gain/10.0, (double)System.elevation_gain_raw/10.0,
		(double)System.elevation_loss/10.0, (double)System.elevation_loss_raw/10.0,
		System.points_written, System.rejected_count);
	xprintf(PSTR(" iomax=%ums stack=%u"), io_get_and_reset_max(), get_stack_free_bytes());
	if (utc)
		xprintf(PSTR(" loc=%s"), get_iso_time(utc, 1));
	xputs_P(PSTR("\r\n"));
}

void log_session_summary(unsigned char final) {
	unsigned int moving = get_logging_time();
	unsigned long int stopped = get_pause_time();
	unsigned int h, m;

	log_reject_flush();
	log_prefix();
	xputs_P(final ? PSTR("SUMMARY final ") : PSTR("SUMMARY "));
	xprintf(PSTR("dist=%.2f gain=%.1f loss=%.1f moving="), (double)System.distance/100.0,
		(double)System.elevation_gain/10.0, (double)System.elevation_loss/10.0);
	h = moving/3600; m = (moving/60)%60;
	xprintf(PSTR("%uh%02um stopped="), h, m);
	h = stopped/3600; m = (stopped/60)%60;
	xprintf(PSTR("%uh%02um altmax=%.1f vmin=%.3f rej=%lu"), h, m,
		(double)System.alt_max/10.0, (double)System.bat_volt_min, System.rejected_count);
	/* Both averages should track each other; a growing gap is worth noticing. */
	xprintf(PSTR(" avg_speed=%.2f avg_dist=%.2f"),
		(double)get_avg_speed_x100()/100.0, (double)get_dist_avg_speed_x100()/100.0);
	/* points_accepted is pre-averaging: with filters enabled (AVG_COUNT
	 * samples per written trkpt), points_accepted - points_written*AVG_COUNT
	 * is however many accepted points are sitting in the averaging window,
	 * not yet flushed to a trkpt - "averaged out" here, since it never will
	 * be on its own (the group only flushes once it reaches AVG_COUNT). */
	xprintf(PSTR(" paused=%lu skipped=%lu accepted=%lu wr=%lu\r\n"),
		System.points_paused, System.points_skipped, System.points_accepted, System.points_written);
}