Skip to content

Logger#object_filter: restrict Logger to messages referring to specific objects #9844

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
wants to merge 15 commits into
base: master
Choose a base branch
from
Draft

Logger#object_filter: restrict Logger to messages referring to specific objects #9844

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
15 commits
Select commit Hold shift + click to select a range
aaa0657
Introduce Logger#object_filter
Al2Klimov Aug 11, 2023
0738d6b
Logger#{OnAllConfigLoaded,SetObjectFilter}(): warn on missing objects…
Al2Klimov Aug 11, 2023
071dae8
Cache actual Logger#object_filter objects in Logger#m_ObjectFilterCache
Al2Klimov Aug 11, 2023
fd4d3e8
Introduce ObjectImpl<ConfigObject>#GetParentsAffectingLogging()
Al2Klimov Aug 14, 2023
491499a
Disallow Downtime#config_owner modification
Al2Klimov Aug 14, 2023
fff2cd8
Forbid Zone#endpoints modification
Al2Klimov Aug 14, 2023
844bcd7
parent_affecting_logging: a zone affects everything in it
Al2Klimov Aug 14, 2023
ddc1073
parent_affecting_logging: a group affects everything in it
Al2Klimov Aug 14, 2023
8c3b6ad
parent_affecting_logging: a config object affects everything applied …
Al2Klimov Aug 14, 2023
f98b5c5
parent_affecting_logging: a config object affects everything function…
Al2Klimov Aug 14, 2023
a3a6a8a
ConfigObject#OnAllConfigLoaded(): build m_AllParentsAffectingLogging …
Al2Klimov Aug 15, 2023
481ef9e
Merge Log#Log() methods
Al2Klimov Aug 11, 2023
6b642b2
Log#Log(): require passing one involved object
Al2Klimov Aug 11, 2023
81ab5b6
[TODO: REVERT] Repair GHA for now
Al2Klimov Aug 11, 2023
9f9e2b3
Log#~Log(): skip messages based on Logger#m_ObjectFilterCache & Confi…
Al2Klimov Aug 16, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
24 changes: 24 additions & 0 deletions lib/base/configobject.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -419,6 +419,30 @@ void ConfigObject::OnAllConfigLoaded()

if (!zoneName.IsEmpty())
m_Zone = ctype->GetObject(zoneName);

std::vector<Ptr> toDo {this};

do {
auto current (toDo.back());

toDo.pop_back();

if (m_AllParentsAffectingLogging.Data.emplace(current.get()).second) {
current->GetParentsAffectingLogging(toDo);
}
} while (!toDo.empty());
Comment on lines +423 to +433
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So m_AllParentsAffectingLogging.Data will contain Ptr(this), so wouldn't this prevent the object from ever being deleted?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I permanently store only raw pointers, not intrusive ones.


m_AllParentsAffectingLogging.Frozen.store(true);
}

const std::set<ConfigObject*>& ConfigObject::GetAllParentsAffectingLogging() const
{
if (m_AllParentsAffectingLogging.Frozen.load(std::memory_order_relaxed)) {
return m_AllParentsAffectingLogging.Data;
}

static const std::set<ConfigObject*> fallback;
return fallback;
}

void ConfigObject::CreateChildObjects(const Type::Ptr& childType)
Expand Down
8 changes: 8 additions & 0 deletions lib/base/configobject.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,11 +4,13 @@
#define CONFIGOBJECT_H

#include "base/i2-base.hpp"
#include "base/atomic.hpp"
#include "base/configobject-ti.hpp"
#include "base/object.hpp"
#include "base/type.hpp"
#include "base/dictionary.hpp"
#include <boost/signals2.hpp>
#include <set>

