Calculate time spent on evaluating mismatching apply rules and parent objects

lib/base/configobject.cpp

@@ -421,7 +421,7 @@ void ConfigObject::OnAllConfigLoaded()
 		m_Zone = ctype->GetObject(zoneName);
 }
 
-void ConfigObject::CreateChildObjects(const Type::Ptr& childType)
+void ConfigObject::CreateChildObjects(const Type::Ptr& childType, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches)
 {
 	/* Nothing to do here. */
 }

lib/base/configobject.hpp

@@ -14,6 +14,7 @@ namespace icinga
 {
 
 class ConfigType;
+class TotalTimeSpentOnApplyMismatches;
 
 /**
  * A dynamic object that can be instantiated from the configuration file.
@@ -55,7 +56,7 @@ public:
 	virtual void Resume();
 
 	virtual void OnConfigLoaded();
-	virtual void CreateChildObjects(const Type::Ptr& childType);
+	virtual void CreateChildObjects(const Type::Ptr& childType, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches);
 	virtual void OnAllConfigLoaded();
 	virtual void OnStateLoaded();
 

lib/config/applyrule.cpp

@@ -197,3 +197,10 @@ void ApplyRule::CheckMatches(const ApplyRule::Ptr& rule, Type* sourceType, bool
 			<< sourceType->GetName() << "' does not match anywhere!";
 	}
 }
+
+double TotalTimeSpentOnApplyMismatches::AsSeconds() const
+{
+	using namespace std::chrono;
+
+	return duration<double, seconds::period>(steady_clock::duration(m_MonotonicTicks.load())).count();
+}

lib/config/applyrule.hpp

@@ -5,9 +5,11 @@
 
 #include "config/i2-config.hpp"
 #include "config/expression.hpp"
+#include "base/atomic.hpp"
 #include "base/debuginfo.hpp"
 #include "base/shared-object.hpp"
 #include "base/type.hpp"
+#include <chrono>
 #include <unordered_map>
 
 namespace icinga
@@ -110,6 +112,53 @@ private:
 		bool ignoreOnError, DebugInfo di, Dictionary::Ptr scope);
 };
 
+class BenchmarkApplyRuleEvaluation;
+
+class TotalTimeSpentOnApplyMismatches
+{
+	friend BenchmarkApplyRuleEvaluation;
+
+public:
+	TotalTimeSpentOnApplyMismatches() = default;
+	TotalTimeSpentOnApplyMismatches(const TotalTimeSpentOnApplyMismatches&) = delete;
+	TotalTimeSpentOnApplyMismatches(TotalTimeSpentOnApplyMismatches&&) = delete;
+	TotalTimeSpentOnApplyMismatches& operator=(const TotalTimeSpentOnApplyMismatches&) = delete;
+	TotalTimeSpentOnApplyMismatches& operator=(TotalTimeSpentOnApplyMismatches&&) = delete;
+
+	double AsSeconds() const;
+
+private:
+	Atomic<std::chrono::steady_clock::rep> m_MonotonicTicks {0};
+};
+
+class BenchmarkApplyRuleEvaluation
+{
+public:
+	inline BenchmarkApplyRuleEvaluation(TotalTimeSpentOnApplyMismatches& totalTimeSpentOnMismatches, const bool& ruleMatched)
+		: m_TotalTimeSpentOnMismatches(totalTimeSpentOnMismatches),
+		m_RuleMatched(ruleMatched), m_Start(std::chrono::steady_clock::now())
+	{ }
+
+	BenchmarkApplyRuleEvaluation(const BenchmarkApplyRuleEvaluation&) = delete;
+	BenchmarkApplyRuleEvaluation(BenchmarkApplyRuleEvaluation&&) = delete;
+	BenchmarkApplyRuleEvaluation& operator=(const BenchmarkApplyRuleEvaluation&) = delete;
+	BenchmarkApplyRuleEvaluation& operator=(BenchmarkApplyRuleEvaluation&&) = delete;
+
+	inline ~BenchmarkApplyRuleEvaluation()
+	{
+		if (!m_RuleMatched) {
+			m_TotalTimeSpentOnMismatches.m_MonotonicTicks.fetch_add(
+				(std::chrono::steady_clock::now() - m_Start).count()
+			);
+		}
+	}
+
+private:
+	TotalTimeSpentOnApplyMismatches& m_TotalTimeSpentOnMismatches;
+	const bool& m_RuleMatched;
+	std::chrono::steady_clock::time_point m_Start;
+};
+
 }
 
 #endif /* APPLYRULE_H */

lib/config/configitem.cpp

@@ -385,7 +385,10 @@ ConfigItem::Ptr ConfigItem::GetByTypeAndName(const Type::Ptr& type, const String
 	return it2->second;
 }
 
-bool ConfigItem::CommitNewItems(const ActivationContext::Ptr& context, WorkQueue& upq, std::vector<ConfigItem::Ptr>& newItems)
+bool ConfigItem::CommitNewItems(
+	const ActivationContext::Ptr& context, WorkQueue& upq, std::vector<ConfigItem::Ptr>& newItems,
+	TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches
+)
 {
 	typedef std::pair<ConfigItem::Ptr, bool> ItemPair;
 	std::unordered_map<Type*, std::vector<ItemPair>> itemsByType;
@@ -595,14 +598,14 @@ bool ConfigItem::CommitNewItems(const ActivationContext::Ptr& context, WorkQueue
 				auto items (itemsByType.find(loadDep));
 
 				if (items != itemsByType.end()) {
-					upq.ParallelFor(items->second, [&type, &notified_items](const ItemPair& ip) {
+					upq.ParallelFor(items->second, [&type, &notified_items, &totalTimeSpentOnApplyMismatches](const ItemPair& ip) {
 						const ConfigItem::Ptr& item = ip.first;
 
 						if (!item->m_Object)
 							return;
 
 						ActivationScope ascope(item->m_ActivationContext);
-						item->m_Object->CreateChildObjects(type);
+						item->m_Object->CreateChildObjects(type, totalTimeSpentOnApplyMismatches);
 						notified_items++;
 					});
 				}
@@ -620,7 +623,7 @@ bool ConfigItem::CommitNewItems(const ActivationContext::Ptr& context, WorkQueue
 				return false;
 
 			// Make sure to activate any additionally generated items
-			if (!CommitNewItems(context, upq, newItems))
+			if (!CommitNewItems(context, upq, newItems, totalTimeSpentOnApplyMismatches))
 				return false;
 		}
 	}
@@ -633,7 +636,9 @@ bool ConfigItem::CommitItems(const ActivationContext::Ptr& context, WorkQueue& u
 	if (!silent)
 		Log(LogInformation, "ConfigItem", "Committing config item(s).");
 
-	if (!CommitNewItems(context, upq, newItems)) {
+	TotalTimeSpentOnApplyMismatches totalTimeSpentOnApplyMismatches;
+
+	if (!CommitNewItems(context, upq, newItems, totalTimeSpentOnApplyMismatches)) {
 		upq.ReportExceptions("config");
 
 		for (const ConfigItem::Ptr& item : newItems) {
@@ -646,6 +651,10 @@ bool ConfigItem::CommitItems(const ActivationContext::Ptr& context, WorkQueue& u
 	ApplyRule::CheckMatches(silent);
 
 	if (!silent) {
+		Log(LogNotice, "ConfigItem")
+			<< "Spent " << totalTimeSpentOnApplyMismatches.AsSeconds()
+			<< " seconds on evaluating mismatching apply rules and parent objects.";
+
 		/* log stats for external parsers */
 		typedef std::map<Type::Ptr, int> ItemCountMap;
 		ItemCountMap itemCounts;

lib/config/configitem.hpp

@@ -6,6 +6,7 @@
 #include "config/i2-config.hpp"
 #include "config/expression.hpp"
 #include "config/activationcontext.hpp"
+#include "config/applyrule.hpp"
 #include "base/configobject.hpp"
 #include "base/workqueue.hpp"
 
@@ -98,7 +99,10 @@ private:
 
 	ConfigObject::Ptr Commit(bool discard = true);
 
-	static bool CommitNewItems(const ActivationContext::Ptr& context, WorkQueue& upq, std::vector<ConfigItem::Ptr>& newItems);
+	static bool CommitNewItems(
+		const ActivationContext::Ptr& context, WorkQueue& upq, std::vector<ConfigItem::Ptr>& newItems,
+		TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches
+	);
 };
 
 }

lib/icinga/dependency-apply.cpp

@@ -62,8 +62,11 @@ bool Dependency::EvaluateApplyRuleInstance(const Checkable::Ptr& checkable, cons
 	return true;
 }
 
-bool Dependency::EvaluateApplyRule(const Checkable::Ptr& checkable, const ApplyRule& rule, bool skipFilter)
+bool Dependency::EvaluateApplyRule(const Checkable::Ptr& checkable, const ApplyRule& rule, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches, bool skipFilter)
 {
+	bool match = false;
+	BenchmarkApplyRuleEvaluation bare (totalTimeSpentOnApplyMismatches, match);
+
 	auto& di (rule.GetDebugInfo());
 
 	std::ostringstream msgbuf;
@@ -85,8 +88,6 @@ bool Dependency::EvaluateApplyRule(const Checkable::Ptr& checkable, const ApplyR
 		frame.Locals = checkable->GetFrozenLocalsForApply();
 	}
 
-	bool match = false;
-
 	if (rule.GetFTerm()) {
 		Value vinstances;
 
@@ -135,32 +136,32 @@ bool Dependency::EvaluateApplyRule(const Checkable::Ptr& checkable, const ApplyR
 	return match;
 }
 
-void Dependency::EvaluateApplyRules(const Host::Ptr& host)
+void Dependency::EvaluateApplyRules(const Host::Ptr& host, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches)
 {
 	CONTEXT("Evaluating 'apply' rules for host '" + host->GetName() + "'");
 
 	for (auto& rule : ApplyRule::GetRules(Dependency::TypeInstance, Host::TypeInstance)) {
-		if (EvaluateApplyRule(host, *rule))
+		if (EvaluateApplyRule(host, *rule, totalTimeSpentOnApplyMismatches))
 			rule->AddMatch();
 	}
 
 	for (auto& rule : ApplyRule::GetTargetedHostRules(Dependency::TypeInstance, host->GetName())) {
-		if (EvaluateApplyRule(host, *rule, true))
+		if (EvaluateApplyRule(host, *rule, totalTimeSpentOnApplyMismatches, true))
 			rule->AddMatch();
 	}
 }
 
-void Dependency::EvaluateApplyRules(const Service::Ptr& service)
+void Dependency::EvaluateApplyRules(const Service::Ptr& service, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches)
 {
 	CONTEXT("Evaluating 'apply' rules for service '" + service->GetName() + "'");
 
 	for (auto& rule : ApplyRule::GetRules(Dependency::TypeInstance, Service::TypeInstance)) {
-		if (EvaluateApplyRule(service, *rule))
+		if (EvaluateApplyRule(service, *rule, totalTimeSpentOnApplyMismatches))
 			rule->AddMatch();
 	}
 
 	for (auto& rule : ApplyRule::GetTargetedServiceRules(Dependency::TypeInstance, service->GetHost()->GetName(), service->GetShortName())) {
-		if (EvaluateApplyRule(service, *rule, true))
+		if (EvaluateApplyRule(service, *rule, totalTimeSpentOnApplyMismatches, true))
 			rule->AddMatch();
 	}
 }

lib/icinga/dependency.hpp

@@ -34,8 +34,8 @@ public:
 
 	void ValidateStates(const Lazy<Array::Ptr>& lvalue, const ValidationUtils& utils) override;
 
-	static void EvaluateApplyRules(const intrusive_ptr<Host>& host);
+	static void EvaluateApplyRules(const intrusive_ptr<Host>& host, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches);
-	static void EvaluateApplyRules(const intrusive_ptr<Service>& service);
+	static void EvaluateApplyRules(const intrusive_ptr<Service>& service, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches);
 
 	/* Note: Only use them for unit test mocks. Prefer OnConfigLoaded(). */
 	void SetParent(intrusive_ptr<Checkable> parent);
@@ -51,7 +51,11 @@ private:
 	Checkable::Ptr m_Child;
 
 	static bool EvaluateApplyRuleInstance(const Checkable::Ptr& checkable, const String& name, ScriptFrame& frame, const ApplyRule& rule, bool skipFilter);
-	static bool EvaluateApplyRule(const Checkable::Ptr& checkable, const ApplyRule& rule, bool skipFilter = false);
+
+	static bool EvaluateApplyRule(
+		const Checkable::Ptr& checkable, const ApplyRule& rule,
+		TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches, bool skipFilter = false
+	);
 };
 
 }

lib/icinga/host.cpp

@@ -47,19 +47,19 @@ void Host::OnAllConfigLoaded()
 	}
 }
 
-void Host::CreateChildObjects(const Type::Ptr& childType)
+void Host::CreateChildObjects(const Type::Ptr& childType, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches)
 {
 	if (childType == ScheduledDowntime::TypeInstance)
-		ScheduledDowntime::EvaluateApplyRules(this);
+		ScheduledDowntime::EvaluateApplyRules(this, totalTimeSpentOnApplyMismatches);
 
 	if (childType == Notification::TypeInstance)
-		Notification::EvaluateApplyRules(this);
+		Notification::EvaluateApplyRules(this, totalTimeSpentOnApplyMismatches);
 
 	if (childType == Dependency::TypeInstance)
-		Dependency::EvaluateApplyRules(this);
+		Dependency::EvaluateApplyRules(this, totalTimeSpentOnApplyMismatches);
 
 	if (childType == Service::TypeInstance)
-		Service::EvaluateApplyRules(this);
+		Service::EvaluateApplyRules(this, totalTimeSpentOnApplyMismatches);
 }
 
 void Host::Stop(bool runtimeRemoved)

lib/icinga/host.hpp

@@ -55,7 +55,7 @@ public:
 protected:
 	void Stop(bool runtimeRemoved) override;
 
-	void CreateChildObjects(const Type::Ptr& childType) override;
+	void CreateChildObjects(const Type::Ptr& childType, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches) override;
 
 	Dictionary::Ptr MakeLocalsForApply() override;
 

lib/icinga/notification-apply.cpp

@@ -61,8 +61,14 @@ bool Notification::EvaluateApplyRuleInstance(const Checkable::Ptr& checkable, co
 	return true;
 }
 
-bool Notification::EvaluateApplyRule(const Checkable::Ptr& checkable, const ApplyRule& rule, bool skipFilter)
+bool Notification::EvaluateApplyRule(
+	const Checkable::Ptr& checkable, const ApplyRule& rule,
+	TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches, bool skipFilter
+)
 {
+	bool match = false;
+	BenchmarkApplyRuleEvaluation bare (totalTimeSpentOnApplyMismatches, match);
+
 	auto& di (rule.GetDebugInfo());
 
 	std::ostringstream msgbuf;
@@ -84,8 +90,6 @@ bool Notification::EvaluateApplyRule(const Checkable::Ptr& checkable, const Appl
 		frame.Locals = checkable->GetFrozenLocalsForApply();
 	}
 
-	bool match = false;
-
 	if (rule.GetFTerm()) {
 		Value vinstances;
 
@@ -134,33 +138,33 @@ bool Notification::EvaluateApplyRule(const Checkable::Ptr& checkable, const Appl
 	return match;
 }
 
-void Notification::EvaluateApplyRules(const Host::Ptr& host)
+void Notification::EvaluateApplyRules(const Host::Ptr& host, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches)
 {
 	CONTEXT("Evaluating 'apply' rules for host '" + host->GetName() + "'");
 
 	for (auto& rule : ApplyRule::GetRules(Notification::TypeInstance, Host::TypeInstance))
 	{
-		if (EvaluateApplyRule(host, *rule))
+		if (EvaluateApplyRule(host, *rule, totalTimeSpentOnApplyMismatches))
 			rule->AddMatch();
 	}
 
 	for (auto& rule : ApplyRule::GetTargetedHostRules(Notification::TypeInstance, host->GetName())) {
-		if (EvaluateApplyRule(host, *rule, true))
+		if (EvaluateApplyRule(host, *rule, totalTimeSpentOnApplyMismatches, true))
 			rule->AddMatch();
 	}
 }
 
-void Notification::EvaluateApplyRules(const Service::Ptr& service)
+void Notification::EvaluateApplyRules(const Service::Ptr& service, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches)
 {
 	CONTEXT("Evaluating 'apply' rules for service '" + service->GetName() + "'");
 
 	for (auto& rule : ApplyRule::GetRules(Notification::TypeInstance, Service::TypeInstance)) {
-		if (EvaluateApplyRule(service, *rule))
+		if (EvaluateApplyRule(service, *rule, totalTimeSpentOnApplyMismatches))
 			rule->AddMatch();
 	}
 
 	for (auto& rule : ApplyRule::GetTargetedServiceRules(Notification::TypeInstance, service->GetHost()->GetName(), service->GetShortName())) {
-		if (EvaluateApplyRule(service, *rule, true))
+		if (EvaluateApplyRule(service, *rule, totalTimeSpentOnApplyMismatches, true))
 			rule->AddMatch();
 	}
 }

lib/icinga/notification.hpp

@@ -99,8 +99,8 @@ public:
 	void ValidateTypes(const Lazy<Array::Ptr>& lvalue, const ValidationUtils& utils) override;
 	void ValidateTimes(const Lazy<Dictionary::Ptr>& lvalue, const ValidationUtils& utils) override;
 
-	static void EvaluateApplyRules(const intrusive_ptr<Host>& host);
+	static void EvaluateApplyRules(const intrusive_ptr<Host>& host, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches);
-	static void EvaluateApplyRules(const intrusive_ptr<Service>& service);
+	static void EvaluateApplyRules(const intrusive_ptr<Service>& service, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches);
 
 	static const std::map<String, int>& GetStateFilterMap();
 	static const std::map<String, int>& GetTypeFilterMap();
@@ -119,7 +119,11 @@ private:
 	void ExecuteNotificationHelper(NotificationType type, const User::Ptr& user, const CheckResult::Ptr& cr, bool force, const String& author = "", const String& text = "");
 
 	static bool EvaluateApplyRuleInstance(const intrusive_ptr<Checkable>& checkable, const String& name, ScriptFrame& frame, const ApplyRule& rule, bool skipFilter);
-	static bool EvaluateApplyRule(const intrusive_ptr<Checkable>& checkable, const ApplyRule& rule, bool skipFilter = false);
+
+	static bool EvaluateApplyRule(
+		const intrusive_ptr<Checkable>& checkable, const ApplyRule& rule,
+		TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches, bool skipFilter = false
+	);
 
 	static std::map<String, int> m_StateFilterMap;
 	static std::map<String, int> m_TypeFilterMap;

lib/icinga/scheduleddowntime-apply.cpp

@@ -60,8 +60,14 @@ bool ScheduledDowntime::EvaluateApplyRuleInstance(const Checkable::Ptr& checkabl
 	return true;
 }
 
-bool ScheduledDowntime::EvaluateApplyRule(const Checkable::Ptr& checkable, const ApplyRule& rule, bool skipFilter)
+bool ScheduledDowntime::EvaluateApplyRule(
+	const Checkable::Ptr& checkable, const ApplyRule& rule,
+	TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches, bool skipFilter
+)
 {
+	bool match = false;
+	BenchmarkApplyRuleEvaluation bare (totalTimeSpentOnApplyMismatches, match);
+
 	auto& di (rule.GetDebugInfo());
 
 	std::ostringstream msgbuf;
@@ -83,8 +89,6 @@ bool ScheduledDowntime::EvaluateApplyRule(const Checkable::Ptr& checkable, const
 		frame.Locals = checkable->GetFrozenLocalsForApply();
 	}
 
-	bool match = false;
-
 	if (rule.GetFTerm()) {
 		Value vinstances;
 
@@ -133,32 +137,32 @@ bool ScheduledDowntime::EvaluateApplyRule(const Checkable::Ptr& checkable, const
 	return match;
 }
 
-void ScheduledDowntime::EvaluateApplyRules(const Host::Ptr& host)
+void ScheduledDowntime::EvaluateApplyRules(const Host::Ptr& host, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches)
 {
 	CONTEXT("Evaluating 'apply' rules for host '" + host->GetName() + "'");
 
 	for (auto& rule : ApplyRule::GetRules(ScheduledDowntime::TypeInstance, Host::TypeInstance)) {
-		if (EvaluateApplyRule(host, *rule))
+		if (EvaluateApplyRule(host, *rule, totalTimeSpentOnApplyMismatches))
 			rule->AddMatch();
 	}
 
 	for (auto& rule : ApplyRule::GetTargetedHostRules(ScheduledDowntime::TypeInstance, host->GetName())) {
-		if (EvaluateApplyRule(host, *rule, true))
+		if (EvaluateApplyRule(host, *rule, totalTimeSpentOnApplyMismatches, true))
 			rule->AddMatch();
 	}
 }
 
-void ScheduledDowntime::EvaluateApplyRules(const Service::Ptr& service)
+void ScheduledDowntime::EvaluateApplyRules(const Service::Ptr& service, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches)
 {
 	CONTEXT("Evaluating 'apply' rules for service '" + service->GetName() + "'");
 
 	for (auto& rule : ApplyRule::GetRules(ScheduledDowntime::TypeInstance, Service::TypeInstance)) {
-		if (EvaluateApplyRule(service, *rule))
+		if (EvaluateApplyRule(service, *rule, totalTimeSpentOnApplyMismatches))
 			rule->AddMatch();
 	}
 
 	for (auto& rule : ApplyRule::GetTargetedServiceRules(ScheduledDowntime::TypeInstance, service->GetHost()->GetName(), service->GetShortName())) {
-		if (EvaluateApplyRule(service, *rule, true))
+		if (EvaluateApplyRule(service, *rule, totalTimeSpentOnApplyMismatches, true))
 			rule->AddMatch();
 	}
 }

lib/icinga/scheduleddowntime.hpp

@@ -29,8 +29,8 @@ public:
 
 	Checkable::Ptr GetCheckable() const;
 
-	static void EvaluateApplyRules(const intrusive_ptr<Host>& host);
+	static void EvaluateApplyRules(const intrusive_ptr<Host>& host, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches);
-	static void EvaluateApplyRules(const intrusive_ptr<Service>& service);
+	static void EvaluateApplyRules(const intrusive_ptr<Service>& service, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches);
 	static bool AllConfigIsLoaded();
 
 	void ValidateRanges(const Lazy<Dictionary::Ptr>& lvalue, const ValidationUtils& utils) override;
@@ -52,7 +52,11 @@ private:
 	static std::atomic<bool> m_AllConfigLoaded;
 
 	static bool EvaluateApplyRuleInstance(const Checkable::Ptr& checkable, const String& name, ScriptFrame& frame, const ApplyRule& rule, bool skipFilter);
-	static bool EvaluateApplyRule(const Checkable::Ptr& checkable, const ApplyRule& rule, bool skipFilter = false);
+
+	static bool EvaluateApplyRule(
+		const Checkable::Ptr& checkable, const ApplyRule& rule,
+		TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches, bool skipFilter = false
+	);
 };
 
 }

lib/icinga/service-apply.cpp

@@ -55,8 +55,14 @@ bool Service::EvaluateApplyRuleInstance(const Host::Ptr& host, const String& nam
 	return true;
 }
 
-bool Service::EvaluateApplyRule(const Host::Ptr& host, const ApplyRule& rule, bool skipFilter)
+bool Service::EvaluateApplyRule(
+	const Host::Ptr& host, const ApplyRule& rule,
+	TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches, bool skipFilter
+)
 {
+	bool match = false;
+	BenchmarkApplyRuleEvaluation bare (totalTimeSpentOnApplyMismatches, match);
+
 	auto& di (rule.GetDebugInfo());
 
 	std::ostringstream msgbuf;
@@ -78,8 +84,6 @@ bool Service::EvaluateApplyRule(const Host::Ptr& host, const ApplyRule& rule, bo
 		frame.Locals = host->GetFrozenLocalsForApply();
 	}
 
-	bool match = false;
-
 	if (rule.GetFTerm()) {
 		Value vinstances;
 
@@ -130,17 +134,17 @@ bool Service::EvaluateApplyRule(const Host::Ptr& host, const ApplyRule& rule, bo
 	return match;
 }
 
-void Service::EvaluateApplyRules(const Host::Ptr& host)
+void Service::EvaluateApplyRules(const Host::Ptr& host, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches)
 {
 	CONTEXT("Evaluating 'apply' rules for host '" + host->GetName() + "'");
 
 	for (auto& rule : ApplyRule::GetRules(Service::TypeInstance, Host::TypeInstance)) {
-		if (EvaluateApplyRule(host, *rule))
+		if (EvaluateApplyRule(host, *rule, totalTimeSpentOnApplyMismatches))
 			rule->AddMatch();
 	}
 
 	for (auto& rule : ApplyRule::GetTargetedHostRules(Service::TypeInstance, host->GetName())) {
-		if (EvaluateApplyRule(host, *rule, true))
+		if (EvaluateApplyRule(host, *rule, totalTimeSpentOnApplyMismatches, true))
 			rule->AddMatch();
 	}
 }

lib/icinga/service.cpp

@@ -74,16 +74,16 @@ void Service::OnAllConfigLoaded()
 	}
 }
 
-void Service::CreateChildObjects(const Type::Ptr& childType)
+void Service::CreateChildObjects(const Type::Ptr& childType, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches)
 {
 	if (childType == ScheduledDowntime::TypeInstance)
-		ScheduledDowntime::EvaluateApplyRules(this);
+		ScheduledDowntime::EvaluateApplyRules(this, totalTimeSpentOnApplyMismatches);
 
 	if (childType == Notification::TypeInstance)
-		Notification::EvaluateApplyRules(this);
+		Notification::EvaluateApplyRules(this, totalTimeSpentOnApplyMismatches);
 
 	if (childType == Dependency::TypeInstance)
-		Dependency::EvaluateApplyRules(this);
+		Dependency::EvaluateApplyRules(this, totalTimeSpentOnApplyMismatches);
 }
 
 Service::Ptr Service::GetByNamePair(const String& hostName, const String& serviceName)

lib/icinga/service.hpp

@@ -42,14 +42,14 @@ public:
 	static StateType StateTypeFromString(const String& state);
 	static String StateTypeToString(StateType state);
 
-	static void EvaluateApplyRules(const Host::Ptr& host);
+	static void EvaluateApplyRules(const Host::Ptr& host, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches);
 
 	void OnAllConfigLoaded() override;
 
 	static boost::signals2::signal<void (const Service::Ptr&, const CheckResult::Ptr&, const MessageOrigin::Ptr&)> OnHostProblemChanged;
 
 protected:
-	void CreateChildObjects(const Type::Ptr& childType) override;
+	void CreateChildObjects(const Type::Ptr& childType, TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches) override;
 
 	Dictionary::Ptr MakeLocalsForApply() override;
 
@@ -57,7 +57,11 @@ private:
 	Host::Ptr m_Host;
 
 	static bool EvaluateApplyRuleInstance(const Host::Ptr& host, const String& name, ScriptFrame& frame, const ApplyRule& rule, bool skipFilter);
-	static bool EvaluateApplyRule(const Host::Ptr& host, const ApplyRule& rule, bool skipFilter = false);
+
+	static bool EvaluateApplyRule(
+		const Host::Ptr& host, const ApplyRule& rule,
+		TotalTimeSpentOnApplyMismatches& totalTimeSpentOnApplyMismatches, bool skipFilter = false
+	);
 };
 
 std::pair<Host::Ptr, Service::Ptr> GetHostService(const Checkable::Ptr& checkable);