From 4d6e08f60baaeefed69308238933b951d6b244ef Mon Sep 17 00:00:00 2001 From: Uditha Atukorala Date: Mon, 17 Jul 2023 07:36:29 +0100 Subject: [PATCH 1/6] basic structured (json) logs --- src/CMakeLists.txt | 13 +++++++++++++ src/log/CMakeLists.txt | 8 ++++++++ src/log/log.cpp | 27 +++++++++++++++++++++++++++ src/log/log.h | 21 +++++++++++++++++++++ 4 files changed, 69 insertions(+) create mode 100644 src/log/CMakeLists.txt create mode 100644 src/log/log.cpp create mode 100644 src/log/log.h diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt index 2c41806b..2b82ed18 100644 --- a/src/CMakeLists.txt +++ b/src/CMakeLists.txt @@ -1,6 +1,7 @@ add_subdirectory(datastore) add_subdirectory(err) add_subdirectory(events) +add_subdirectory(log) add_subdirectory(service) # datastore @@ -39,6 +40,18 @@ target_include_directories(libevents add_library(${PROJECT_NAME}::events ALIAS libevents) +# log +add_library(liblog INTERFACE) +target_link_libraries(liblog + INTERFACE log +) + +target_include_directories(liblog + INTERFACE $ +) + +add_library(${PROJECT_NAME}::log ALIAS liblog) + # service add_library(libservice INTERFACE) target_link_libraries(libservice diff --git a/src/log/CMakeLists.txt b/src/log/CMakeLists.txt new file mode 100644 index 00000000..fd2febf5 --- /dev/null +++ b/src/log/CMakeLists.txt @@ -0,0 +1,8 @@ +add_library(log + log.cpp log.h +) + +target_link_libraries(log + PRIVATE + glaze::glaze +) diff --git a/src/log/log.cpp b/src/log/log.cpp new file mode 100644 index 00000000..f3fd0590 --- /dev/null +++ b/src/log/log.cpp @@ -0,0 +1,27 @@ +#include "log.h" + +#include + +namespace log { +std::string timestamp() { + const auto now = std::chrono::system_clock::now(); + auto days = std::chrono::floor(now); + std::chrono::year_month_day ymd(days); + std::chrono::hh_mm_ss time(std::chrono::floor(now - days)); + + char buf[std::size("2006-01-02T15:04:05.999999999Z")]; + std::snprintf( + std::data(buf), + std::size(buf), + "%d-%.2u-%.2uT%.2ld:%.2ld:%.2lld.%lldZ", + static_cast(ymd.year()), + static_cast(ymd.month()), + static_cast(ymd.day()), + time.hours().count(), + time.minutes().count(), + time.seconds().count(), + time.subseconds().count()); + + return buf; +} +} // namespace log diff --git a/src/log/log.h b/src/log/log.h new file mode 100644 index 00000000..264682e3 --- /dev/null +++ b/src/log/log.h @@ -0,0 +1,21 @@ +#include + +#include + +namespace log { +std::string timestamp(); + +template void info(std::string_view source, Args &&...args) { + glz::obj obj{ + "@timestamp", + timestamp(), + "severity", + "info", + "source", + source, + args..., + }; + + std::cout << glz::write_json(obj) << std::endl; +} +} // namespace log From d2be8e3f997830485fda7b0f235a38204d2f617f Mon Sep 17 00:00:00 2001 From: Uditha Atukorala Date: Mon, 17 Jul 2023 07:38:21 +0100 Subject: [PATCH 2/6] grpc interceptor for request logging --- src/main.cpp | 9 +++++++++ src/service/CMakeLists.txt | 2 ++ src/service/interceptors/logger.cpp | 21 +++++++++++++++++++++ src/service/interceptors/logger.h | 28 ++++++++++++++++++++++++++++ 4 files changed, 60 insertions(+) create mode 100644 src/service/interceptors/logger.cpp create mode 100644 src/service/interceptors/logger.h diff --git a/src/main.cpp b/src/main.cpp index 304e1c82..df45cf34 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -6,6 +6,7 @@ #include "datastore/datastore.h" #include "service/gatekeeper.h" +#include "service/interceptors/logger.h" int main() { try { @@ -37,6 +38,14 @@ int main() { builder.AddListeningPort(std::string{conf["tcp.address"]}, grpc::InsecureServerCredentials()); builder.RegisterService(&service); + if (conf["app.debug"].get()) { + std::vector> + creators; + creators.push_back(std::unique_ptr( + new service::interceptors::LoggerFactory())); + builder.experimental().SetInterceptorCreators(std::move(creators)); + } + std::unique_ptr server(builder.BuildAndStart()); server->Wait(); diff --git a/src/service/CMakeLists.txt b/src/service/CMakeLists.txt index 3ea63872..a7b9abd0 100644 --- a/src/service/CMakeLists.txt +++ b/src/service/CMakeLists.txt @@ -6,6 +6,7 @@ add_library(service gatekeeper.rbac-policies.cpp gatekeeper.roles.cpp mappers.cpp mappers.h + interceptors/logger.cpp interceptors/logger.h ) target_link_libraries(service @@ -13,6 +14,7 @@ target_link_libraries(service ${PROJECT_NAME}::libproto PRIVATE ${PROJECT_NAME}::datastore + ${PROJECT_NAME}::log ) if (GATEKEEPER_ENABLE_COVERAGE) diff --git a/src/service/interceptors/logger.cpp b/src/service/interceptors/logger.cpp new file mode 100644 index 00000000..b42bc5bb --- /dev/null +++ b/src/service/interceptors/logger.cpp @@ -0,0 +1,21 @@ +#include "logger.h" + +#include "log/log.h" + +namespace service { +namespace interceptors { +Logger::Logger(grpc::experimental::ServerRpcInfo *rpc) : + _rpc(rpc), _start(std::chrono::high_resolution_clock::now()) {} + +Logger::~Logger() { + std::chrono::duration diff = + std::chrono::high_resolution_clock::now() - _start; + + log::info("service", "latency_ms", diff.count(), "method", _rpc->method()); +} + +void Logger::Intercept(grpc::experimental::InterceptorBatchMethods *methods) { + methods->Proceed(); +} +} // namespace interceptors +} // namespace service diff --git a/src/service/interceptors/logger.h b/src/service/interceptors/logger.h new file mode 100644 index 00000000..a6b26f09 --- /dev/null +++ b/src/service/interceptors/logger.h @@ -0,0 +1,28 @@ +#include + +#include + +namespace service { +namespace interceptors { +class Logger final : public grpc::experimental::Interceptor { +public: + Logger(grpc::experimental::ServerRpcInfo *rpc); + ~Logger(); + + void Intercept(grpc::experimental::InterceptorBatchMethods *methods) override; + +private: + grpc::experimental::ServerRpcInfo *_rpc; + + std::chrono::high_resolution_clock::time_point _start; +}; + +class LoggerFactory : public grpc::experimental::ServerInterceptorFactoryInterface { +public: + grpc::experimental::Interceptor *CreateServerInterceptor( + grpc::experimental::ServerRpcInfo *info) override { + return new Logger(info); + } +}; +} // namespace interceptors +} // namespace service From 1291fe5d2bf23e8c486c371c28c6b5f3bd2ab74c Mon Sep 17 00:00:00 2001 From: Uditha Atukorala Date: Mon, 17 Jul 2023 18:42:06 +0100 Subject: [PATCH 3/6] (cmake) update libviper dependency --- cmake/dependencies.cmake | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/cmake/dependencies.cmake b/cmake/dependencies.cmake index c75096de..79675642 100644 --- a/cmake/dependencies.cmake +++ b/cmake/dependencies.cmake @@ -99,8 +99,8 @@ FetchContent_MakeAvailable(libpqxx) # libviper FetchContent_Declare(libviper - URL https://github.com/uditha-atukorala/libviper/archive/refs/tags/v0.3.1.tar.gz - URL_HASH SHA256=24a79fe54708a315394938f7946dab35aa69b884f0fab4ac0a9fa42b60c93313 + URL https://github.com/uditha-atukorala/libviper/archive/refs/tags/v0.3.2.tar.gz + URL_HASH SHA256=6b4bc56a4015e5a3889bac66f868947781001c621a61db4383bb528e2239722f ) FetchContent_MakeAvailable(libviper) From 2c848d956c4c66ea201a6f1d4e38c803f957e0ec Mon Sep 17 00:00:00 2001 From: Uditha Atukorala Date: Mon, 17 Jul 2023 18:49:14 +0100 Subject: [PATCH 4/6] tidy-up --- src/main.cpp | 19 +++++++++++++------ 1 file changed, 13 insertions(+), 6 deletions(-) diff --git a/src/main.cpp b/src/main.cpp index df45cf34..2e5595a2 100644 --- a/src/main.cpp +++ b/src/main.cpp @@ -38,12 +38,19 @@ int main() { builder.AddListeningPort(std::string{conf["tcp.address"]}, grpc::InsecureServerCredentials()); builder.RegisterService(&service); - if (conf["app.debug"].get()) { - std::vector> - creators; - creators.push_back(std::unique_ptr( - new service::interceptors::LoggerFactory())); - builder.experimental().SetInterceptorCreators(std::move(creators)); + // Interceptors + { + using factory_t = std::unique_ptr; + std::vector creators; + + if (conf["app.debug"].get()) { + factory_t logger(new service::interceptors::LoggerFactory()); + creators.push_back(std::move(logger)); + } + + if (creators.size() > 0) { + builder.experimental().SetInterceptorCreators(std::move(creators)); + } } std::unique_ptr server(builder.BuildAndStart()); From beb45c344f84eb2219679959828a5e6f1e833ff6 Mon Sep 17 00:00:00 2001 From: Uditha Atukorala Date: Mon, 17 Jul 2023 20:09:31 +0100 Subject: [PATCH 5/6] avoid name conflicts in linux --- src/CMakeLists.txt | 14 +++++++------- src/log/CMakeLists.txt | 8 -------- src/logger/CMakeLists.txt | 8 ++++++++ src/{log/log.cpp => logger/logger.cpp} | 6 +++--- src/{log/log.h => logger/logger.h} | 4 ++-- src/service/CMakeLists.txt | 2 +- src/service/interceptors/logger.cpp | 4 ++-- 7 files changed, 23 insertions(+), 23 deletions(-) delete mode 100644 src/log/CMakeLists.txt create mode 100644 src/logger/CMakeLists.txt rename src/{log/log.cpp => logger/logger.cpp} (92%) rename src/{log/log.h => logger/logger.h} (88%) diff --git a/src/CMakeLists.txt b/src/CMakeLists.txt index 2b82ed18..b76e2790 100644 --- a/src/CMakeLists.txt +++ b/src/CMakeLists.txt @@ -1,7 +1,7 @@ add_subdirectory(datastore) add_subdirectory(err) add_subdirectory(events) -add_subdirectory(log) +add_subdirectory(logger) add_subdirectory(service) # datastore @@ -40,17 +40,17 @@ target_include_directories(libevents add_library(${PROJECT_NAME}::events ALIAS libevents) -# log -add_library(liblog INTERFACE) -target_link_libraries(liblog - INTERFACE log +# logger +add_library(liblogger INTERFACE) +target_link_libraries(liblogger + INTERFACE logger ) -target_include_directories(liblog +target_include_directories(liblogger INTERFACE $ ) -add_library(${PROJECT_NAME}::log ALIAS liblog) +add_library(${PROJECT_NAME}::logger ALIAS liblogger) # service add_library(libservice INTERFACE) diff --git a/src/log/CMakeLists.txt b/src/log/CMakeLists.txt deleted file mode 100644 index fd2febf5..00000000 --- a/src/log/CMakeLists.txt +++ /dev/null @@ -1,8 +0,0 @@ -add_library(log - log.cpp log.h -) - -target_link_libraries(log - PRIVATE - glaze::glaze -) diff --git a/src/logger/CMakeLists.txt b/src/logger/CMakeLists.txt new file mode 100644 index 00000000..d5ef380d --- /dev/null +++ b/src/logger/CMakeLists.txt @@ -0,0 +1,8 @@ +add_library(logger + logger.cpp logger.h +) + +target_link_libraries(logger + PRIVATE + glaze::glaze +) diff --git a/src/log/log.cpp b/src/logger/logger.cpp similarity index 92% rename from src/log/log.cpp rename to src/logger/logger.cpp index f3fd0590..58cbe00d 100644 --- a/src/log/log.cpp +++ b/src/logger/logger.cpp @@ -1,8 +1,8 @@ -#include "log.h" +#include "logger.h" #include -namespace log { +namespace logger { std::string timestamp() { const auto now = std::chrono::system_clock::now(); auto days = std::chrono::floor(now); @@ -24,4 +24,4 @@ std::string timestamp() { return buf; } -} // namespace log +} // namespace logger diff --git a/src/log/log.h b/src/logger/logger.h similarity index 88% rename from src/log/log.h rename to src/logger/logger.h index 264682e3..ec6cf38a 100644 --- a/src/log/log.h +++ b/src/logger/logger.h @@ -2,7 +2,7 @@ #include -namespace log { +namespace logger { std::string timestamp(); template void info(std::string_view source, Args &&...args) { @@ -18,4 +18,4 @@ template void info(std::string_view source, Args &&...args) { std::cout << glz::write_json(obj) << std::endl; } -} // namespace log +} // namespace logger diff --git a/src/service/CMakeLists.txt b/src/service/CMakeLists.txt index a7b9abd0..0402bc17 100644 --- a/src/service/CMakeLists.txt +++ b/src/service/CMakeLists.txt @@ -14,7 +14,7 @@ target_link_libraries(service ${PROJECT_NAME}::libproto PRIVATE ${PROJECT_NAME}::datastore - ${PROJECT_NAME}::log + ${PROJECT_NAME}::logger ) if (GATEKEEPER_ENABLE_COVERAGE) diff --git a/src/service/interceptors/logger.cpp b/src/service/interceptors/logger.cpp index b42bc5bb..9da0802c 100644 --- a/src/service/interceptors/logger.cpp +++ b/src/service/interceptors/logger.cpp @@ -1,6 +1,6 @@ #include "logger.h" -#include "log/log.h" +#include "logger/logger.h" namespace service { namespace interceptors { @@ -11,7 +11,7 @@ Logger::~Logger() { std::chrono::duration diff = std::chrono::high_resolution_clock::now() - _start; - log::info("service", "latency_ms", diff.count(), "method", _rpc->method()); + logger::info("service", "latency_ms", diff.count(), "method", _rpc->method()); } void Logger::Intercept(grpc::experimental::InterceptorBatchMethods *methods) { From 6c425ad1f29366f9db17b07a9ef2f26066cfe5ef Mon Sep 17 00:00:00 2001 From: Uditha Atukorala Date: Tue, 18 Jul 2023 13:27:19 +0100 Subject: [PATCH 6/6] (service) tidy-up --- src/service/interceptors/logger.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/service/interceptors/logger.h b/src/service/interceptors/logger.h index a6b26f09..bf604ef2 100644 --- a/src/service/interceptors/logger.h +++ b/src/service/interceptors/logger.h @@ -17,7 +17,7 @@ class Logger final : public grpc::experimental::Interceptor { std::chrono::high_resolution_clock::time_point _start; }; -class LoggerFactory : public grpc::experimental::ServerInterceptorFactoryInterface { +class LoggerFactory final : public grpc::experimental::ServerInterceptorFactoryInterface { public: grpc::experimental::Interceptor *CreateServerInterceptor( grpc::experimental::ServerRpcInfo *info) override {