Rate-limit duplicate error messages to avoid flooding console.

Fixes artf4809.

In both C++ and Java, error messages are being sent to both the console
(via stdout/stderr) and being reported via the HAL.  We don't want to
remove the stdout/stderr reporting at present because users debugging only
via netconsole (e.g. using riolog) won't see the HAL-reported errors.  Until
there's an alternative means to getting the HAL-reported errors to those
users, instead store the previous 5 error messages and don't duplicate them
more often than once per second.

Changes the error reporting from setErrorData() to sendError(), which
improves driver station error reporting.  The "location" in C++ is given as
the immediate caller (e.g. the WPILib function).  The "location" in Java is
given as the first user function in the call stack.  Note the full call stack
is provided in both instances.

Change-Id: I590dd63dcb66825301ebb260aff00cd8d7d501ed
This commit is contained in:
Peter Johnson
2016-02-04 22:29:11 -08:00
parent f17d27aacf
commit 3c3b2c75c0
12 changed files with 244 additions and 74 deletions

View File

@@ -227,6 +227,9 @@ extern "C"
bool getFPGAButton(int32_t *status);
int HALSetErrorData(const char *errors, int errorsLength, int wait_ms);
int HALSendError(int isError, int32_t errorCode, int isLVCode,
const char *details, const char *location, const char *callStack,
int printMsg);
int HALGetControlWord(HALControlWord *data);
int HALGetAllianceStation(enum HALAllianceStationID *allianceStation);

View File

