add logging facility and check logs in tests

This commit is contained in:
Konstantin Käfer
2014-07-11 13:55:18 -07:00
parent 8fc4d61025
commit f3c55eba9d
17 changed files with 418 additions and 23 deletions

View File

@@ -25,11 +25,11 @@ build/test/Makefile: src common config.gypi test/test.gyp
deps/run_gyp test/test.gyp --depth=. -Goutput_dir=.. --generator-output=./build/test -f make
test: build/test/Makefile
$(MAKE) -C build/test BUILDTYPE=$(BUILDTYPE) V=$(V) test
$(MAKE) -C build/test BUILDTYPE=Testing V=$(V) test
test/%: build/test/Makefile
$(MAKE) -C build/test BUILDTYPE=$(BUILDTYPE) V=$(V) $*
(cd build/$(BUILDTYPE) && exec ./test_$*)
$(MAKE) -C build/test BUILDTYPE=Testing V=$(V) $*
(cd build/Testing && exec ./test_$*)
# build Mac OS X project for Xcode
xtest: config.gypi clear_xcode_cache node
@@ -42,7 +42,7 @@ xtest: config.gypi clear_xcode_cache node
# Builds the linux app with make. This is also used by Travis CI
linux: config.gypi linux/llmr-app.gyp node
deps/run_gyp linux/llmr-app.gyp --depth=. -Goutput_dir=.. --generator-output=./build/linux -f make
$(MAKE) -C build/linux BUILDTYPE=$(BUILDTYPE) V=$(V) linuxapp
$(MAKE) -C build/linux BUILDTYPE=Testing V=$(V) linuxapp
# Executes the Linux binary
run-linux: linux

View File

@@ -33,6 +33,16 @@
'DEAD_CODE_STRIPPING': 'YES',
'GCC_INLINES_ARE_PRIVATE_EXTERN': 'YES'
}
},
'Testing': {
'cflags_cc': [ '-O3' ],
'defines': [ 'NDEBUG', 'TESTING' ],
'xcode_settings': {
'GCC_OPTIMIZATION_LEVEL': '3',
'GCC_GENERATE_DEBUGGING_SYMBOLS': 'NO',
'DEAD_CODE_STRIPPING': 'YES',
'GCC_INLINES_ARE_PRIVATE_EXTERN': 'YES'
}
}
}
}

View File

@@ -0,0 +1,53 @@
#ifndef LLMR_PLATFORM_EVENT
#define LLMR_PLATFORM_EVENT
#include <cstdint>
#include <ostream>
namespace llmr {
enum class EventSeverity : uint8_t {
Debug,
Info,
Test,
Warning,
Error,
};
EventSeverity parseEventSeverity(const char *name);
::std::ostream& operator<<(::std::ostream& os, EventSeverity eventSeverity);
enum class Event : uint8_t {
ParseStyle,
ParseTile,
Render,
HttpRequest,
};
Event parseEvent(const char *name);
::std::ostream& operator<<(::std::ostream& os, Event event);
constexpr EventSeverity enabledEventSeverities[] = {
#if DEBUG
EventSeverity::Debug,
#endif
#if TESTING
EventSeverity::Test,
#endif
EventSeverity::Info,
EventSeverity::Warning,
EventSeverity::Error,
};
/* enabled event classes */
constexpr Event enabledEvents[] = {
Event::ParseStyle,
Event::ParseTile,
Event::HttpRequest,
};
}
#endif

View File