namespace icinga
{
Expand Down Expand Up @@ -60,6 +62,7 @@ class ConfigObject : public ObjectImpl<ConfigObject>
virtual void OnStateLoaded();

Dictionary::Ptr GetSourceLocation() const override;
const std::set<ConfigObject*>& GetAllParentsAffectingLogging() const;

template<typename T>
static intrusive_ptr<T> GetObject(const String& name)
Expand All @@ -82,6 +85,11 @@ class ConfigObject : public ObjectImpl<ConfigObject>
private:
ConfigObject::Ptr m_Zone;

struct {
std::set<ConfigObject*> Data;
Atomic<bool> Frozen {false};
} m_AllParentsAffectingLogging;

static void RestoreObject(const String& message, int attributeTypes);
};

Expand Down
2 changes: 1 addition & 1 deletion lib/base/configobject.ti
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -66,7 +66,7 @@ abstract class ConfigObject : ConfigObjectBase < ConfigType
return shortName;
}}}
};
[config, no_user_modify] name(Zone) zone (ZoneName);
[config, no_user_modify, parent_affecting_logging] name(Zone) zone (ZoneName);
[config, no_user_modify] String package;
[config, get_protected, no_user_modify] Array::Ptr templates;
[config, no_storage, no_user_modify] Dictionary::Ptr source_location {
Expand Down
138 changes: 129 additions & 9 deletions lib/base/logger.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,9 @@
#endif /* _WIN32 */
#include <algorithm>
#include <iostream>
#include <iterator>
#include <utility>
#include <vector>

using namespace icinga;

Expand Down Expand Up @@ -62,6 +64,19 @@ void Logger::Start(bool runtimeCreated)
UpdateMinLogSeverity();
}

void Logger::SetObjectFilter(const Dictionary::Ptr& value, bool suppress_events, const Value& cookie)
{
ObjectImpl<Logger>::SetObjectFilter(value, suppress_events, cookie);
UpdateCheckObjectFilterCache();
}

void Logger::OnAllConfigLoaded()
{
ObjectImpl<Logger>::OnAllConfigLoaded();
m_CalledOnAllConfigLoaded.store(true);
UpdateCheckObjectFilterCache();
}

