From 3c3b2c75c0ac0624ec6ac4f9b2ab1545a20a95aa Mon Sep 17 00:00:00 2001 From: Peter Johnson Date: Thu, 4 Feb 2016 22:29:11 -0800 Subject: [PATCH] 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 --- hal/include/HAL/HAL.hpp | 3 + hal/lib/Athena/HALAthena.cpp | 49 ++++++++++++ wpilibc/Athena/include/DriverStation.h | 5 ++ wpilibc/Athena/src/DriverStation.cpp | 57 +++++++++---- wpilibc/Athena/src/Utility.cpp | 26 +++--- wpilibc/shared/src/Error.cpp | 21 +++-- wpilibc/simulation/include/DriverStation.h | 2 + wpilibc/simulation/src/DriverStation.cpp | 25 ++++++ .../lib/FRCNetworkCommunicationsLibrary.cpp | 22 +++++ wpilibj/src/athena/cpp/lib/HALUtil.cpp | 26 +++--- .../edu/wpi/first/wpilibj/DriverStation.java | 80 +++++++++++++------ .../FRCNetworkCommunicationsLibrary.java | 2 + 12 files changed, 244 insertions(+), 74 deletions(-) diff --git a/hal/include/HAL/HAL.hpp b/hal/include/HAL/HAL.hpp index 75c72e38f7..fb3c6aa325 100644 --- a/hal/include/HAL/HAL.hpp +++ b/hal/include/HAL/HAL.hpp @@ -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); diff --git a/hal/lib/Athena/HALAthena.cpp b/hal/lib/Athena/HALAthena.cpp index ec1c162c26..3a392f189e 100644 --- a/hal/lib/Athena/HALAthena.cpp +++ b/hal/lib/Athena/HALAthena.cpp @@ -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 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= 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 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); } diff --git a/wpilibc/Athena/src/Utility.cpp b/wpilibc/Athena/src/Utility.cpp index f3b06664a9..d675e60f6b 100644 --- a/wpilibc/Athena/src/Utility.cpp +++ b/wpilibc/Athena/src/Utility.cpp @@ -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); } /** diff --git a/wpilibc/shared/src/Error.cpp b/wpilibc/shared/src/Error.cpp index c281e99386..5237a923b3 100644 --- a/wpilibc/shared/src/Error.cpp +++ b/wpilibc/shared/src/Error.cpp @@ -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() { diff --git a/wpilibc/simulation/include/DriverStation.h b/wpilibc/simulation/include/DriverStation.h index 58cbc9e53b..b96f1a7e9e 100644 --- a/wpilibc/simulation/include/DriverStation.h +++ b/wpilibc/simulation/include/DriverStation.h @@ -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; diff --git a/wpilibc/simulation/src/DriverStation.cpp b/wpilibc/simulation/src/DriverStation.cpp index 815eb362b3..274cb1870f 100644 --- a/wpilibc/simulation/src/DriverStation.cpp +++ b/wpilibc/simulation/src/DriverStation.cpp @@ -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 diff --git a/wpilibj/src/athena/cpp/lib/FRCNetworkCommunicationsLibrary.cpp b/wpilibj/src/athena/cpp/lib/FRCNetworkCommunicationsLibrary.cpp index bfa266d058..3219254c75 100644 --- a/wpilibj/src/athena/cpp/lib/FRCNetworkCommunicationsLibrary.cpp +++ b/wpilibj/src/athena/cpp/lib/FRCNetworkCommunicationsLibrary.cpp @@ -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" diff --git a/wpilibj/src/athena/cpp/lib/HALUtil.cpp b/wpilibj/src/athena/cpp/lib/HALUtil.cpp index b82dc995c1..276b6b6875 100644 --- a/wpilibj/src/athena/cpp/lib/HALUtil.cpp +++ b/wpilibj/src/athena/cpp/lib/HALUtil.cpp @@ -14,6 +14,7 @@ #include "HAL/HAL.hpp" #include "errno.h" #include +#include #include // 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); } } diff --git a/wpilibj/src/athena/java/edu/wpi/first/wpilibj/DriverStation.java b/wpilibj/src/athena/java/edu/wpi/first/wpilibj/DriverStation.java index c6a2c9ee43..650b271bb9 100644 --- a/wpilibj/src/athena/java/edu/wpi/first/wpilibj/DriverStation.java +++ b/wpilibj/src/athena/java/edu/wpi/first/wpilibj/DriverStation.java @@ -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); } /** diff --git a/wpilibj/src/athena/java/edu/wpi/first/wpilibj/communication/FRCNetworkCommunicationsLibrary.java b/wpilibj/src/athena/java/edu/wpi/first/wpilibj/communication/FRCNetworkCommunicationsLibrary.java index 1146a459c8..fdc2f9db2d 100644 --- a/wpilibj/src/athena/java/edu/wpi/first/wpilibj/communication/FRCNetworkCommunicationsLibrary.java +++ b/wpilibj/src/athena/java/edu/wpi/first/wpilibj/communication/FRCNetworkCommunicationsLibrary.java @@ -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); }