@@ -0,0 +1,69 @@
#ifndef LLMR_PLATFORM_LOG
#define LLMR_PLATFORM_LOG
#include "event.hpp"
#include <memory>
#include <string>
namespace llmr {
class LogBackend {
public:
virtual inline ~LogBackend() = default;
virtual void record(EventSeverity severity, Event event, const std::string &msg) = 0;
virtual void record(EventSeverity severity, Event event, int64_t code) = 0;
virtual void record(EventSeverity severity, Event event, int64_t code, const std::string &msg) = 0;
};
class Log {
private:
template <typename T>
constexpr static bool includes(const T e, T const *l, const size_t i = 0) {
return i >= sizeof l ? false : *(l + i) == e ? true : includes(e, l, i + 1);
}
public:
template <typename ...Args>
static inline void Debug(Event event, Args&& ...args) {
Record(EventSeverity::Debug, event, ::std::forward<Args>(args)...);
}
template <typename ...Args>
static inline void Info(Event event, Args&& ...args) {
Record(EventSeverity::Info, event, ::std::forward<Args>(args)...);
}
template <typename ...Args>
static inline void Warning(Event event, Args&& ...args) {
Record(EventSeverity::Warning, event, ::std::forward<Args>(args)...);
}
template <typename ...Args>
static inline void Error(Event event, Args&& ...args) {
Record(EventSeverity::Error, event, ::std::forward<Args>(args)...);
}
template <typename ...Args>
static inline void Record(EventSeverity severity, Event event, Args&& ...args) {
if (includes(severity, enabledEventSeverities) &&
includes(event, enabledEvents)) {
if (Backend) {
Backend->record(severity, event, ::std::forward<Args>(args)...);
}
}
}
template<typename T, typename ...Args>
static inline const T &Set(Args&& ...args) {
Backend = ::std::unique_ptr<T>(new T(::std::forward<Args>(args)...));
return *dynamic_cast<T *>(Backend.get());
}
private:
static std::unique_ptr<LogBackend> Backend;
};
}
#endif

View File

@@ -3,9 +3,7 @@
set -e
set -o pipefail
BUILDTYPE="${BUILDTYPE:-Release}"
cd build/${BUILDTYPE}
cd build/Testing
for TEST in ./test_* ; do
${TEST}

46
src/platform/event.cpp Normal file
View File

@@ -0,0 +1,46 @@
#include <llmr/platform/event.hpp>
#include <cstring>
namespace llmr {
EventSeverity parseEventSeverity(const char *name) {
if (strcmp(name, "DEBUG") == 0) return EventSeverity::Debug;
if (strcmp(name, "INFO") == 0) return EventSeverity::Info;
if (strcmp(name, "TEST") == 0) return EventSeverity::Test;
if (strcmp(name, "WARNING") == 0) return EventSeverity::Warning;
if (strcmp(name, "ERROR") == 0) return EventSeverity::Error;
return EventSeverity(-1);
}
::std::ostream& operator<<(::std::ostream& os, EventSeverity eventSeverity) {
switch (eventSeverity) {
case EventSeverity::Debug: return os << "DEBUG";
case EventSeverity::Info: return os << "INFO";
case EventSeverity::Test: return os << "TEST";
case EventSeverity::Warning: return os << "WARNING";
case EventSeverity::Error: return os << "ERROR";
default: return os << "UNKNOWN";
}
}
Event parseEvent(const char *name) {
if (strcmp(name, "ParseStyle") == 0) return Event::ParseStyle;
if (strcmp(name, "ParseTile") == 0) return Event::ParseTile;
if (strcmp(name, "Render") == 0) return Event::Render;
if (strcmp(name, "HttpRequest") == 0) return Event::HttpRequest;
return Event(-1);
}
::std::ostream& operator<<(::std::ostream& os, Event event) {
switch (event) {
case Event::ParseStyle: return os << "ParseStyle";
case Event::ParseTile: return os << "ParseTile";
case Event::Render: return os << "Render";
case Event::HttpRequest: return os << "HttpRequest";
default: return os << "Unknown";
}
}
}

7
src/platform/log.cpp Normal file
View File

@@ -0,0 +1,7 @@
#include <llmr/platform/log.hpp>
namespace llmr {
std::unique_ptr<LogBackend> Log::Backend;
}

42
test/fixtures/fixture_log.cpp vendored Normal file
View File

@@ -0,0 +1,42 @@
#include "fixture_log.hpp"
#include <iostream>
namespace llmr {
size_t FixtureLogBackend::count(const LogMessage &message) const {
size_t count = 0;
for (const LogMessage &msg : messages) {
if (msg == message) {
count++;
msg.checked = true;
}
}
return count;
}
std::vector<FixtureLogBackend::LogMessage> FixtureLogBackend::unchecked() const {
std::vector<LogMessage> unchecked;
for (const LogMessage &msg : messages) {
if (!msg.checked) {
unchecked.push_back(msg);
}
}
return unchecked;
}
::std::ostream& operator<<(::std::ostream& os, const std::vector<FixtureLogBackend::LogMessage>& messages) {
for (const FixtureLogBackend::LogMessage &message : messages) {
os << "- " << message;
}
return os;
}
::std::ostream& operator<<(::std::ostream& os, const FixtureLogBackend::LogMessage& message) {
os << "[\"" << message.severity.get() << "\", \"" << message.event.get();
if (message.code) os << "\", " << message.code.get();
if (message.msg) os << ", \"" << message.msg.get();
return os << "\"]" << std::endl;
}
}