void Logger::Stop(bool runtimeRemoved)
{
{
Expand All @@ -74,6 +89,47 @@ void Logger::Stop(bool runtimeRemoved)
ObjectImpl<Logger>::Stop(runtimeRemoved);
}

void Logger::ValidateObjectFilter(const Lazy<Dictionary::Ptr>& lvalue, const ValidationUtils& utils)
{
ObjectImpl<Logger>::ValidateObjectFilter(lvalue, utils);

auto filter (lvalue());

if (filter) {
ObjectLock lock (filter);

for (auto& kv : filter) {
auto type (Type::GetByName(kv.first));

if (!type) {
BOOST_THROW_EXCEPTION(
ValidationError(this, {"object_filter"}, "No such type: '" + kv.first + "'")
);
}

if (!dynamic_cast<ConfigType*>(type.get())) {
BOOST_THROW_EXCEPTION(
ValidationError(this, {"object_filter"}, "Not a config object type: '" + kv.first + "'")
);
}

Array::Ptr objects = kv.second;

if (objects) {
ObjectLock lock (objects);

for (auto& object : objects) {
if (object.GetType() != ValueString) {
BOOST_THROW_EXCEPTION(
ValidationError(this, {"object_filter", kv.first}, "Must be an array of strings.")
);
}
}
}
}
}
}

std::set<Logger::Ptr> Logger::GetLoggers()
{
std::unique_lock<std::mutex> lock(m_Mutex);
Expand Down Expand Up @@ -243,17 +299,61 @@ void Logger::UpdateMinLogSeverity()
m_MinLogSeverity.store(result);
}

Log::Log(LogSeverity severity, String facility, const String& message)
: Log(severity, std::move(facility))
void Logger::UpdateCheckObjectFilterCache()
{
if (!m_IsNoOp) {
m_Buffer << message;
if (!m_CalledOnAllConfigLoaded.load()) {
return;
}

auto filter (GetObjectFilter());

if (!filter) {
ObjectLock lock (this);
m_ObjectFilterCache.clear();
return;
}

std::vector<ConfigObject*> allObjects;

{
ObjectLock lock (filter);

for (auto& kv : filter) {
auto type (Type::GetByName(kv.first));
auto ctype (dynamic_cast<ConfigType*>(type.get()));
Array::Ptr objects = kv.second;

if (ctype && objects) {
ObjectLock lock (objects);

for (String name : objects) {
auto object (ctype->GetObject(name));

if (object) {
allObjects.emplace_back(object.get());
} else {
Log(LogWarning, GetReflectionType()->GetName())
<< "Missing " << kv.first << " '" << name << "' in name filter of '" << GetName() << "'.";
}
}
}
}
}

std::sort(allObjects.begin(), allObjects.end());

ObjectLock lock (this);

m_ObjectFilterCache.swap(allObjects);
}

Log::Log(LogSeverity severity, String facility)
Log::Log(LogSeverity severity, String facility, const String& message)
: m_Severity(severity), m_Facility(std::move(facility)), m_IsNoOp(severity < Logger::GetMinLogSeverity())
{ }
{
if (!m_IsNoOp && !message.IsEmpty()) {
m_Buffer << message;
}
}

/**
* Writes the message to the application's log.
Expand Down Expand Up @@ -289,11 +389,31 @@ Log::~Log()
for (const Logger::Ptr& logger : Logger::GetLoggers()) {
ObjectLock llock(logger);

if (!logger->IsActive())
if (!logger->IsActive()) {
continue;
}

if (entry.Severity < logger->GetMinSeverity()) {
continue;
}

if (logger->GetObjectFilter()) {
if (!m_Involved) {
continue;
}

auto& allowed (logger->GetObjectFilterCache());
auto& indirect (m_Involved->GetAllParentsAffectingLogging());
std::vector<ConfigObject*> intersection;

std::set_intersection(allowed.begin(), allowed.end(), indirect.begin(), indirect.end(), std::back_inserter(intersection));

if (intersection.empty()) {
continue;
}
}

if (entry.Severity >= logger->GetMinSeverity())
logger->ProcessLogEntry(entry);
logger->ProcessLogEntry(entry);

#ifdef I2_DEBUG /* I2_DEBUG */
/* Always flush, don't depend on the timer. Enable this for development sprints on Linux/macOS only. Windows crashes. */
Expand Down
20 changes: 17 additions & 3 deletions lib/base/logger.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,9 +5,11 @@

#include "base/atomic.hpp"
#include "base/i2-base.hpp"
#include "base/configobject.hpp"
#include "base/logger-ti.hpp"
#include <set>
#include <sstream>
#include <vector>

namespace icinga
{
Expand Down Expand Up @@ -88,14 +90,24 @@ class Logger : public ObjectImpl<Logger>

void SetSeverity(const String& value, bool suppress_events = false, const Value& cookie = Empty) override;
void ValidateSeverity(const Lazy<String>& lvalue, const ValidationUtils& utils) final;
void SetObjectFilter(const Dictionary::Ptr& value, bool suppress_events = false, const Value& cookie = Empty) override;
void OnAllConfigLoaded() override;

inline const std::vector<ConfigObject*>& GetObjectFilterCache() const
{
return m_ObjectFilterCache;
}

protected:
void Start(bool runtimeCreated) override;
void Stop(bool runtimeRemoved) override;
void ValidateObjectFilter(const Lazy<Dictionary::Ptr>& lvalue, const ValidationUtils& utils) override;

private:
static void UpdateMinLogSeverity();

void UpdateCheckObjectFilterCache();

static std::mutex m_Mutex;
static std::set<Logger::Ptr> m_Loggers;
static bool m_ConsoleLogEnabled;
Expand All @@ -104,6 +116,9 @@ class Logger : public ObjectImpl<Logger>
static LogSeverity m_ConsoleLogSeverity;
static std::mutex m_UpdateMinLogSeverityMutex;
static Atomic<LogSeverity> m_MinLogSeverity;

Atomic<bool> m_CalledOnAllConfigLoaded {false};
std::vector<ConfigObject*> m_ObjectFilterCache;
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As these are raw pointer, is there anything preventing them from becoming dangling? (For those in ConfigObject.m_AllParentsAffectingLogging.Data one might argue with that they should only be removed in a safe order, but even that should be double checked and here, I don't see anything like that.)

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nothing at all and I see no problems as they're only intersected anyway.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It looks like the behavior of that is implementation-defined (see https://stackoverflow.com/a/30694084, and even undefined in C++11) and even in the best-case scenario, this could result in some object randomly being logged if is allocated at the same address as some previous object that was included in the filter.

Apart from that, leaving dangling pointers is always dangerous, better hope nobody will ever have an idea that involves dereferencing the pointers in this vector.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Seriously, a raw pointer is just a number. Not more, not less. In Log#~Log(🪵) I'm only comparing numbers. Change my mind.

this could result in some object randomly being logged if is allocated at the same address as some previous object that was included in the filter.

Yes, in case someone who explicitly included an object in a filter removes that object. Again, explicitly. Would you feel better if I maintain an additional vector with Ptr, just for keep alive?

Apart from that, leaving dangling pointers is always dangerous, better hope nobody will ever have an idea that involves dereferencing the pointers in this vector.

DependencyGraph has the same problem.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Seriously, a raw pointer is just a number. Not more, not less. In Log#~Log(🪵) I'm only comparing numbers. Change my mind.

That's probably what most people expect, but compilers may see an opportunity for optimization that could go wrong.

this could result in some object randomly being logged if is allocated at the same address as some previous object that was included in the filter.

Yes, in case someone who explicitly included an object in a filter removes that object. Again, explicitly. Would you feel better if I maintain an additional vector with Ptr, just for keep alive?

Which would then just prevent the object from ever being freed?

Apart from that, leaving dangling pointers is always dangerous, better hope nobody will ever have an idea that involves dereferencing the pointers in this vector.

DependencyGraph has the same problem.

I hope it doesn't. DependencyGraph will even dereference the pointers itself in DependencyGraph::GetParents() so there better be no dangling pointers. Objects should do DependencyGraph::RemoveDependency() before they die, if they don't, it's a bug.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Seriously, a raw pointer is just a number. Not more, not less. In Log#~Log(🪵) I'm only comparing numbers. Change my mind.

That's probably what most people expect, but compilers may see an opportunity for optimization that could go wrong.

Suggestion:

I assert std::is_trivial_v on the pointer type I use.

this could result in some object randomly being logged if is allocated at the same address as some previous object that was included in the filter.

Yes, in case someone who explicitly included an object in a filter removes that object. Again, explicitly. Would you feel better if I maintain an additional vector with Ptr, just for keep alive?

Which would then just prevent the object from ever being freed?

Exactly. (Especially with my recursive relationship feature) one shouldn't list every single object in the config.

Apart from that, leaving dangling pointers is always dangerous, better hope nobody will ever have an idea that involves dereferencing the pointers in this vector.

DependencyGraph has the same problem.

I hope it doesn't. DependencyGraph will even dereference the pointers itself in DependencyGraph::GetParents() so there better be no dangling pointers. Objects should do DependencyGraph::RemoveDependency() before they die, if they don't, it's a bug.

+1.

All in all, have I ever mentioned I'd like the classic std::shared_ptr back? We'd have std::weak_ptr which enables having not dangling, but not leaking pointers.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggestion:

I assert std::is_trivial_v on the pointer type I use.

Ah, nice! Pointer types are scalar types (https://en.cppreference.com/w/cpp/named_req/ScalarType) which are trivial types (https://en.cppreference.com/w/cpp/named_req/TrivialType).

compilers may see an opportunity for optimization that could go wrong.

Shall I make my just-numbers volatile then?

};

class Log
Expand All @@ -113,9 +128,7 @@ class Log
Log(const Log& other) = delete;
Log& operator=(const Log& rhs) = delete;

Log(LogSeverity severity, String facility, const String& message);
Log(LogSeverity severity, String facility);

Log(LogSeverity severity, String facility, const String& message = String());
~Log();

template<typename T>
Expand All @@ -133,6 +146,7 @@ class Log
private:
LogSeverity m_Severity;
String m_Facility;
ConfigObject::Ptr m_Involved;
std::ostringstream m_Buffer;
bool m_IsNoOp;
};
Expand Down
7 changes: 7 additions & 0 deletions lib/base/logger.ti
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,13 @@ abstract class Logger : ConfigObject
[config, set_virtual] String severity {
default {{{ return "information"; }}}
};
[config, set_virtual] Dictionary::Ptr object_filter;
};

validator Logger {
Dictionary object_filter {
Array "*";
};
};

}
4 changes: 2 additions & 2 deletions lib/icinga/comment.ti
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,12 +34,12 @@ class Comment : ConfigObject < CommentNameComposer
load_after Host;
load_after Service;

[config, no_user_modify, protected, required, navigation(host)] name(Host) host_name {
[config, no_user_modify, protected, required, navigation(host), parent_affecting_logging] name(Host) host_name {
navigate {{{
return Host::GetByName(GetHostName());
}}}
};
[config, no_user_modify, protected, navigation(service)] String service_name {
[config, no_user_modify, protected, navigation(service), parent_affecting_logging] String service_name {
track {{{
if (!oldValue.IsEmpty()) {
Service::Ptr service = Service::GetByNamePair(GetHostName(), oldValue);
Expand Down
8 changes: 4 additions & 4 deletions lib/icinga/dependency.ti
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -23,13 +23,13 @@ class Dependency : CustomVarObject < DependencyNameComposer
load_after Host;
load_after Service;

[config, no_user_modify, required, navigation(child_host)] name(Host) child_host_name {
[config, no_user_modify, required, navigation(child_host), parent_affecting_logging] name(Host) child_host_name {
navigate {{{
return Host::GetByName(GetChildHostName());
}}}
};

[config, no_user_modify, navigation(child_service)] String child_service_name {
[config, no_user_modify, navigation(child_service), parent_affecting_logging] String child_service_name {
track {{{
if (!oldValue.IsEmpty()) {
Service::Ptr service = Service::GetByNamePair(GetChildHostName(), oldValue);
Expand All @@ -50,13 +50,13 @@ class Dependency : CustomVarObject < DependencyNameComposer
}}}
};

[config, no_user_modify, required, navigation(parent_host)] name(Host) parent_host_name {
[config, no_user_modify, required, navigation(parent_host), parent_affecting_logging] name(Host) parent_host_name {
navigate {{{
return Host::GetByName(GetParentHostName());
}}}
};

[config, no_user_modify, navigation(parent_service)] String parent_service_name {
[config, no_user_modify, navigation(parent_service), parent_affecting_logging] String parent_service_name {
track {{{
if (!oldValue.IsEmpty()) {
Service::Ptr service = Service::GetByNamePair(GetParentHostName(), oldValue);
Expand Down
11 changes: 11 additions & 0 deletions lib/icinga/downtime.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -167,6 +167,17 @@ void Downtime::Stop(bool runtimeRemoved)
ObjectImpl<Downtime>::Stop(runtimeRemoved);
}

void Downtime::GetParentsAffectingLogging(std::vector<ConfigObject::Ptr>& output) const
{
ObjectImpl<Downtime>::GetParentsAffectingLogging(output);

auto object (ConfigObject::GetObject<ScheduledDowntime>(GetConfigOwner()));

if (object) {
output.emplace_back(std::move(object));
}
}

void Downtime::Pause()
{
if (m_CleanupTimer) {
Expand Down
Loading
Loading