torched_esc/ESPNTPServer
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Switch to use DLog as dbug output

Browse Source
This commit is contained in:
Christopher Liebman 2018-03-11 19:00:40 -07:00
parent 7f45ec04bf
commit 6e29da89b5
8 changed files with 47 additions and 261 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
Display.cpp
View File

@ -27,10 +27,10 @@ Display::~Display()
void Display::begin() void Display::begin()
{ {
logger.info(TAG, "initializing display"); dlog.info(TAG, F("initializing display"));
if (!_dsp.init()) if (!_dsp.init())
{ {
logger.error(TAG, "display.init() failed!"); dlog.error(TAG, F("display.init() failed!"));
} }
_dsp.flipScreenVertically(); _dsp.flipScreenVertically();
font(ArialMT_Plain_10); font(ArialMT_Plain_10);

1
Display.h
View File

@ -28,6 +28,7 @@ public:
void display(); void display();
void align(OLEDDISPLAY_TEXT_ALIGNMENT alignment); void align(OLEDDISPLAY_TEXT_ALIGNMENT alignment);
void font(const char* fontData); void font(const char* fontData);
void print(int16_t x, int16_t y, const char* fmt, ...); void print(int16_t x, int16_t y, const char* fmt, ...);
private: private:
SSD1306Wire _dsp; SSD1306Wire _dsp;

55
ESPNTPServer.cpp
View File

@ -22,6 +22,7 @@
#include "ESPNTPServer.h" #include "ESPNTPServer.h"
#include "Log.h" #include "Log.h"
#include "DLogPrintWriter.h"
#include "GPS.h" #include "GPS.h"
#include "NTP.h" #include "NTP.h"
@ -30,18 +31,20 @@
GPS gps(Serial, SYNC_PIN); GPS gps(Serial, SYNC_PIN);
NTP ntp(gps); NTP ntp(gps);
Display display(gps, ntp, SDA_PIN, SCL_PIN); Display display(gps, ntp, SDA_PIN, SCL_PIN);
DLog& dlog = DLog::getLog();
const char* SETUP_TAG = "setup"; const char* SETUP_TAG = "setup";
const char* LOOP_TAG = "loop"; const char* LOOP_TAG = "loop";
void logTimeFirst(Print* print) void logTimeFirst(DLogBuffer& buffer, DLogLevel level)
{ {
static struct timeval tv; (void)level; // not used
struct timeval tv;
struct tm tm;
gps.getTime(&tv); gps.getTime(&tv);
static struct tm tm;
gmtime_r(&tv.tv_sec, &tm); gmtime_r(&tv.tv_sec, &tm);
print->printf("%04d/%02d/%02d %02d:%02d:%02d.%06ld ", buffer.printf(F("%04d/%02d/%02d %02d:%02d:%02d.%06ld "),
tm.tm_year+1900, tm.tm_year+1900,
tm.tm_mon+1, tm.tm_mon+1,
tm.tm_mday, tm.tm_mday,
@ -54,25 +57,29 @@ void logTimeFirst(Print* print)
void setup() void setup()
{ {
delay(5000); // delay for IDE to re-open serial delay(5000); // delay for IDE to re-open serial
Serial1.begin(115200);
logger.setSize(256);
logger.setPrint(&Serial1);
logger.setPreFunc(&logTimeFirst);
logger.info(SETUP_TAG, "Startup!");
logger.info(SETUP_TAG, "initializing display"); //
// Setup DLog with Serial1, set the pre function to add the date/time
//
Serial1.begin(115200);
dlog.begin(new DLogPrintWriter(Serial1));
dlog.setPreFunc(&logTimeFirst);
dlog.info(SETUP_TAG, F("Startup!"));
dlog.info(SETUP_TAG, F("initializing display"));
display.begin(); display.begin();
logger.info(SETUP_TAG, "initializing serial for GPS"); dlog.info(SETUP_TAG, F("initializing serial for GPS"));
Serial.begin(9600); Serial.begin(9600);
Serial.swap(); Serial.swap();
logger.info(SETUP_TAG, "initializing GPS"); dlog.info(SETUP_TAG, F("initializing GPS"));
gps.begin(); gps.begin();
display.process(); display.process();
#if !defined(USE_NO_WIFI) #if !defined(USE_NO_WIFI)
logger.info(SETUP_TAG, "initializing wifi"); dlog.info(SETUP_TAG, F("initializing wifi"));
#if 0 #if 0
WiFiManager wifi; WiFiManager wifi;
wifi.setDebugStream(Serial1); wifi.setDebugStream(Serial1);
@ -88,7 +95,7 @@ void setup()
display.process(); display.process();
logger.info(SETUP_TAG, "initializing NTP"); dlog.info(SETUP_TAG, F("initializing NTP"));
ntp.begin(); ntp.begin();
} }
@ -122,14 +129,14 @@ void loop()
status = "<UNKNOWN>"; status = "<UNKNOWN>";
break; break;
} }
logger.info(LOOP_TAG, "wifi status change %d -> %d '%s'", last_wifi_status, wifi_status, status); dlog.info(LOOP_TAG, F("wifi status change %d -> %d '%s'"), last_wifi_status, wifi_status, status);
last_wifi_status = wifi_status; last_wifi_status = wifi_status;
} }
IPAddress ip = WiFi.localIP(); IPAddress ip = WiFi.localIP();
if (ip != last_ip) if (ip != last_ip)
{ {
logger.warning(LOOP_TAG, "ip address change %s -> %s", last_ip.toString().c_str(), ip.toString().c_str()); dlog.warning(LOOP_TAG, F("ip address change %s -> %s"), last_ip.toString().c_str(), ip.toString().c_str());
last_ip = ip; last_ip = ip;
} }
@ -138,22 +145,12 @@ void loop()
static time_t last_seconds; static time_t last_seconds;
struct timeval tv; struct timeval tv;
gps.getTime(&tv); gps.getTime(&tv);
if (tv.tv_sec != last_seconds) if (tv.tv_sec != last_seconds)
{ {
struct tm tm;
gmtime_r(&tv.tv_sec, &tm);
char ts[64];
snprintf(ts, 63, "%04d/%02d/%02d %02d:%02d:%02d.%06ld",
tm.tm_year+1900,
tm.tm_mon+1,
tm.tm_mday,
tm.tm_hour,
tm.tm_min,
tm.tm_sec,
tv.tv_usec);
if (tv.tv_sec != last_seconds && ((tv.tv_sec % 300) == 0 || gps.getValidDelay())) if (tv.tv_sec != last_seconds && ((tv.tv_sec % 300) == 0 || gps.getValidDelay()))
{ {
logger.info("loop", "jitter:%lu valid_count:%lu valid:%s gpsvalid:%s numsat:%d heap:%ld valid_delay:%d", dlog.info("loop", F("jitter:%lu valid_count:%lu valid:%s gpsvalid:%s numsat:%d heap:%ld valid_delay:%d"),
gps.getJitter(), gps.getJitter(),
gps.getValidCount(), gps.getValidCount(),
gps.isValid() ? "true" : "false", gps.isValid() ? "true" : "false",
@ -165,7 +162,7 @@ void loop()
if (tv.tv_sec < last_seconds) if (tv.tv_sec < last_seconds)
{ {
logger.warning(LOOP_TAG, "%s: OOPS: time went backwards: last:%lu now:%lu\n", ts, last_seconds, tv.tv_sec); dlog.warning(LOOP_TAG, F("OOPS: time went backwards: last:%lu now:%lu delta:%ld"), last_seconds, tv.tv_sec, tv.tv_sec-last_seconds);
} }
display.process(); display.process();

10
GPS.cpp
View File

@ -110,7 +110,7 @@ void GPS::process()
{ {
if (_reason[0] != '\0') if (_reason[0] != '\0')
{ {
logger.warning(TAG, "REASON: %s", _reason); dlog.warning(TAG, F("REASON: %s"), _reason);
_reason[0] = '\0'; _reason[0] = '\0';
} }
@ -120,7 +120,7 @@ void GPS::process()
{ {
struct timeval tv; struct timeval tv;
getTime(&tv); getTime(&tv);
logger.debug(TAG, "'%s'", _nmea.getSentence()); dlog.debug(TAG, F("'%s'"), _nmea.getSentence());
const char * id = _nmea.getMessageID(); const char * id = _nmea.getMessageID();
@ -148,11 +148,11 @@ void GPS::process()
{ {
_seconds = new_seconds; _seconds = new_seconds;
invalidate("seconds adjusted!"); invalidate("seconds adjusted!");
logger.info(TAG, "adjusting seconds from %lu to %lu from:'%s'", old_seconds, new_seconds, _nmea.getSentence()); dlog.info(TAG, F("adjusting seconds from %lu to %lu from:'%s'"), old_seconds, new_seconds, _nmea.getSentence());
} }
else else
{ {
logger.debug(TAG, "ignoring late NMEA time: '%s'",_nmea.getSentence()); dlog.debug(TAG, F("ignoring late NMEA time: '%s'"),_nmea.getSentence());
} }
} }
@ -169,7 +169,7 @@ void GPS::process()
{ {
_valid_delay = VALID_DELAY; _valid_delay = VALID_DELAY;
_gps_valid = true; _gps_valid = true;
logger.info(TAG, "GPS valid!"); dlog.info(TAG, F("GPS valid!"));
} }
} }
else /* nmea not valid or sat count < 4 */ else /* nmea not valid or sat count < 4 */

160
Log.cpp
View File

@ -1,160 +0,0 @@
/*
* Log.cpp
*
* Copyright 2017 Christopher B. Liebman
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*
* Created on: Mar 2, 2018
* Author: chris.l
*/
#include "Arduino.h"
#include "Log.h"
static const char* level_names[LOG_LEVEL_MAX] = {
"NONE",
"ERROR",
"WARN",
"INFO",
"DEBUG",
"TRACE"
};
Log& Log::getLog()
{
static Log log;
return log;
}
Log::Log() :
_level(LOG_LEVEL_INFO),
_size(LOG_MAX_SIZE),
_buffer(nullptr),
_print(nullptr)
{
}
Log::~Log()
{
if (_buffer != nullptr)
{
delete[] _buffer;
}
}
void Log::setSize(size_t size)
{
_size = size;
if (_buffer)
{
delete[] _buffer;
_buffer = nullptr;
}
}
void Log::setLevel(LogLevel level)
{
_level = level;
}
void Log::setLevel(const char* name, LogLevel level)
{
_levels[name] = level;
}
void Log::setPrint(Print *print)
{
_print = print;
}
void Log::setPreFunc(std::function<void(Print* print)> func)
{
pre_func = func;
}
void Log::error(const char* name, const char* fmt, ...)
{
va_list ap;
va_start(ap, fmt);
print(name, LOG_LEVEL_ERROR, fmt, ap);
va_end(ap);
}
void Log::warning(const char* name, const char* fmt, ...)
{
va_list ap;
va_start(ap, fmt);
print(name, LOG_LEVEL_WARNING, fmt, ap);
va_end(ap);
}
void Log::info(const char* name, const char* fmt, ...)
{
va_list ap;
va_start(ap, fmt);
print(name, LOG_LEVEL_INFO, fmt, ap);
va_end(ap);
}
void Log::debug(const char* name, const char* fmt, ...)
{
va_list ap;
va_start(ap, fmt);
print(name, LOG_LEVEL_DEBUG, fmt, ap);
va_end(ap);
}
void Log::trace(const char* name, const char* fmt, ...)
{
va_list ap;
va_start(ap, fmt);
print(name, LOG_LEVEL_TRACE, fmt, ap);
va_end(ap);
}
void Log::print(const char* name, LogLevel level, const char* fmt, va_list ap)
{
LogLevel limit = _level;
if (_levels.find(name) != _levels.end())
{
limit = _levels[name];
}
if (level > limit)
{
return;
}
//
// allocate the buffer on first use
//
if (_buffer == nullptr)
{
_buffer = new char[_size];
}
if (_print == nullptr)
{
_print = &Serial;
}
vsnprintf(_buffer, _size-1, fmt, ap);
if (pre_func)
{
pre_func(_print);
}
_print->printf("%s %5s %s\n", name, level_names[level], _buffer);
}
Log& logger = Log::getLog();

57
Log.h
View File

@ -22,61 +22,8 @@
#ifndef LOG_H_ #ifndef LOG_H_
#define LOG_H_ #define LOG_H_
#include "Print.h" #include "DLog.h"
#include <string>
#include <map>
#include <stdarg.h>
typedef enum log_level extern DLog& dlog;
{
LOG_LEVEL_NONE = 0,
LOG_LEVEL_ERROR,
LOG_LEVEL_WARNING,
LOG_LEVEL_INFO,
LOG_LEVEL_DEBUG,
LOG_LEVEL_TRACE,
LOG_LEVEL_MAX,
} LogLevel;
#define LOG_MAX_SIZE 80
#define LOG_LEVEL_DEFAULT LOG_LEVEL_INFO
class Log
{
public:
static Log& getLog();
void setSize(size_t size);
void setLevel(LogLevel level);
void setLevel(const char* name, LogLevel level);
void setPrint(Print *print);
void setPreFunc(std::function<void(Print* print)> func);
void error(const char* name, const char* fmt, ...);
void warning(const char* name, const char* fmt, ...);
void info(const char* name, const char* fmt, ...);
void debug(const char* name, const char* fmt, ...);
void trace(const char* name, const char* fmt, ...);
// we don't allow copying this guy!
Log(const Log&) = delete;
Log& operator=(const Log&) = delete;
private:
LogLevel _level; // default log level
size_t _size;
char* _buffer;
std::map<std::string, LogLevel> _levels;
Print* _print;
std::function<void(Print* print)> pre_func;
Log();
virtual ~Log();
void print(const char* name, LogLevel level, const char*fmt, va_list ap);
};
extern Log& logger;
#endif /* LOG_H_ */ #endif /* LOG_H_ */

11
NTP.cpp
View File

@ -125,10 +125,11 @@ void NTP::begin()
_precision = computePrecision(); _precision = computePrecision();
while (!_udp.listen(NTP_PORT)) while (!_udp.listen(NTP_PORT))
{ {
logger.error(TAG, "failed to listen on port %d! Will retry in a bit...", NTP_PORT); dlog.error(TAG, F("failed to listen on port %d! Will retry in a bit..."), NTP_PORT);
delay(1000); delay(1000);
logger.warning(TAG, "setup: retrying!"); dlog.warning(TAG, F("setup: retrying!"));
} }
using namespace std::placeholders; // for _1, _2, _3... using namespace std::placeholders; // for _1, _2, _3...
_udp.onPacket(std::bind( &NTP::ntp, this, _1)); _udp.onPacket(std::bind( &NTP::ntp, this, _1));
@ -146,7 +147,7 @@ int8_t NTP::computePrecision()
double total = (double)(end - start) / 1000000.0; double total = (double)(end - start) / 1000000.0;
double time = total / PRECISION_COUNT; double time = total / PRECISION_COUNT;
double prec = log2(time); double prec = log2(time);
logger.info(TAG, "computePrecision: total:%f time:%f prec:%f (%d)", total, time, prec, (int8_t)prec); dlog.info(TAG, F("computePrecision: total:%f time:%f prec:%f (%d)"), total, time, prec, (int8_t)prec);
return (int8_t)prec; return (int8_t)prec;
} }
@ -168,13 +169,13 @@ void NTP::ntp(AsyncUDPPacket& aup)
getNTPTime(&recv_time); getNTPTime(&recv_time);
if (aup.length() != sizeof(NTPPacket)) if (aup.length() != sizeof(NTPPacket))
{ {
logger.warning(TAG, "recievePacket: ignoring packet with bad length: %d < %d", aup.length(), sizeof(NTPPacket)); dlog.warning(TAG, F("recievePacket: ignoring packet with bad length: %d < %d"), aup.length(), sizeof(NTPPacket));
return; return;
} }
if (!_gps.isValid()) if (!_gps.isValid())
{ {
logger.warning(TAG, "recievePacket: GPS data not valid!"); dlog.warning(TAG, F("recievePacket: GPS data not valid!"));
return; return;
} }

10
WireUtils.cpp
View File

@ -43,7 +43,7 @@ WireUtilsC::WireUtilsC()
*/ */
int WireUtilsC::clearBus() int WireUtilsC::clearBus()
{ {
logger.warning(TAG, "WireUtils::ClearBus: attempting to clean i2c bus"); dlog.warning(TAG, F("WireUtils::ClearBus: attempting to clean i2c bus"));
#if defined(TWCR) && defined(TWEN) #if defined(TWCR) && defined(TWEN)
TWCR &= ~(_BV(TWEN)); //Disable the Atmel 2-Wire interface so we can control the SDA and SCL pins directly TWCR &= ~(_BV(TWEN)); //Disable the Atmel 2-Wire interface so we can control the SDA and SCL pins directly
#endif #endif
@ -53,7 +53,7 @@ int WireUtilsC::clearBus()
boolean SCL_LOW = (digitalRead(SCL) == LOW); // Check is SCL is Low. boolean SCL_LOW = (digitalRead(SCL) == LOW); // Check is SCL is Low.
if (SCL_LOW) if (SCL_LOW)
{ //If it is held low Arduno cannot become the I2C master. { //If it is held low Arduno cannot become the I2C master.
logger.error(TAG, "WireUtils::ClearBus: Failed! SCL held low!"); dlog.error(TAG, F("WireUtils::ClearBus: Failed! SCL held low!"));
return 1; //I2C bus error. Could not clear SCL clock line held low return 1; //I2C bus error. Could not clear SCL clock line held low
} }
@ -82,14 +82,14 @@ int WireUtilsC::clearBus()
} }
if (SCL_LOW) if (SCL_LOW)
{ // still low after 2 sec error { // still low after 2 sec error
logger.error(TAG, "WireUtils::ClearBus: Failed! SCL clock line held low by slave clock stretch for >2sec"); dlog.error(TAG, F("WireUtils::ClearBus: Failed! SCL clock line held low by slave clock stretch for >2sec"));
return 2; // I2C bus error. Could not clear. SCL clock line held low by slave clock stretch for >2sec return 2; // I2C bus error. Could not clear. SCL clock line held low by slave clock stretch for >2sec
} }
SDA_LOW = (digitalRead(SDA) == LOW); // and check SDA input again and loop SDA_LOW = (digitalRead(SDA) == LOW); // and check SDA input again and loop
} }
if (SDA_LOW) if (SDA_LOW)
{ // still low { // still low
logger.error(TAG, "WireUtils::ClearBus: Failed! SDA data line still held low"); dlog.error(TAG, F("WireUtils::ClearBus: Failed! SDA data line still held low"));
return 3; // I2C bus error. Could not clear. SDA data line held low return 3; // I2C bus error. Could not clear. SDA data line held low
} }
@ -104,7 +104,7 @@ int WireUtilsC::clearBus()
delayMicroseconds(10); // x. wait >5uS delayMicroseconds(10); // x. wait >5uS
pinMode(SDA, INPUT); // and reset pins as tri-state inputs which is the default state on reset pinMode(SDA, INPUT); // and reset pins as tri-state inputs which is the default state on reset
pinMode(SCL, INPUT); pinMode(SCL, INPUT);
logger.info(TAG, "WireUtils::ClearBus: Success!"); dlog.info(TAG, F("WireUtils::ClearBus: Success!"));
return 0; // all ok return 0; // all ok
} }