66
test/fixtures/fixture_log.hpp vendored Normal file
View File

@@ -0,0 +1,66 @@
#ifndef LLMR_TEST_FIXTURE_LOG
#define LLMR_TEST_FIXTURE_LOG
#include <llmr/platform/log.hpp>
#include <boost/optional.hpp>
#include <vector>
namespace llmr {
class FixtureLogBackend : public LogBackend {
public:
struct LogMessage {
inline LogMessage(EventSeverity severity, Event event, int64_t code, const std::string &msg)
: severity(severity), event(event), code(code), msg(msg) {}
inline LogMessage(EventSeverity severity, Event event, int64_t code)
: severity(severity), event(event), code(code) {}
inline LogMessage(EventSeverity severity, Event event, const std::string &msg)
: severity(severity), event(event), msg(msg) {}
inline LogMessage(EventSeverity severity, Event event)
: severity(severity), event(event) {}
inline bool operator==(const LogMessage &rhs) const {
return (!severity || !rhs.severity || severity.get() == rhs.severity.get()) &&
(!event || !rhs.event || event.get() == rhs.event.get()) &&
(!code || !rhs.code || code.get() == rhs.code.get()) &&
(!msg || !rhs.msg || msg.get() == rhs.msg.get());
}
const boost::optional<EventSeverity> severity;
const boost::optional<Event> event;
const boost::optional<int64_t> code;
const boost::optional<std::string> msg;
mutable bool checked = false;
};
inline ~FixtureLogBackend() = default;
void record(EventSeverity severity, Event event, const std::string &msg) {
messages.emplace_back(severity, event, msg);
}
void record(EventSeverity severity, Event event, int64_t code) {
messages.emplace_back(severity, event, code);
}
void record(EventSeverity severity, Event event, int64_t code, const std::string &msg) {
messages.emplace_back(severity, event, code, msg);
}
size_t count(const LogMessage &message) const;
std::vector<LogMessage> unchecked() const;
public:
std::vector<LogMessage> messages;
};
::std::ostream& operator<<(::std::ostream& os, const std::vector<FixtureLogBackend::LogMessage>& messages);
::std::ostream& operator<<(::std::ostream& os, const FixtureLogBackend::LogMessage& message);
}
#endif

View File

