diff --git a/etc/CMakeLists.txt b/etc/CMakeLists.txt index 40e181a0a61..55bebe0db91 100644 --- a/etc/CMakeLists.txt +++ b/etc/CMakeLists.txt @@ -34,6 +34,7 @@ install_if_not_exists(icinga2/conf.d/notifications.conf ${ICINGA2_CONFIGDIR}/con install_if_not_exists(icinga2/conf.d/templates.conf ${ICINGA2_CONFIGDIR}/conf.d) install_if_not_exists(icinga2/conf.d/timeperiods.conf ${ICINGA2_CONFIGDIR}/conf.d) install_if_not_exists(icinga2/conf.d/users.conf ${ICINGA2_CONFIGDIR}/conf.d) +install_if_not_exists(icinga2/features-available/accesslog.conf ${ICINGA2_CONFIGDIR}/features-available) install_if_not_exists(icinga2/features-available/api.conf ${ICINGA2_CONFIGDIR}/features-available) install_if_not_exists(icinga2/features-available/debuglog.conf ${ICINGA2_CONFIGDIR}/features-available) install_if_not_exists(icinga2/features-available/mainlog.conf ${ICINGA2_CONFIGDIR}/features-available) diff --git a/etc/icinga2/features-available/accesslog.conf b/etc/icinga2/features-available/accesslog.conf new file mode 100644 index 00000000000..b2d82f5316d --- /dev/null +++ b/etc/icinga2/features-available/accesslog.conf @@ -0,0 +1,7 @@ +/** + * The AccessLogger type writes API access information to a file. + */ + +object AccessLogger "access-log" { + path = LogDir + "/access.log" +} diff --git a/lib/base/CMakeLists.txt b/lib/base/CMakeLists.txt index 59e83644394..ba5e8d7c1b2 100644 --- a/lib/base/CMakeLists.txt +++ b/lib/base/CMakeLists.txt @@ -1,5 +1,6 @@ # Icinga 2 | (c) 2012 Icinga GmbH | GPLv2+ +mkclass_target(accesslogger.ti accesslogger-ti.cpp accesslogger-ti.hpp) mkclass_target(application.ti application-ti.cpp application-ti.hpp) mkclass_target(configobject.ti configobject-ti.cpp configobject-ti.hpp) mkclass_target(configuration.ti configuration-ti.cpp configuration-ti.hpp) @@ -14,6 +15,7 @@ mkclass_target(sysloglogger.ti sysloglogger-ti.cpp sysloglogger-ti.hpp) set(base_SOURCES i2-base.hpp + accesslogger.cpp accesslogger.hpp accesslogger-ti.hpp application.cpp application.hpp application-ti.hpp application-version.cpp application-environment.cpp array.cpp array.hpp array-script.cpp atomic.hpp diff --git a/lib/base/accesslogger.cpp b/lib/base/accesslogger.cpp new file mode 100644 index 00000000000..57835bb1281 --- /dev/null +++ b/lib/base/accesslogger.cpp @@ -0,0 +1,262 @@ +/* Icinga 2 | (c) 2020 Icinga GmbH | GPLv2+ */ + +#include "base/accesslogger.hpp" +#include "base/accesslogger-ti.cpp" +#include "base/configtype.hpp" +#include "base/statsfunction.hpp" +#include "base/application.hpp" +#include +#include +#include +#include +#include +#include +#include +#include + +using namespace icinga; +namespace http = boost::beast::http; + +static std::set l_AccessLoggers; +static boost::mutex l_AccessLoggersMutex; + +REGISTER_TYPE(AccessLogger); + +REGISTER_STATSFUNCTION(AccessLogger, &AccessLogger::StatsFunc); + +void AccessLogger::StatsFunc(const Dictionary::Ptr& status, const Array::Ptr&) +{ + DictionaryData nodes; + + for (const AccessLogger::Ptr& accesslogger : ConfigType::GetObjectsByType()) { + nodes.emplace_back(accesslogger->GetName(), 1); //add more stats + } + + status->Set("accesslogger", new Dictionary(std::move(nodes))); +} + +LogAccess::~LogAccess() +{ + decltype(l_AccessLoggers) loggers; + + { + boost::mutex::scoped_lock lock (l_AccessLoggersMutex); + loggers = l_AccessLoggers; + } + + for (auto& logger : loggers) { + ObjectLock oLock (logger); + logger->m_Formatter(*this, *logger->m_Stream); + } +} + +void AccessLogger::Register() +{ + boost::mutex::scoped_lock lock (l_AccessLoggersMutex); + l_AccessLoggers.insert(this); +} + +void AccessLogger::Unregister() +{ + boost::mutex::scoped_lock lock (l_AccessLoggersMutex); + l_AccessLoggers.erase(this); +} + +void AccessLogger::OnAllConfigLoaded() +{ + ObjectImpl::OnAllConfigLoaded(); + + m_Formatter = ParseFormatter(GetFormat()); +} + +void AccessLogger::ValidateFormat(const Lazy& lvalue, const ValidationUtils& utils) +{ + ObjectImpl::ValidateFormat(lvalue, utils); + + try { + ParseFormatter(lvalue()); + } catch (const std::invalid_argument& ex) { + BOOST_THROW_EXCEPTION(ValidationError(this, { "format" }, ex.what())); + } +} + +template +static inline +void StreamHttpProtocol(const Message& in, std::ostream& out) +{ + auto protocol (in.version()); + auto minor (protocol % 10u); + + out << (protocol / 10u); + + if (minor || protocol != 20u) { + out << '.' << minor; + } +} + +template +static inline +void StreamHttpCLength(const Message& in, std::ostream& out) +{ + if (in.count(http::field::content_length)) { + out << in[http::field::content_length]; + } else { + out << '-'; + } +} + +template +static inline +void StreamHttpHeader(const Message& in, const Header& header, std::ostream& out) +{ + if (in.count(header)) { + out << in[header]; + } else { + out << '-'; + } +} + +static boost::regex l_ALFTime (R"EOF(\Atime.(.*)\z)EOF", boost::regex::mod_s); +static boost::regex l_ALFHeaders (R"EOF(\A(request|response).headers.(.*)\z)EOF", boost::regex::mod_s); + +static std::unordered_map l_ALFormatters ({ + { "local.address", [](const LogAccess& in, std::ostream& out) { + out << in.Stream.lowest_layer().local_endpoint().address(); + } }, + { "local.port", [](const LogAccess& in, std::ostream& out) { + out << in.Stream.lowest_layer().local_endpoint().port(); + } }, + { "remote.address", [](const LogAccess& in, std::ostream& out) { + out << in.Stream.lowest_layer().remote_endpoint().address(); + } }, + { "remote.port", [](const LogAccess& in, std::ostream& out) { + out << in.Stream.lowest_layer().remote_endpoint().port(); + } }, + { "remote.user", [](const LogAccess& in, std::ostream& out) { + if (in.User.IsEmpty()) { + out << '-'; + } else { + out << in.User; + } + } }, + { "request.method", [](const LogAccess& in, std::ostream& out) { + out << in.Request.method(); + } }, + { "request.uri", [](const LogAccess& in, std::ostream& out) { + out << in.Request.target(); + } }, + { "request.protocol", [](const LogAccess& in, std::ostream& out) { + StreamHttpProtocol(in.Request, out); + } }, + { "request.size", [](const LogAccess& in, std::ostream& out) { + StreamHttpCLength(in.Request, out); + } }, + { "response.protocol", [](const LogAccess& in, std::ostream& out) { + StreamHttpProtocol(in.Response, out); + } }, + { "response.status", [](const LogAccess& in, std::ostream& out) { + out << (int)in.Response.result(); + } }, + { "response.reason", [](const LogAccess& in, std::ostream& out) { + out << in.Response.reason(); + } }, + { "response.size", [](const LogAccess& in, std::ostream& out) { + StreamHttpCLength(in.Response, out); + } } +}); + +AccessLogger::Formatter AccessLogger::ParseFormatter(const String& format) +{ + std::vector tokens; + boost::algorithm::split(tokens, format.GetData(), boost::algorithm::is_any_of("$")); + + if (tokens.size() % 2u == 0u) { + throw std::invalid_argument("Closing $ not found in macro format string '" + format + "'."); + } + + std::vector formatters; + std::string literal; + bool isLiteral = true; + + for (auto& token : tokens) { + if (isLiteral) { + literal += token; + } else if (token.empty()) { + literal += "$"; + } else { + if (!literal.empty()) { + formatters.emplace_back([literal](const LogAccess&, std::ostream& out) { + out << literal; + }); + + literal = ""; + } + + auto formatter (l_ALFormatters.find(token)); + + if (formatter == l_ALFormatters.end()) { + boost::smatch what; + + if (boost::regex_search(token, what, l_ALFTime)) { + auto spec (what[1].str()); + + formatters.emplace_back([spec](const LogAccess&, std::ostream& out) { + time_t now; + struct tm tmNow; + + (void)time(&now); + (void)localtime_r(&now, &tmNow); + + for (std::vector::size_type size = 64;; size *= 2u) { + std::vector buf (size); + + if (strftime(buf.data(), size, spec.data(), &tmNow)) { + out << buf.data(); + break; + } else if (!strlen(spec.data())) { + break; + } + } + }); + } else if (boost::regex_search(token, what, l_ALFHeaders)) { + auto header (what[2].str()); + + if (what[1] == "request") { + formatters.emplace_back([header](const LogAccess& in, std::ostream& out) { + StreamHttpHeader(in.Request, header, out); + }); + } else { + formatters.emplace_back([header](const LogAccess& in, std::ostream& out) { + StreamHttpHeader(in.Response, header, out); + }); + } + } else { + throw std::invalid_argument("Bad macro '" + token + "'."); + } + } else { + formatters.emplace_back(formatter->second); + } + } + + isLiteral = !isLiteral; + } + + if (!literal.empty()) { + formatters.emplace_back([literal](const LogAccess&, std::ostream& out) { + out << literal; + }); + } + + switch (formatters.size()) { + case 0u: + return [](const LogAccess&, std::ostream&) { }; + case 1u: + return std::move(formatters[0]); + default: + return [formatters](const LogAccess& in, std::ostream& out) { + for (auto& formatter : formatters) { + formatter(in, out); + } + }; + } +} diff --git a/lib/base/accesslogger.hpp b/lib/base/accesslogger.hpp new file mode 100644 index 00000000000..ce03c598770 --- /dev/null +++ b/lib/base/accesslogger.hpp @@ -0,0 +1,73 @@ +/* Icinga 2 | (c) 2020 Icinga GmbH | GPLv2+ */ + +#ifndef ACCESSLOGGER_H +#define ACCESSLOGGER_H + +#include "base/i2-base.hpp" +#include "base/accesslogger-ti.hpp" +#include "base/shared.hpp" +#include "base/tlsstream.hpp" +#include +#include +#include +#include + +namespace icinga +{ + +class LogAccess +{ +public: + inline LogAccess( + const AsioTlsStream& stream, + const boost::beast::http::request& request, + String user, + const boost::beast::http::response& response + ) : Stream(stream), Request(request), User(std::move(user)), Response(response) + {} + + LogAccess(const LogAccess&) = delete; + LogAccess(LogAccess&&) = delete; + LogAccess& operator=(const LogAccess&) = delete; + LogAccess& operator=(LogAccess&&) = delete; + ~LogAccess(); + + const AsioTlsStream& Stream; + const boost::beast::http::request& Request; + String User; + const boost::beast::http::response& Response; +}; + +/** + * A file logger that logs API access. + * + * @ingroup base + */ +class AccessLogger final : public ObjectImpl +{ + friend LogAccess; + +public: + typedef void FormatterFunc(const LogAccess& in, std::ostream& out); + typedef std::function Formatter; + + DECLARE_OBJECT(AccessLogger); + DECLARE_OBJECTNAME(AccessLogger); + + static void StatsFunc(const Dictionary::Ptr& status, const Array::Ptr& perfdata); + +protected: + void OnAllConfigLoaded() override; + void ValidateFormat(const Lazy& lvalue, const ValidationUtils& utils) override; + void Register() override; + void Unregister() override; + +private: + Formatter ParseFormatter(const String& format); + + Formatter m_Formatter; +}; + +} + +#endif /* ACCESSLOGGER_H */ diff --git a/lib/base/accesslogger.ti b/lib/base/accesslogger.ti new file mode 100644 index 00000000000..1326bf0fc17 --- /dev/null +++ b/lib/base/accesslogger.ti @@ -0,0 +1,20 @@ +/* Icinga 2 | (c) 2020 Icinga GmbH | GPLv2+ */ + +#include "base/filelogger.hpp" + +library base; + +namespace icinga +{ + +class AccessLogger : FileLogger +{ + activation_priority -99; + + [config] String format { + default {{{ return R"EOF($remote.address$ - $remote.user$ [$time.%d/%b/%Y:%T %z$] "$request.method$ $request.uri$ HTTP/$request.protocol$" $response.status$ $response.size$ +)EOF"; }}} + }; +}; + +} diff --git a/lib/base/filelogger.cpp b/lib/base/filelogger.cpp index c3da84a3700..91a5e5f2572 100644 --- a/lib/base/filelogger.cpp +++ b/lib/base/filelogger.cpp @@ -35,7 +35,7 @@ void FileLogger::Start(bool runtimeCreated) ObjectImpl::Start(runtimeCreated); - Log(LogInformation, "FileLogger") + Log(LogInformation, GetReflectionType()->GetName()) << "'" << GetName() << "' started."; } diff --git a/lib/base/filelogger.hpp b/lib/base/filelogger.hpp index 420337f6a84..905b294fc0b 100644 --- a/lib/base/filelogger.hpp +++ b/lib/base/filelogger.hpp @@ -14,7 +14,7 @@ namespace icinga * * @ingroup base */ -class FileLogger final : public ObjectImpl +class FileLogger : public ObjectImpl { public: DECLARE_OBJECT(FileLogger); diff --git a/lib/base/logger.cpp b/lib/base/logger.cpp index 38a2c6721b4..55daabd7225 100644 --- a/lib/base/logger.cpp +++ b/lib/base/logger.cpp @@ -53,7 +53,17 @@ INITIALIZE_ONCE([]() { void Logger::Start(bool runtimeCreated) { ObjectImpl::Start(runtimeCreated); + Register(); +} + +void Logger::Stop(bool runtimeRemoved) +{ + Unregister(); + ObjectImpl::Stop(runtimeRemoved); +} +void Logger::Register() +{ { std::unique_lock lock(m_Mutex); m_Loggers.insert(this); @@ -62,7 +72,7 @@ void Logger::Start(bool runtimeCreated) UpdateMinLogSeverity(); } -void Logger::Stop(bool runtimeRemoved) +void Logger::Unregister() { { std::unique_lock lock(m_Mutex); @@ -70,8 +80,6 @@ void Logger::Stop(bool runtimeRemoved) } UpdateMinLogSeverity(); - - ObjectImpl::Stop(runtimeRemoved); } std::set Logger::GetLoggers() diff --git a/lib/base/logger.hpp b/lib/base/logger.hpp index 7b4758d8b72..a7d8b8e88d2 100644 --- a/lib/base/logger.hpp +++ b/lib/base/logger.hpp @@ -93,6 +93,9 @@ class Logger : public ObjectImpl void Start(bool runtimeCreated) override; void Stop(bool runtimeRemoved) override; + virtual void Register(); + virtual void Unregister(); + private: static void UpdateMinLogSeverity(); diff --git a/lib/base/streamlogger.hpp b/lib/base/streamlogger.hpp index 8cbe313cedd..71d82b1fc7f 100644 --- a/lib/base/streamlogger.hpp +++ b/lib/base/streamlogger.hpp @@ -31,10 +31,10 @@ class StreamLogger : public ObjectImpl protected: void ProcessLogEntry(const LogEntry& entry) final; void Flush() final; + std::ostream *m_Stream{nullptr}; private: static std::mutex m_Mutex; - std::ostream *m_Stream{nullptr}; bool m_OwnsStream{false}; Timer::Ptr m_FlushLogTimer; diff --git a/lib/remote/eventshandler.cpp b/lib/remote/eventshandler.cpp index bdda714611d..b8513185267 100644 --- a/lib/remote/eventshandler.cpp +++ b/lib/remote/eventshandler.cpp @@ -5,6 +5,7 @@ #include "remote/filterutility.hpp" #include "config/configcompiler.hpp" #include "config/expression.hpp" +#include "base/accesslogger.hpp" #include "base/defer.hpp" #include "base/io-engine.hpp" #include "base/objectlock.hpp" @@ -105,6 +106,8 @@ bool EventsHandler::HandleRequest( response.result(http::status::ok); response.set(http::field::content_type, "application/json"); + LogAccess(stream, request, user ? user->GetName() : "", response); + IoBoundWorkSlot dontLockTheIoThread (yc); http::async_write(stream, response, yc); diff --git a/lib/remote/httpserverconnection.cpp b/lib/remote/httpserverconnection.cpp index cc0ecc37672..71383c41f10 100644 --- a/lib/remote/httpserverconnection.cpp +++ b/lib/remote/httpserverconnection.cpp @@ -6,6 +6,7 @@ #include "remote/apilistener.hpp" #include "remote/apifunction.hpp" #include "remote/jsonrpc.hpp" +#include "base/accesslogger.hpp" #include "base/application.hpp" #include "base/base64.hpp" #include "base/convert.hpp" @@ -143,10 +144,16 @@ bool EnsureValidHeaders( return false; bool httpError = false; + bool logAccess = true; String errorMsg; boost::system::error_code ec; + if (!buf.size() && !stream.in_avail()) { + boost::system::error_code ec; + logAccess = stream.async_fill(yc[ec]); + } + http::async_read_header(stream, buf, parser, yc[ec]); if (ec) { @@ -181,6 +188,10 @@ bool EnsureValidHeaders( response.set(http::field::connection, "close"); + if (logAccess) { + LogAccess(stream, parser.get(), "", response); + } + http::async_write(stream, response, yc); stream.async_flush(yc); @@ -213,6 +224,7 @@ static inline bool HandleAccessControl( AsioTlsStream& stream, boost::beast::http::request& request, + ApiUser::Ptr& authenticatedUser, boost::beast::http::response& response, boost::asio::yield_context& yc ) @@ -244,6 +256,8 @@ bool HandleAccessControl( response.content_length(response.body().size()); response.set(http::field::connection, "close"); + LogAccess(stream, request, authenticatedUser ? authenticatedUser->GetName() : "", response); + http::async_write(stream, response, yc); stream.async_flush(yc); @@ -260,6 +274,7 @@ static inline bool EnsureAcceptHeader( AsioTlsStream& stream, boost::beast::http::request& request, + ApiUser::Ptr& authenticatedUser, boost::beast::http::response& response, boost::asio::yield_context& yc ) @@ -273,6 +288,8 @@ bool EnsureAcceptHeader( response.content_length(response.body().size()); response.set(http::field::connection, "close"); + LogAccess(stream, request, authenticatedUser ? authenticatedUser->GetName() : "", response); + http::async_write(stream, response, yc); stream.async_flush(yc); @@ -312,6 +329,8 @@ bool EnsureAuthenticatedUser( response.content_length(response.body().size()); } + LogAccess(stream, request, "", response); + http::async_write(stream, response, yc); stream.async_flush(yc); @@ -326,6 +345,7 @@ bool EnsureValidBody( AsioTlsStream& stream, boost::beast::flat_buffer& buf, boost::beast::http::parser& parser, + boost::beast::http::request& request, ApiUser::Ptr& authenticatedUser, boost::beast::http::response& response, bool& shuttingDown, @@ -402,6 +422,8 @@ bool EnsureValidBody( response.set(http::field::connection, "close"); + LogAccess(stream, request, authenticatedUser ? authenticatedUser->GetName() : "", response); + http::async_write(stream, response, yc); stream.async_flush(yc); @@ -447,6 +469,8 @@ bool ProcessRequest( HttpUtility::SendJsonError(response, nullptr, 500, "Unhandled exception" , DiagnosticInformation(ex)); + LogAccess(stream, request, authenticatedUser ? authenticatedUser->GetName() : "", response); + http::async_write(stream, response, yc); stream.async_flush(yc); @@ -457,6 +481,8 @@ bool ProcessRequest( return false; } + LogAccess(stream, request, authenticatedUser ? authenticatedUser->GetName() : "", response); + http::async_write(stream, response, yc); stream.async_flush(yc); @@ -530,11 +556,11 @@ void HttpServerConnection::ProcessMessages(boost::asio::yield_context yc) logMsg << " took total " << ch::duration_cast(ch::steady_clock::now() - start).count() << "ms."; }); - if (!HandleAccessControl(*m_Stream, request, response, yc)) { + if (!HandleAccessControl(*m_Stream, request, authenticatedUser, response, yc)) { break; } - if (!EnsureAcceptHeader(*m_Stream, request, response, yc)) { + if (!EnsureAcceptHeader(*m_Stream, request, authenticatedUser, response, yc)) { break; } @@ -542,7 +568,7 @@ void HttpServerConnection::ProcessMessages(boost::asio::yield_context yc) break; } - if (!EnsureValidBody(*m_Stream, buf, parser, authenticatedUser, response, m_ShuttingDown, yc)) { + if (!EnsureValidBody(*m_Stream, buf, parser, request, authenticatedUser, response, m_ShuttingDown, yc)) { break; }