copying branch over from other 2013 repo
diff --git a/aos/common/logging/logging.gyp b/aos/common/logging/logging.gyp
new file mode 100644
index 0000000..52d2527
--- /dev/null
+++ b/aos/common/logging/logging.gyp
@@ -0,0 +1,15 @@
+{
+ 'targets': [
+ {
+ 'target_name': 'logging_impl_test',
+ 'type': '<(aos_target)',
+ 'sources': [
+ 'logging_impl_test.cc',
+ ],
+ 'dependencies': [
+ '<(EXTERNALS):gtest',
+ '<(AOS)/build/aos.gyp:libaos',
+ ],
+ },
+ ],
+}
diff --git a/aos/common/logging/logging.h b/aos/common/logging/logging.h
index e3ff839..392fc5b 100644
--- a/aos/common/logging/logging.h
+++ b/aos/common/logging/logging.h
@@ -1,102 +1,114 @@
#ifndef AOS_COMMON_LOGGING_LOGGING_H_
-// must be kept in sync with crio/logging/crio_logging.h and atom_code/logging/atom_logging.h
#define AOS_COMMON_LOGGING_LOGGING_H_
+// This file contains the logging client interface. It works with both C and C++
+// code.
+
+#include <stdio.h>
#include <stdint.h>
-#include <sys/types.h>
-#include <unistd.h>
-#include <string.h>
#ifdef __cplusplus
extern "C" {
#endif
typedef uint8_t log_level;
+
#define DECL_LEVELS \
DECL_LEVEL(DEBUG, 0); /* stuff that gets printed out every cycle */ \
DECL_LEVEL(INFO, 1); /* things like PosEdge/NegEdge */ \
-/* things that might still work if they happen occasionally but should be watched */ \
+/* things that might still work if they happen occasionally */ \
DECL_LEVEL(WARNING, 2); \
/*-1 so that vxworks macro of same name will have same effect if used*/ \
DECL_LEVEL(ERROR, -1); /* errors */ \
-DECL_LEVEL(FATAL, 4); /* serious errors. the logging code will terminate the process/task */ \
+/* serious errors. the logging code will terminate the process/task */ \
+DECL_LEVEL(FATAL, 4); \
DECL_LEVEL(LOG_UNKNOWN, 5); /* unknown logging level */
-#define DECL_LEVEL(name, value) extern const log_level name;
+#define DECL_LEVEL(name, value) static const log_level name = value;
#undef ERROR
-DECL_LEVELS
+DECL_LEVELS;
#undef DECL_LEVEL
#define STRINGIFY(x) TO_STRING(x)
#define TO_STRING(x) #x
//not static const size_t for c code
-#define LOG_MESSAGE_LEN 300
+#define LOG_MESSAGE_LEN 500
+
+#ifdef __VXWORKS__
+// We're using ancient glibc, so sticking to just what the syscall can handle is
+// probably safer.
+#define LOG_PRINTF_FORMAT_TYPE printf
+#else
+#define LOG_PRINTF_FORMAT_TYPE gnu_printf
+#endif
+#ifdef __cplusplus
+extern "C" {
+#endif
+// Actually implements the basic logging call.
+// Does not check that level is valid.
+void log_do(log_level level, const char *format, ...)
+ __attribute__((format(LOG_PRINTF_FORMAT_TYPE, 2, 3)));
+
+void log_cork(int line, const char *function, const char *format, ...)
+ __attribute__((format(LOG_PRINTF_FORMAT_TYPE, 3, 4)));
+// Implements the uncork logging call.
+void log_uncork(int line, const char *function, log_level level,
+ const char *file, const char *format, ...)
+ __attribute__((format(LOG_PRINTF_FORMAT_TYPE, 5, 6)));
+#ifdef __cplusplus
+}
+#endif
+
+// A magical static const char[] or string literal that communicates the name
+// of the enclosing function.
+// It's currently using __PRETTY_FUNCTION__ because both GCC and Clang support
+// that and it gives nicer results in C++ than the standard __func__ (which
+// would also work).
+#define LOG_CURRENT_FUNCTION __PRETTY_FUNCTION__
+
+// The basic logging call.
+#define LOG(level, format, args...) do {\
+ log_do(level, LOG_SOURCENAME ": " STRINGIFY(__LINE__) ": %s: " format, \
+ LOG_CURRENT_FUNCTION, ##args); \
+ /* so that GCC knows that it won't return */ \
+ if (level == FATAL) { \
+ fprintf(stderr, "log_do(FATAL) fell through!!!!!\n"); \
+ printf("see stderr\n"); \
+ abort(); \
+ } \
+} while (0)
// Allows format to not be a string constant.
-#define LOG_DYNAMIC(level, format, args...) do{ \
+#define LOG_DYNAMIC(level, format, args...) do { \
static char log_buf[LOG_MESSAGE_LEN]; \
int ret = snprintf(log_buf, sizeof(log_buf), format, ##args); \
- if(ret < 0 || (uintmax_t)ret >= LOG_MESSAGE_LEN){ \
- LOG(WARNING, "next message was too long so not subbing in args\n"); \
+ if (ret < 0 || (uintmax_t)ret >= LOG_MESSAGE_LEN) { \
+ LOG(ERROR, "next message was too long so not subbing in args\n"); \
LOG(level, "%s", format); \
}else{ \
LOG(level, "%s", log_buf); \
} \
-}while(0)
+} while (0)
-// The struct that the crio-side code uses for making logging calls.
-// Packed so it's the same on the atom and the crio.
-typedef struct {
- // pid_t here at the front like in log_message
- pid_t identifier; // must ALWAYS be -1 to identify that this is a crio log message
- log_level level;
- // still has to fit in LOG_MESSAGE_LEN on the atom side
- char message[LOG_MESSAGE_LEN - 50];
- double time;
- uint8_t sequence;
-} __attribute__((packed)) log_crio_message;
+// Allows "bottling up" multiple log fragments which can then all be logged in
+// one message with LOG_UNCORK.
+// Calls from a given thread/task will be grouped together.
+#define LOG_CORK(format, args...) do { \
+ log_cork(__LINE__, LOG_CURRENT_FUNCTION, format, ##args); \
+} while (0)
+// Actually logs all of the saved up log fragments (including format and args on
+// the end).
+#define LOG_UNCORK(level, format, args...) do { \
+ log_uncork(__LINE__, LOG_CURRENT_FUNCTION, level, LOG_SOURCENAME, \
+ format, ##args); \
+} while (0)
-#ifdef __cplusplus
-// Just sticks the message into the shared memory queue.
-int log_crio_message_send(log_crio_message &to_send);
-// Returns left > right. LOG_UNKNOWN is most important.
-static inline bool log_gt_important(log_level left, log_level right) {
- log_level l = left, r = right;
- if (l == ERROR) l = 3;
- if (r == ERROR) r = 3;
- return left > right;
-}
-#endif
-
-// Returns a string representing level or "unknown".
-static inline const char *log_str(log_level level) {
- // c doesn't really have const variables so they don't work in case statements
- if (level == DEBUG) return "DEBUG";
- if (level == INFO) return "INFO";
- if (level == WARNING) return "WARNING";
- if (level == ERROR) return "ERROR";
- if (level == FATAL) return "FATAL";
- return "unknown";
-}
-// Returns the log level represented by str or LOG_UNKNOWN.
-static inline log_level str_log(const char *str) {
- if (!strcmp(str, "DEBUG")) return DEBUG;
- if (!strcmp(str, "INFO")) return INFO;
- if (!strcmp(str, "WARNING")) return WARNING;
- if (!strcmp(str, "ERROR")) return ERROR;
- if (!strcmp(str, "FATAL")) return FATAL;
- return LOG_UNKNOWN;
-}
+// TODO(brians) add CHECK macros like glog
+// (<http://google-glog.googlecode.com/svn/trunk/doc/glog.html>)
+// and replace assert with one
#ifdef __cplusplus
}
#endif
-#ifdef __unix
-#include "aos/atom_code/logging/atom_logging.h" // IWYU pragma: export
-#else
-#include "aos/crio/logging/crio_logging.h" // IWYU pragma: export
#endif
-
-#endif
-
diff --git a/aos/common/logging/logging_impl.cc b/aos/common/logging/logging_impl.cc
new file mode 100644
index 0000000..66e64d8
--- /dev/null
+++ b/aos/common/logging/logging_impl.cc
@@ -0,0 +1,230 @@
+#include "aos/common/logging/logging_impl.h"
+
+#include <assert.h>
+
+#include "aos/common/die.h"
+#include "aos/common/time.h"
+#include "aos/common/inttypes.h"
+#include "aos/common/once.h"
+
+namespace aos {
+namespace logging {
+namespace {
+
+using internal::Context;
+
+LogImplementation *global_top_implementation(NULL);
+// Just going to use a mutex instead of getting fancy because speed doesn't
+// really matter when accessing global_top_implementation.
+Mutex global_top_implementation_mutex;
+LogImplementation *get_global_top_implementation() {
+ MutexLocker locker(&global_top_implementation_mutex);
+ return global_top_implementation;
+}
+
+// The root LogImplementation. It only logs to stderr/stdout.
+// Some of the things specified in the LogImplementation documentation doesn't
+// apply here (mostly the parts about being able to use LOG) because this is the
+// root one.
+class RootLogImplementation : public LogImplementation {
+ virtual void set_next(LogImplementation *) {
+ LOG(FATAL, "can't have a next logger from here\n");
+ }
+
+ virtual void DoLog(log_level level, const char *format, va_list ap) {
+ LogMessage message;
+ internal::FillInMessage(level, format, ap, &message);
+ internal::PrintMessage(stderr, message);
+ fputs("root logger got used, see stderr for message\n", stdout);
+ }
+};
+
+void SetGlobalImplementation(LogImplementation *implementation) {
+ Context *context = Context::Get();
+
+ context->implementation = implementation;
+ {
+ MutexLocker locker(&global_top_implementation_mutex);
+ global_top_implementation = implementation;
+ }
+}
+
+// Prints format (with ap) into output and correctly deals with the result
+// being too long etc.
+void ExecuteFormat(char *output, size_t output_size,
+ const char *format, va_list ap) {
+ static const char *continued = "...\n";
+ const size_t size = output_size - strlen(continued);
+ const int ret = vsnprintf(output, size, format, ap);
+ if (ret < 0) {
+ LOG(FATAL, "vsnprintf(%p, %zd, %s, %p) failed with %d (%s)\n",
+ output, size, format, ap, errno, strerror(errno));
+ } else if (static_cast<uintmax_t>(ret) >= static_cast<uintmax_t>(size)) {
+ // Overwrite the '\0' at the end of the existing data and
+ // copy in the one on the end of continued.
+ memcpy(&output[size - 1], continued, strlen(continued) + 1);
+ }
+}
+
+void *DoInit() {
+ SetGlobalImplementation(new RootLogImplementation());
+ return NULL;
+}
+
+} // namespace
+namespace internal {
+
+Context::Context()
+ : implementation(get_global_top_implementation()),
+ sequence(0) {
+ cork_data.Reset();
+}
+
+void FillInMessage(log_level level, const char *format, va_list ap,
+ LogMessage *message) {
+ Context *context = Context::Get();
+
+ ExecuteFormat(message->message, sizeof(message->message), format, ap);
+
+ message->level = level;
+ message->source = context->source;
+ memcpy(message->name, context->name, context->name_size);
+
+ time::Time now = time::Time::Now();
+ message->seconds = now.sec();
+ message->nseconds = now.nsec();
+
+ message->sequence = context->sequence++;
+}
+
+void PrintMessage(FILE *output, const LogMessage &message) {
+ fprintf(output, "%s(%"PRId32")(%05"PRIu16"): %s at"
+ " %010"PRId32".%09"PRId32"s: %s",
+ message.name, message.source, message.sequence,
+ log_str(message.level), message.seconds, message.nseconds,
+ message.message);
+}
+
+} // namespace internal
+
+void LogImplementation::DoVLog(log_level level, const char *format, va_list ap,
+ int levels) {
+ Context *context = Context::Get();
+
+ LogImplementation *top_implementation = context->implementation;
+ LogImplementation *new_implementation = top_implementation;
+ LogImplementation *implementation = NULL;
+ assert(levels >= 1);
+ for (int i = 0; i < levels; ++i) {
+ implementation = new_implementation;
+ if (new_implementation == NULL) {
+ Die("no logging implementation to use\n");
+ }
+ new_implementation = new_implementation->next();
+ }
+ context->implementation = new_implementation;
+ implementation->DoLog(level, format, ap);
+ context->implementation = top_implementation;
+
+ if (level == FATAL) {
+ VDie(format, ap);
+ }
+}
+
+void VLog(log_level level, const char *format, va_list ap) {
+ LogImplementation::DoVLog(level, format, ap, 1);
+}
+
+void VCork(int line, const char *function, const char *format, va_list ap) {
+ Context *context = Context::Get();
+
+ const size_t message_length = strlen(context->cork_data.message);
+ if (line > context->cork_data.line_max) context->cork_data.line_max = line;
+ if (line < context->cork_data.line_min) context->cork_data.line_min = line;
+
+ if (context->cork_data.function == NULL) {
+ context->cork_data.function = function;
+ } else {
+ if (strcmp(context->cork_data.function, function) != 0) {
+ LOG(FATAL, "started corking data in function %s but then moved to %s\n",
+ context->cork_data.function, function);
+ }
+ }
+
+ ExecuteFormat(context->cork_data.message + message_length,
+ sizeof(context->cork_data.message) - message_length,
+ format, ap);
+}
+
+void VUnCork(int line, const char *function, log_level level, const char *file,
+ const char *format, va_list ap) {
+ Context *context = Context::Get();
+
+ VCork(line, function, format, ap);
+
+ log_do(level, "%s: %d-%d: %s: %s", file,
+ context->cork_data.line_min, context->cork_data.line_max, function,
+ context->cork_data.message);
+
+ context->cork_data.Reset();
+}
+
+void LogNext(log_level level, const char *format, ...) {
+ va_list ap;
+ va_start(ap, format);
+ LogImplementation::DoVLog(level, format, ap, 2);
+ va_end(ap);
+}
+
+void AddImplementation(LogImplementation *implementation) {
+ Context *context = Context::Get();
+
+ if (implementation->next() != NULL) {
+ LOG(FATAL, "%p already has a next implementation, but it's not"
+ " being used yet\n", implementation);
+ }
+
+ LogImplementation *old = context->implementation;
+ if (old != NULL) {
+ implementation->set_next(old);
+ }
+ SetGlobalImplementation(implementation);
+}
+
+void Init() {
+ static Once<void> once(DoInit);
+ once.Get();
+}
+
+void Load() {
+ Context::Get();
+}
+
+void Cleanup() {
+ Context::Delete();
+}
+
+} // namespace logging
+} // namespace aos
+
+void log_do(log_level level, const char *format, ...) {
+ va_list ap;
+ va_start(ap, format);
+ aos::logging::VLog(level, format, ap);
+ va_end(ap);
+}
+
+void log_cork(int line, const char *function, const char *format, ...) {
+ va_list ap;
+ va_start(ap, format);
+ aos::logging::VCork(line, function, format, ap);
+ va_end(ap);
+}
+
+void log_uncork(int line, const char *function, log_level level,
+ const char *file, const char *format, ...) {
+ va_list ap;
+ va_start(ap, format);
+ aos::logging::VUnCork(line, function, level, file, format, ap);
+ va_end(ap);
+}
diff --git a/aos/common/logging/logging_impl.h b/aos/common/logging/logging_impl.h
new file mode 100644
index 0000000..0b1e256
--- /dev/null
+++ b/aos/common/logging/logging_impl.h
@@ -0,0 +1,205 @@
+#ifndef AOS_COMMON_LOGGING_LOGGING_IMPL_H_
+#define AOS_COMMON_LOGGING_LOGGING_IMPL_H_
+
+#include <sys/types.h>
+#include <unistd.h>
+#include <stdint.h>
+#include <limits.h>
+#include <string.h>
+#include <stdio.h>
+
+#include <string>
+
+#include "aos/common/logging/logging.h"
+#include "aos/common/type_traits.h"
+#include "aos/common/mutex.h"
+
+// This file has all of the logging implementation. It can't be #included by C
+// code like logging.h can.
+
+namespace aos {
+namespace logging {
+
+// Unless explicitly stated otherwise, format must always be a string constant,
+// args are printf-style arguments for format, and ap is a va_list of args.
+// The validitiy of format and args together will be checked at compile time
+// using a gcc function attribute.
+
+// The struct that the code uses for making logging calls.
+// Packed so that it ends up the same under both linux and vxworks.
+struct __attribute__((packed)) LogMessage {
+#ifdef __VXWORKS__
+ static_assert(sizeof(pid_t) == sizeof(int),
+ "we use task IDs (aka ints) and pid_t interchangeably");
+#endif
+ // Actually the task ID (aka a pointer to the TCB) on the cRIO.
+ pid_t source;
+ static_assert(sizeof(source) == 4, "that's how they get printed");
+ // Per task/thread.
+ uint16_t sequence;
+ log_level level;
+ int32_t seconds, nseconds;
+ char name[100];
+ char message[LOG_MESSAGE_LEN];
+};
+static_assert(shm_ok<LogMessage>::value, "it's going in a queue");
+
+// Returns left > right. LOG_UNKNOWN is most important.
+static inline bool log_gt_important(log_level left, log_level right) {
+ if (left == ERROR) left = 3;
+ if (right == ERROR) right = 3;
+ return left > right;
+}
+
+// Returns a string representing level or "unknown".
+static inline const char *log_str(log_level level) {
+#define DECL_LEVEL(name, value) if (level == name) return #name;
+ DECL_LEVELS;
+#undef DECL_LEVEL
+ return "unknown";
+}
+// Returns the log level represented by str or LOG_UNKNOWN.
+static inline log_level str_log(const char *str) {
+#define DECL_LEVEL(name, value) if (!strcmp(str, #name)) return name;
+ DECL_LEVELS;
+#undef DECL_LEVEL
+ return LOG_UNKNOWN;
+}
+
+// Takes a message and logs it. It will set everything up and then call DoLog
+// for the current LogImplementation.
+void VLog(log_level level, const char *format, va_list ap);
+// Adds to the saved up message.
+void VCork(int line, const char *format, va_list ap);
+// Actually logs the saved up message.
+void VUnCork(int line, log_level level, const char *file,
+ const char *format, va_list ap);
+
+// Will call VLog with the given arguments for the next logger in the chain.
+void LogNext(log_level level, const char *format, ...)
+ __attribute__((format(LOG_PRINTF_FORMAT_TYPE, 2, 3)));
+
+// Represents a system that can actually take log messages and do something
+// useful with them.
+// All of the code (transitively too!) in the DoLog here can make
+// normal LOG and LOG_DYNAMIC calls but can NOT call LOG_CORK/LOG_UNCORK. These
+// calls will not result in DoLog recursing. However, implementations must be
+// safe to call from multiple threads/tasks at the same time. Also, any other
+// overriden methods may end up logging through a given implementation's DoLog.
+class LogImplementation {
+ public:
+ LogImplementation() : next_(NULL) {}
+
+ // The one that this one's implementation logs to.
+ // NULL means that there is no next one.
+ LogImplementation *next() { return next_; }
+ // Virtual in case a subclass wants to perform checks. There will be a valid
+ // logger other than this one available while this is called.
+ virtual void set_next(LogImplementation *next) { next_ = next; }
+
+ private:
+ // Actually logs the given message. Implementations should somehow create a
+ // LogMessage and then call internal::FillInMessage.
+ virtual void DoLog(log_level level, const char *format, va_list ap) = 0;
+
+ // Function of this class so that it can access DoLog.
+ // Levels is how many LogImplementations to not use off the stack.
+ static void DoVLog(log_level, const char *format, va_list ap, int levels);
+ // Friends so that they can access DoVLog.
+ friend void VLog(log_level, const char *, va_list);
+ friend void LogNext(log_level, const char *, ...);
+
+ LogImplementation *next_;
+};
+
+// Adds another implementation to the stack of implementations in this
+// task/thread.
+// Any tasks/threads created after this call will also use this implementation.
+// The cutoff is when the state in a given task/thread is created (either lazily
+// when needed or by calling Load()).
+// The logging system takes ownership of implementation. It will delete it if
+// necessary, so it must be created with new.
+void AddImplementation(LogImplementation *implementation);
+
+// Must be called at least once per process/load before anything else is
+// called. This function is safe to call multiple times from multiple
+// tasks/threads.
+void Init();
+
+// Forces all of the state that is usually lazily created when first needed to
+// be created when called. Cleanup() will delete it.
+void Load();
+// Resets all information in this task/thread to its initial state.
+// NOTE: This is not the opposite of Init(). The state that this deletes is
+// lazily created when needed. It is actually the opposite of Load().
+void Cleanup();
+
+// This is where all of the code that is only used by actual LogImplementations
+// goes.
+namespace internal {
+
+// An separate instance of this class is accessible from each task/thread.
+struct Context {
+ Context();
+
+ // Gets the Context object for this task/thread. Will create one the first
+ // time it is called.
+ //
+ // The implementation for each platform will lazily instantiate a new instance
+ // and then initialize name the first time.
+ // IMPORTANT: The implementation of this can not use logging.
+ static Context *Get();
+ // Deletes the Context object for this task/thread so that the next Get() is
+ // called it will create a new one.
+ // It is valid to call this when Get() has never been called.
+ static void Delete();
+
+ // Which one to log to right now.
+ // Will be NULL if there is no logging implementation to use right now.
+ LogImplementation *implementation;
+
+ // A string representing this task/(process and thread).
+ const char *name;
+ // The number of bytes in name (including the terminating '\0').
+ // Must be <= sizeof(LogMessage::name).
+ size_t name_size;
+
+ // What to assign LogMessage::source to in this task/thread.
+ pid_t source;
+
+ // The sequence value to send out with the next message.
+ uint16_t sequence;
+
+ // Contains all of the information related to implementing LOG_CORK and
+ // LOG_UNCORK.
+ struct {
+ char message[LOG_MESSAGE_LEN];
+ int line_min, line_max;
+ // Sets the data up to record a new series of corked logs.
+ void Reset() {
+ message[0] = '\0'; // make strlen of it 0
+ line_min = INT_MAX;
+ line_max = -1;
+ function = NULL;
+ }
+ // The function that the calls are in.
+ // REMEMBER: While the compiler/linker will probably optimize all of the
+ // identical strings to point to the same data, it might not, so using == to
+ // compare this with another value is a bad idea.
+ const char *function;
+ } cork_data;
+};
+
+// Fills in *message according to the given inputs. Used for implementing
+// LogImplementation::DoLog.
+void FillInMessage(log_level level, const char *format, va_list ap,
+ LogMessage *message);
+
+// Prints message to output.
+void PrintMessage(FILE *output, const LogMessage &message);
+
+} // namespace internal
+} // namespace logging
+} // namespace aos
+
+#endif // AOS_COMMON_LOGGING_LOGGING_IMPL_H_
diff --git a/aos/common/logging/logging_impl_test.cc b/aos/common/logging/logging_impl_test.cc
new file mode 100644
index 0000000..bc411ce
--- /dev/null
+++ b/aos/common/logging/logging_impl_test.cc
@@ -0,0 +1,176 @@
+#include <string>
+
+#include "gtest/gtest.h"
+
+#include "aos/common/logging/logging_impl.h"
+#include "aos/common/time.h"
+#include "aos/common/die.h"
+#include "aos/common/inttypes.h"
+
+using ::testing::AssertionResult;
+using ::testing::AssertionSuccess;
+using ::testing::AssertionFailure;
+
+namespace aos {
+namespace logging {
+namespace testing {
+
+class TestLogImplementation : public LogImplementation {
+ virtual void DoLog(log_level level, const char *format, va_list ap) {
+ internal::FillInMessage(level, format, ap, &message_);
+
+ used_ = true;
+ }
+
+ LogMessage message_;
+
+ public:
+ const LogMessage &message() { return message_; }
+ bool used() { return used_; }
+ void reset_used() { used_ = false; }
+
+ TestLogImplementation() : used_(false) {}
+
+ bool used_;
+};
+class LoggingTest : public ::testing::Test {
+ protected:
+ AssertionResult WasAnythingLogged() {
+ if (log_implementation->used()) {
+ return AssertionSuccess() << "read message '" <<
+ log_implementation->message().message << "'";
+ }
+ return AssertionFailure();
+ }
+ AssertionResult WasLogged(log_level level, const std::string message) {
+ if (!log_implementation->used()) {
+ return AssertionFailure() << "nothing was logged";
+ }
+ if (log_implementation->message().level != level) {
+ return AssertionFailure() << "a message with level " <<
+ log_str(log_implementation->message().level) <<
+ " was logged instead of " << log_str(level);
+ }
+ internal::Context *context = internal::Context::Get();
+ if (log_implementation->message().source != context->source) {
+ Die("got a message from %"PRIu32", but we're %"PRIu32"\n",
+ static_cast<uint32_t>(log_implementation->message().source),
+ static_cast<uint32_t>(context->source));
+ }
+ if (strcmp(log_implementation->message().name, context->name) != 0) {
+ Die("got a message from %s, but we're %s\n",
+ log_implementation->message().name, context->name);
+ }
+ if (strstr(log_implementation->message().message, message.c_str())
+ == NULL) {
+ return AssertionFailure() << "got a message of '" <<
+ log_implementation->message().message <<
+ "' but expected it to contain '" << message << "'";
+ }
+
+ return AssertionSuccess() << log_implementation->message().message;
+ }
+
+ private:
+ virtual void SetUp() {
+ static bool first = true;
+ if (first) {
+ first = false;
+
+ Init();
+ // We'll end up with several of them stacked up, but it really doesn't
+ // matter.
+ AddImplementation(log_implementation = new TestLogImplementation());
+ }
+
+ log_implementation->reset_used();
+ }
+ virtual void TearDown() {
+ Cleanup();
+ }
+
+ static TestLogImplementation *log_implementation;
+};
+TestLogImplementation *LoggingTest::log_implementation(NULL);
+typedef LoggingTest LoggingDeathTest;
+
+// Tests both basic logging functionality and that the test setup works
+// correctly.
+TEST_F(LoggingTest, Basic) {
+ EXPECT_FALSE(WasAnythingLogged());
+ LOG(INFO, "test log 1\n");
+ EXPECT_TRUE(WasLogged(INFO, "test log 1\n"));
+ LOG(INFO, "test log 1.5\n");
+ // there's a subtle typo on purpose...
+ EXPECT_FALSE(WasLogged(INFO, "test log 15\n"));
+ LOG(ERROR, "test log 2=%d\n", 55);
+ EXPECT_TRUE(WasLogged(ERROR, "test log 2=55\n"));
+ LOG(ERROR, "test log 3\n");
+ EXPECT_FALSE(WasLogged(WARNING, "test log 3\n"));
+ LOG(WARNING, "test log 4\n");
+ EXPECT_TRUE(WasAnythingLogged());
+}
+TEST_F(LoggingTest, Cork) {
+ static const int begin_line = __LINE__;
+ LOG_CORK("first part ");
+ LOG_CORK("second part (=%d) ", 19);
+ EXPECT_FALSE(WasAnythingLogged());
+ LOG_CORK("third part ");
+ static const int end_line = __LINE__;
+ LOG_UNCORK(WARNING, "last part %d\n", 5);
+ std::stringstream expected;
+ expected << "logging_impl_test.cc: ";
+ expected << (begin_line + 1);
+ expected << "-";
+ expected << (end_line + 1);
+ expected << ": ";
+ expected << __PRETTY_FUNCTION__;
+ expected << ": first part second part (=19) third part last part 5\n";
+ EXPECT_TRUE(WasLogged(WARNING, expected.str()));
+}
+
+#ifndef __VXWORKS__
+TEST_F(LoggingDeathTest, Fatal) {
+ ASSERT_EXIT(LOG(FATAL, "this should crash it\n"),
+ ::testing::KilledBySignal(SIGABRT),
+ "this should crash it");
+}
+#endif
+
+TEST_F(LoggingTest, PrintfDirectives) {
+ LOG(INFO, "test log %%1 %%d\n");
+ EXPECT_TRUE(WasLogged(INFO, "test log %1 %d\n"));
+ LOG_DYNAMIC(WARNING, "test log %%2 %%f\n");
+ EXPECT_TRUE(WasLogged(WARNING, "test log %2 %f\n"));
+ LOG_CORK("log 3 part %%1 %%d ");
+ LOG_UNCORK(DEBUG, "log 3 part %%2 %%f\n");
+ EXPECT_TRUE(WasLogged(DEBUG, "log 3 part %1 %d log 3 part %2 %f\n"));
+}
+
+TEST_F(LoggingTest, Timing) {
+ // For writing only.
+ //static const long kTimingCycles = 5000000;
+ static const long kTimingCycles = 5000;
+
+ time::Time start = time::Time::Now();
+ for (long i = 0; i < kTimingCycles; ++i) {
+ LOG(INFO, "a\n");
+ }
+ time::Time end = time::Time::Now();
+ time::Time diff = end - start;
+ printf("short message took %lld nsec for %ld\n",
+ diff.ToNSec(), kTimingCycles);
+
+ start = time::Time::Now();
+ for (long i = 0; i < kTimingCycles; ++i) {
+ LOG(INFO, "something longer than just \"a\" to log to test timing\n");
+ }
+ end = time::Time::Now();
+ diff = end - start;
+ printf("long message took %lld nsec for %ld\n",
+ diff.ToNSec(), kTimingCycles);
+}
+
+} // namespace testing
+} // namespace logging
+} // namespace aos