@@ -1,6 +1,7 @@
#include <llmr/platform/platform.hpp>
#include <llmr/platform/request.hpp>
#include <llmr/util/uv.hpp>
#include <llmr/platform/log.hpp>
const std::string base_directory = []{
std::string fn = __FILE__;
@@ -40,7 +41,7 @@ platform::request_http(const std::string &url,
if (err < 0) {
req->res->code = err;
req->res->error_message = uv_strerror(err);
fprintf(stderr, "[WARNING] fixture request: %s\n", uv_strerror(err));
Log::Warning(Event::HttpRequest, err, url + ": " + uv_strerror(err));
req->complete();
return req;
}
@@ -90,7 +91,8 @@ platform::request_http(const std::string &url,
req->res->body.swap(body);
req->res->code = 200;
fprintf(stderr, "[INFO] fixture request completed: %s\n", clean_url.c_str());
// fprintf(stderr, "[INFO] fixture request completed: %s\n", clean_url.c_str());
Log::Info(Event::HttpRequest, 200, url);
req->complete();
return req;

View File

@@ -2,12 +2,26 @@
"default": {
"zoom": 14,
"center": [52.499167, 13.418056],
"height": 256
"height": 256,
"log": [
[1, "INFO", "HttpRequest", 200, "tiles/14-8803-5375.vector.pbf"],
[1, "INFO", "HttpRequest", 200, "tiles/14-8802-5375.vector.pbf"],
[1, "INFO", "HttpRequest", 200, "tiles/14-8803-5374.vector.pbf"],
[1, "INFO", "HttpRequest", 200, "tiles/14-8802-5374.vector.pbf"],
[4, "INFO", "HttpRequest"]
]
},
"colored": {
"zoom": 14,
"center": [52.499167, 13.418056],
"height": 256,
"classes": ["colored"]
"classes": ["colored"],
"log": [
[1, "INFO", "HttpRequest", 200, "tiles/14-8803-5375.vector.pbf"],
[1, "INFO", "HttpRequest", 200, "tiles/14-8802-5375.vector.pbf"],
[1, "INFO", "HttpRequest", 200, "tiles/14-8803-5374.vector.pbf"],
[1, "INFO", "HttpRequest", 200, "tiles/14-8802-5374.vector.pbf"],
[4, "INFO", "HttpRequest"]
]
}
}

View File

@@ -2,21 +2,44 @@
"z13.9": {
"zoom": 13.9,
"center": [52.499167, 13.418056],
"height": 256
"height": 256,
"log": [
[1, "INFO", "HttpRequest", 200, "tiles/13-4401-2687.vector.pbf"],
[1, "INFO", "HttpRequest"]
]
},
"z14.0": {
"zoom": 14,
"center": [52.499167, 13.418056],
"height": 256
"height": 256,
"log": [
[1, "INFO", "HttpRequest", 200, "tiles/14-8803-5375.vector.pbf"],
[1, "INFO", "HttpRequest", 200, "tiles/14-8802-5375.vector.pbf"],
[1, "INFO", "HttpRequest", 200, "tiles/14-8803-5374.vector.pbf"],
[1, "INFO", "HttpRequest", 200, "tiles/14-8802-5374.vector.pbf"],
[4, "INFO", "HttpRequest"]
]
},
"z14.1": {
"zoom": 14.1,
"center": [52.499167, 13.418056],
"height": 256
"height": 256,
"log": [
[1, "INFO", "HttpRequest", 200, "tiles/14-8803-5375.vector.pbf"],
[1, "INFO", "HttpRequest", 200, "tiles/14-8802-5375.vector.pbf"],
[1, "INFO", "HttpRequest", 200, "tiles/14-8803-5374.vector.pbf"],
[1, "INFO", "HttpRequest", 200, "tiles/14-8802-5374.vector.pbf"],
[4, "INFO", "HttpRequest"]
]
},
"z14.2": {
"zoom": 14.2,
"center": [52.499167, 13.418056],
"height": 256
"height": 256,
"log": [
[1, "INFO", "HttpRequest", 200, "tiles/14-8803-5374.vector.pbf"],
[1, "INFO", "HttpRequest", 200, "tiles/14-8802-5374.vector.pbf"],
[2, "INFO", "HttpRequest"]
]
}
}

View File

@@ -1,6 +1,9 @@
{
"plain": {
"center": [0, 0],
"zoom": 0
"zoom": 0,
"log": [
[ 1, "INFO", "HttpRequest", 200, "tiles/0-0-0.vector.pbf" ]
]
}
}

View File

@@ -1,6 +1,10 @@
{
"plain": {
"center": [0, 0],
"zoom": 0
"zoom": 0,
"log": [
[1, "INFO", "HttpRequest", 200, "tiles/0-0-0.vector.pbf"],
[1, "INFO", "HttpRequest"]
]
}
}

Binary file not shown.

View File

@@ -9,6 +9,8 @@
#include "../common/headless_view.hpp"
#include "./fixtures/fixture_log.hpp"
#include <dirent.h>
const std::string base_directory = []{
@@ -20,10 +22,12 @@ const std::string base_directory = []{
class HeadlessTest : public ::testing::TestWithParam<std::string> {};
TEST_P(HeadlessTest, render) {
using namespace llmr;
const std::string &base = GetParam();
const std::string style = llmr::util::read_file(base_directory + "/" + base + ".style.json");
const std::string info = llmr::util::read_file(base_directory + "/" + base + ".info.json");
const std::string style = util::read_file(base_directory + "/" + base + ".style.json");
const std::string info = util::read_file(base_directory + "/" + base + ".info.json");
// Parse settings.
rapidjson::Document doc;
@@ -32,10 +36,12 @@ TEST_P(HeadlessTest, render) {
ASSERT_EQ(true, doc.IsObject());
// Setup OpenGL
llmr::HeadlessView view;
llmr::Map map(view);
HeadlessView view;
Map map(view);
for (auto it = doc.MemberBegin(), end = doc.MemberEnd(); it != end; it++) {
const FixtureLogBackend &log = Log::Set<FixtureLogBackend>();
const std::string name { it->name.GetString(), it->name.GetStringLength() };
const rapidjson::Value &value = it->value;
ASSERT_EQ(true, value.IsObject());
@@ -74,8 +80,58 @@ TEST_P(HeadlessTest, render) {
const std::unique_ptr<uint32_t[]> pixels(new uint32_t[width * height]);
glReadPixels(0, 0, width, height, GL_RGBA, GL_UNSIGNED_BYTE, pixels.get());
const std::string image = llmr::util::compress_png(width, height, pixels.get(), true);
llmr::util::write_file(actual_image, image);
const std::string image = util::compress_png(width, height, pixels.get(), true);
util::write_file(actual_image, image);
if (value.HasMember("log")) {
const rapidjson::Value &js_log = value["log"];
ASSERT_EQ(true, js_log.IsArray());
for (rapidjson::SizeType i = 0; i < js_log.Size(); i++) {
const rapidjson::Value &js_entry = js_log[i];
ASSERT_EQ(true, js_entry.IsArray());
if (js_entry.Size() == 5) {
const uint32_t count = js_entry[rapidjson::SizeType(0)].GetUint();
const FixtureLogBackend::LogMessage message {
parseEventSeverity(js_entry[rapidjson::SizeType(1)].GetString()),
parseEvent(js_entry[rapidjson::SizeType(2)].GetString()),
js_entry[rapidjson::SizeType(3)].GetInt64(),
js_entry[rapidjson::SizeType(4)].GetString()
};
ASSERT_EQ(count, log.count(message)) << "Message: " << message << "Full Log: " << std::endl << log.messages;
} else if (js_entry.Size() == 4) {
const uint32_t count = js_entry[rapidjson::SizeType(0)].GetUint();
if (js_entry[rapidjson::SizeType(3)].IsString()) {
const FixtureLogBackend::LogMessage message {
parseEventSeverity(js_entry[rapidjson::SizeType(1)].GetString()),
parseEvent(js_entry[rapidjson::SizeType(2)].GetString()),
js_entry[rapidjson::SizeType(3)].GetString()
};
ASSERT_EQ(count, log.count(message)) << "Message: " << message << "Full Log: " << std::endl << log.messages;
} else {
const FixtureLogBackend::LogMessage message {
parseEventSeverity(js_entry[rapidjson::SizeType(1)].GetString()),
parseEvent(js_entry[rapidjson::SizeType(2)].GetString()),
js_entry[rapidjson::SizeType(3)].GetInt64()
};
ASSERT_EQ(count, log.count(message)) << "Message: " << message << "Full Log: " << std::endl << log.messages;
}
} else if (js_entry.Size() == 3) {
const uint32_t count = js_entry[rapidjson::SizeType(0)].GetUint();
const FixtureLogBackend::LogMessage message {
parseEventSeverity(js_entry[rapidjson::SizeType(1)].GetString()),
parseEvent(js_entry[rapidjson::SizeType(2)].GetString())
};
ASSERT_EQ(count, log.count(message)) << "Message: " << message << "Full Log: " << std::endl << log.messages;
} else {
FAIL();
}
}
}
const auto &unchecked = log.unchecked();
if (unchecked.size()) {
std::cerr << "Unchecked Log Messages (" << base << "/" << name << "): " << std::endl << unchecked;
}
}
}

View File

@@ -151,6 +151,8 @@
"../common/headless_view.hpp",
"../common/headless_view.cpp",
"./fixtures/fixture_request.cpp",
"./fixtures/fixture_log.hpp",
"./fixtures/fixture_log.cpp",
],
"dependencies": [
"../deps/gtest/gtest.gyp:gtest",