@@ -32,6 +32,7 @@ static tGlobal *global = nullptr;
static tSysWatchdog *watchdog = nullptr;
static priority_mutex timeMutex;
static priority_mutex msgMutex;
static uint32_t timeEpoch = 0;
static uint32_t prevFPGATime = 0;
static void* rolloverNotifier = nullptr;
@@ -232,6 +233,54 @@ int HALSetErrorData(const char *errors, int errorsLength, int wait_ms)
return setErrorData(errors, errorsLength, wait_ms);
}
int HALSendError(int isError, int32_t errorCode, int isLVCode,
const char *details, const char *location, const char *callStack,
int printMsg)
{
// Avoid flooding console by keeping track of previous 5 error
// messages and only printing again if they're longer than 1 second old.
static constexpr int KEEP_MSGS = 5;
std::lock_guard<priority_mutex> lock(msgMutex);
static std::string prev_msg[KEEP_MSGS];
static uint64_t prev_msg_time[KEEP_MSGS] = { 0, 0, 0 };
int32_t status = 0;
uint64_t curTime = getFPGATime(&status);
int i;
for (i=0; i<KEEP_MSGS; ++i) {
if (prev_msg[i] == details) break;
}
int retval = 0;
if (i == KEEP_MSGS || (curTime - prev_msg_time[i]) >= 1000000) {
retval = FRC_NetworkCommunication_sendError(isError, errorCode, isLVCode, details, location, callStack);
if (printMsg) {
if (location && location[0] != '\0') {
fprintf(stderr, "%s at %s: ",
isError ? "Error" : "Warning",
location);
}
fprintf(stderr, "%s\n", details);
if (callStack && callStack[0] != '\0') {
fprintf(stderr, "%s\n", callStack);
}
}
if (i == KEEP_MSGS) {
// replace the oldest one
i = 0;
uint64_t first = prev_msg_time[0];
for (int j=1; j<KEEP_MSGS; ++j) {
if (prev_msg_time[j] < first) {
first = prev_msg_time[j];
i = j;
}
}
prev_msg[i] = details;
}
prev_msg_time[i] = curTime;
}
return retval;
}
bool HALGetSystemActive(int32_t *status)
{

View File

@@ -31,6 +31,10 @@ class DriverStation : public SensorBase, public RobotStateInterface {
virtual ~DriverStation();
static DriverStation &GetInstance();
static void ReportError(std::string error);
static void ReportWarning(std::string error);
static void ReportError(bool is_error, int32_t code, const std::string& error,
const std::string& location,
const std::string& stack);
static const uint32_t kJoystickPorts = 6;
@@ -97,6 +101,7 @@ class DriverStation : public SensorBase, public RobotStateInterface {
private:
static DriverStation *m_instance;
void ReportJoystickUnpluggedError(std::string message);
void ReportJoystickUnpluggedWarning(std::string message);
void Run();
HALJoystickAxes m_joystickAxes[kJoystickPorts];

View File

@@ -133,6 +133,18 @@ void DriverStation::ReportJoystickUnpluggedError(std::string message) {
}
}
/**
* Reports errors related to unplugged joysticks
* Throttles the errors so that they don't overwhelm the DS
*/
void DriverStation::ReportJoystickUnpluggedWarning(std::string message) {
double currentTime = Timer::GetFPGATimestamp();
if (currentTime > m_nextMessageTime) {
ReportWarning(message);
m_nextMessageTime = currentTime + JOYSTICK_UNPLUGGED_MESSAGE_INTERVAL;
}
}
/**
* Returns the number of axes on a given joystick port
*
@@ -255,9 +267,8 @@ float DriverStation::GetStickAxis(uint32_t stick, uint32_t axis) {
if (axis >= kMaxJoystickAxes)
wpi_setWPIError(BadJoystickAxis);
else
ReportJoystickUnpluggedError(
"WARNING: Joystick Axis missing, check if all controllers are "
"plugged in\n");
ReportJoystickUnpluggedWarning(
"Joystick Axis missing, check if all controllers are plugged in");
return 0.0f;
}
@@ -285,9 +296,8 @@ int DriverStation::GetStickPOV(uint32_t stick, uint32_t pov) {
if (pov >= kMaxJoystickPOVs)
wpi_setWPIError(BadJoystickAxis);
else
ReportJoystickUnpluggedError(
"WARNING: Joystick POV missing, check if all controllers are plugged "
"in\n");
ReportJoystickUnpluggedWarning(
"Joystick POV missing, check if all controllers are plugged in");
return -1;
}
@@ -323,14 +333,13 @@ bool DriverStation::GetStickButton(uint32_t stick, uint8_t button) {
}
if (button > m_joystickButtons[stick].count) {
ReportJoystickUnpluggedError(
"WARNING: Joystick Button missing, check if all controllers are "
"plugged in\n");
ReportJoystickUnpluggedWarning(
"Joystick Button missing, check if all controllers are plugged in");
return false;
}
if (button == 0) {
ReportJoystickUnpluggedError(
"ERROR: Button indexes begin at 1 in WPILib for C++ and Java");
"Button indexes begin at 1 in WPILib for C++ and Java");
return false;
}
return ((0x1 << (button - 1)) & m_joystickButtons[stick].buttons) != 0;
@@ -527,11 +536,25 @@ double DriverStation::GetMatchTime() const {
* The error is also printed to the program console.
*/
void DriverStation::ReportError(std::string error) {
std::cout << error << std::endl;
HALControlWord controlWord;
HALGetControlWord(&controlWord);
if (controlWord.dsAttached) {
HALSetErrorData(error.c_str(), error.size(), 0);
}
HALSendError(1, 1, 0, error.c_str(), "", "", 1);
}
/**
* Report a warning to the DriverStation messages window.
* The warning is also printed to the program console.
*/
void DriverStation::ReportWarning(std::string error) {
HALSendError(0, 1, 0, error.c_str(), "", "", 1);
}
/**
* Report an error to the DriverStation messages window.
* The error is also printed to the program console.
*/
void DriverStation::ReportError(bool is_error, int32_t code,
const std::string &error,
const std::string &location,
const std::string &stack) {
HALSendError(is_error, code, 0, error.c_str(), location.c_str(),
stack.c_str(), 1);
}

View File

@@ -29,11 +29,13 @@ bool wpi_assert_impl(bool conditionValue, const char *conditionText,
const char *message, const char *fileName,
uint32_t lineNumber, const char *funcName) {
if (!conditionValue) {
std::stringstream locStream;
locStream << funcName << " [";
locStream << basename(fileName) << ":" << lineNumber << "]";
std::stringstream errorStream;
errorStream << "Assertion \"" << conditionText << "\" ";
errorStream << "on line " << lineNumber << " ";
errorStream << "of " << basename(fileName) << " ";
if (message[0] != '\0') {
errorStream << "failed: " << message << std::endl;
@@ -41,13 +43,12 @@ bool wpi_assert_impl(bool conditionValue, const char *conditionText,
errorStream << "failed." << std::endl;
}
errorStream << GetStackTrace(2);
std::string stack = GetStackTrace(2);
std::string location = locStream.str();
std::string error = errorStream.str();
// Print the error and send it to the DriverStation
std::cout << error << std::endl;
HALSetErrorData(error.c_str(), error.size(), 100);
HALSendError(1, 1, 0, error.c_str(), location.c_str(), stack.c_str(), 1);
}
return conditionValue;
@@ -65,12 +66,14 @@ void wpi_assertEqual_common_impl(const char *valueA, const char *valueB,
const char *fileName,
uint32_t lineNumber,
const char *funcName) {
std::stringstream locStream;
locStream << funcName << " [";
locStream << basename(fileName) << ":" << lineNumber << "]";
std::stringstream errorStream;
errorStream << "Assertion \"" << valueA << " " << equalityType << " "
<< valueB << "\" ";
errorStream << "on line " << lineNumber << " ";
errorStream << "of " << basename(fileName) << " ";
if (message[0] != '\0') {
errorStream << "failed: " << message << std::endl;
@@ -78,13 +81,12 @@ void wpi_assertEqual_common_impl(const char *valueA, const char *valueB,
errorStream << "failed." << std::endl;
}
errorStream << GetStackTrace(3);
std::string trace = GetStackTrace(3);
std::string location = locStream.str();
std::string error = errorStream.str();
// Print the error and send it to the DriverStation
std::cout << error << std::endl;
HALSetErrorData(error.c_str(), error.size(), 100);
HALSendError(1, 1, 0, error.c_str(), location.c_str(), trace.c_str(), 1);
}
/**

View File

@@ -66,24 +66,21 @@ void Error::Set(Code code, llvm::StringRef contextMessage,
}
void Error::Report() {
std::stringstream errorStream;
std::stringstream locStream;
locStream << m_function << " [";
errorStream << "Error on line " << m_lineNumber << " ";
#if defined(_UNIX)
errorStream << "of " << basename(m_filename.c_str()) << ": ";
#elif defined(_WIN32)
#if defined(_WIN32)
const int MAX_DIR = 100;
char basename[MAX_DIR];
_splitpath_s(m_filename.c_str(), NULL, 0, basename, MAX_DIR, NULL, 0, NULL, 0);
errorStream << "of " << basename << ": ";
locStream << basename;
#else
locStream << basename(m_filename.c_str());
#endif
locStream << ":" << m_lineNumber << "]";
errorStream << m_message << std::endl;
errorStream << GetStackTrace(4);
std::string error = errorStream.str();
DriverStation::ReportError(error);
DriverStation::ReportError(true, m_code, m_message, locStream.str(),
GetStackTrace(4));
}
void Error::Clear() {

View File

@@ -42,6 +42,8 @@ public:
virtual ~DriverStation() = default;
static DriverStation &GetInstance();
static void ReportError(std::string error);
static void ReportWarning(std::string error);
static void ReportError(bool is_error, int32_t code, const std::string& error, const std::string& location, const std::string& stack);
static const uint32_t kBatteryChannel = 7;
static const uint32_t kJoystickPorts = 4;

View File

@@ -315,6 +315,31 @@ void DriverStation::ReportError(std::string error)
std::cout << error << std::endl;
}
/**
* Report a warning to the DriverStation messages window.
* The warning is also printed to the program console.
*/
void DriverStation::ReportWarning(std::string error)
{
std::cout << error << std::endl;
}
/**
* Report an error to the DriverStation messages window.
* The error is also printed to the program console.
*/
void DriverStation::ReportError(bool is_error, int32_t code,
const std::string& error,
const std::string& location,
const std::string& stack)
{
if (!location.empty())
std::cout << (is_error ? "Error" : "Warning") << " at " << location << ": ";
std::cout << error << std::endl;
if (!stack.empty())
std::cout << stack << std::endl;
}
/**
* Return the team number that the Driver Station is configured for
* @return The team number

View File

@@ -323,4 +323,26 @@ JNIEXPORT jint JNICALL Java_edu_wpi_first_wpilibj_communication_FRCNetworkCommun
return returnValue;
}
/*
* Class: edu_wpi_first_wpilibj_communication_FRCNetworkCommunicationsLibrary
* Method: HALSendError
* Signature: (ZIZLjava/lang/String;Ljava/lang/String;Ljava/lang/String;Z)I
*/
JNIEXPORT jint JNICALL Java_edu_wpi_first_wpilibj_communication_FRCNetworkCommunicationsLibrary_HALSendError
(JNIEnv * env, jclass, jboolean isError, jint errorCode, jboolean isLVCode, jstring details, jstring location, jstring callStack, jboolean printMsg)
{
const char * detailsStr = env->GetStringUTFChars(details, NULL);
const char * locationStr = env->GetStringUTFChars(location, NULL);
const char * callStackStr = env->GetStringUTFChars(callStack, NULL);
NETCOMM_LOG(logDEBUG) << "Send Error: " << detailsStr;
NETCOMM_LOG(logDEBUG) << "Location: " << locationStr;
NETCOMM_LOG(logDEBUG) << "Call Stack: " << callStackStr;
jint returnValue = HALSendError(isError, errorCode, isLVCode, detailsStr, locationStr, callStackStr, printMsg);
env->ReleaseStringUTFChars(details,detailsStr);
env->ReleaseStringUTFChars(location,locationStr);
env->ReleaseStringUTFChars(callStack,callStackStr);
return returnValue;
}
} // extern "C"

View File

@@ -14,6 +14,7 @@
#include "HAL/HAL.hpp"
#include "errno.h"
#include <string.h>
#include <cstring>
#include <string>
// set the logging level
@@ -42,7 +43,7 @@ static jclass canMessageNotAllowedExCls = nullptr;
static jclass canNotInitializedExCls = nullptr;
static jclass uncleanStatusExCls = nullptr;
static void GetStackTrace(JNIEnv *env, std::string& res) {
static void GetStackTrace(JNIEnv *env, std::string& res, std::string& func) {
// create a throwable
static jmethodID constructorId = nullptr;
if (!constructorId)
@@ -72,6 +73,7 @@ static void GetStackTrace(JNIEnv *env, std::string& res) {
toStringId = env->GetMethodID(stackTraceElementCls, "toString",
"()Ljava/lang/String;");
bool haveLoc = false;
for (jsize i = 0; i < stackTraceLength; i++) {
// add the result of toString method of each element in the result
jobject curStackTraceElement = env->GetObjectArrayElement(stackTrace, i);
@@ -91,6 +93,16 @@ static void GetStackTrace(JNIEnv *env, std::string& res) {
const char *tmp = env->GetStringUTFChars(stackElementString, nullptr);
res += tmp;
res += '\n';
// func is caller of immediate caller (if there was one)
// or, if we see it, the first user function
if (i == 1)
func = tmp;
else if (i > 1 && !haveLoc &&
std::strncmp(tmp, "edu.wpi.first.wpilibj", 21) != 0) {
func = tmp;
haveLoc = true;
}
env->ReleaseStringUTFChars(stackElementString, tmp);
env->DeleteLocalRef(curStackTraceElement);
@@ -110,14 +122,10 @@ void ReportError(JNIEnv *env, int32_t status, bool do_throw) {
env->ThrowNew(runtimeExCls, buf);
delete[] buf;
} else {
std::string fullmsg = message;
fullmsg += " at ";
GetStackTrace(env, fullmsg);
fprintf(stderr, "%s\n", fullmsg.c_str());
HALControlWord controlWord;
HALGetControlWord(&controlWord);
if (controlWord.dsAttached)
HALSetErrorData(fullmsg.c_str(), fullmsg.size(), 0);
std::string stack = " at ";
std::string func;
GetStackTrace(env, stack, func);
HALSendError(1, status, 0, message, func.c_str(), stack.c_str(), 1);
}
}

View File

@@ -211,6 +211,18 @@ public class DriverStation implements RobotState.Interface {
}
}
/**
* Reports errors related to unplugged joysticks Throttles the errors so that
* they don't overwhelm the DS
*/
private void reportJoystickUnpluggedWarning(String message) {
double currentTime = Timer.getFPGATimestamp();
if (currentTime > m_nextMessageTime) {
reportWarning(message, false);
m_nextMessageTime = currentTime + JOYSTICK_UNPLUGGED_MESSAGE_INTERVAL;
}
}
/**
* Get the value of the axis on a joystick. This depends on the mapping of the
* joystick connected to the specified port.
@@ -229,8 +241,8 @@ public class DriverStation implements RobotState.Interface {
}
if (axis >= m_joystickAxes[stick].length) {
reportJoystickUnpluggedError("WARNING: Joystick axis " + axis + " on port " + stick
+ " not available, check if controller is plugged in\n");
reportJoystickUnpluggedWarning("Joystick axis " + axis + " on port " + stick
+ " not available, check if controller is plugged in");
return 0.0;
}
@@ -273,8 +285,8 @@ public class DriverStation implements RobotState.Interface {
}
if (pov >= m_joystickPOVs[stick].length) {
reportJoystickUnpluggedError("WARNING: Joystick POV " + pov + " on port " + stick
+ " not available, check if controller is plugged in\n");
reportJoystickUnpluggedWarning("Joystick POV " + pov + " on port " + stick
+ " not available, check if controller is plugged in");
return -1;
}
@@ -324,12 +336,12 @@ public class DriverStation implements RobotState.Interface {
if (button > m_joystickButtons[stick].count) {
reportJoystickUnpluggedError("WARNING: Joystick Button " + button + " on port " + stick
+ " not available, check if controller is plugged in\n");
reportJoystickUnpluggedWarning("Joystick Button " + button + " on port " + stick
+ " not available, check if controller is plugged in");
return false;
}
if (button <= 0) {
reportJoystickUnpluggedError("ERROR: Button indexes begin at 1 in WPILib for C++ and Java\n");
reportJoystickUnpluggedError("Button indexes begin at 1 in WPILib for C++ and Java");
return false;
}
return ((0x1 << (button - 1)) & m_joystickButtons[stick].buttons) != 0;
@@ -365,8 +377,8 @@ public class DriverStation implements RobotState.Interface {
// TODO: Remove this when calling for descriptor on empty stick no longer
// crashes
if (1 > m_joystickButtons[stick].count && 1 > m_joystickAxes[stick].length) {
reportJoystickUnpluggedError("WARNING: Joystick on port " + stick
+ " not available, check if controller is plugged in\n");
reportJoystickUnpluggedWarning("Joystick on port " + stick
+ " not available, check if controller is plugged in");
return false;
}
boolean retVal = false;
@@ -390,8 +402,8 @@ public class DriverStation implements RobotState.Interface {
// TODO: Remove this when calling for descriptor on empty stick no longer
// crashes
if (1 > m_joystickButtons[stick].count && 1 > m_joystickAxes[stick].length) {
reportJoystickUnpluggedError("WARNING: Joystick on port " + stick
+ " not available, check if controller is plugged in\n");
reportJoystickUnpluggedWarning("Joystick on port " + stick
+ " not available, check if controller is plugged in");
return -1;
}
return FRCNetworkCommunicationsLibrary.HALGetJoystickType((byte) stick);
@@ -411,8 +423,8 @@ public class DriverStation implements RobotState.Interface {
// TODO: Remove this when calling for descriptor on empty stick no longer
// crashes
if (1 > m_joystickButtons[stick].count && 1 > m_joystickAxes[stick].length) {
reportJoystickUnpluggedError("WARNING: Joystick on port " + stick
+ " not available, check if controller is plugged in\n");
reportJoystickUnpluggedWarning("Joystick on port " + stick
+ " not available, check if controller is plugged in");
return "";
}
return FRCNetworkCommunicationsLibrary.HALGetJoystickName((byte) stick);
@@ -600,19 +612,39 @@ public class DriverStation implements RobotState.Interface {
* @param printTrace If true, append stack trace to error string
*/
public static void reportError(String error, boolean printTrace) {
String errorString = error;
if (printTrace) {
errorString += " at ";
StackTraceElement[] traces = Thread.currentThread().getStackTrace();
for (int i = 2; i < traces.length; i++) {
errorString += traces[i].toString() + "\n";
reportErrorImpl(true, 1, error, printTrace);
}
/**
* Report warning to Driver Station. Also prints error to System.err Optionally
* appends Stack trace to warning message
*$
* @param printTrace If true, append stack trace to warning string
*/
public static void reportWarning(String error, boolean printTrace) {
reportErrorImpl(false, 1, error, printTrace);
}
private static void reportErrorImpl(boolean is_error, int code, String error, boolean printTrace) {
StackTraceElement[] traces = Thread.currentThread().getStackTrace();
String locString;
if (traces.length > 3)
locString = traces[3].toString();
else
locString = new String();
boolean haveLoc = false;
String traceString = new String();
traceString = " at ";
for (int i = 3; i < traces.length; i++) {
String loc = traces[i].toString();
traceString += loc + "\n";
// get first user function
if (!haveLoc && !loc.startsWith("edu.wpi.first.wpilibj")) {
locString = loc;
haveLoc = true;
}
}
System.err.println(errorString);
HALControlWord controlWord = FRCNetworkCommunicationsLibrary.HALGetControlWord();
if (controlWord.getDSAttached()) {
FRCNetworkCommunicationsLibrary.HALSetErrorData(errorString);
}
FRCNetworkCommunicationsLibrary.HALSendError(is_error, code, false, error, locString, printTrace ? traceString : "", true);
}
/**

View File

@@ -233,4 +233,6 @@ public class FRCNetworkCommunicationsLibrary extends JNIWrapper {
public static native boolean HALGetBrownedOut();
public static native int HALSetErrorData(String error);
public static native int HALSendError(boolean isError, int errorCode, boolean isLVCode, String details, String location, String callStack, boolean printMsg);
}