Merge pull request #7031 from Icinga/feature/metricwriters-logging

Improve logging for parsing metrics in features
This commit is contained in:
Michael Friedrich 2019-03-19 11:34:48 +01:00 committed by GitHub
commit 0649b6fd3b
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
10 changed files with 97 additions and 71 deletions

View File

@ -127,6 +127,8 @@ void ElasticsearchWriter::AddCheckResult(const Dictionary::Ptr& fields, const Ch
Array::Ptr perfdata = cr->GetPerformanceData();
CheckCommand::Ptr checkCommand = checkable->GetCheckCommand();
if (perfdata) {
ObjectLock olock(perfdata);
for (const Value& val : perfdata) {
@ -139,8 +141,9 @@ void ElasticsearchWriter::AddCheckResult(const Dictionary::Ptr& fields, const Ch
pdv = PerfdataValue::Parse(val);
} catch (const std::exception&) {
Log(LogWarning, "ElasticsearchWriter")
<< "Ignoring invalid perfdata value: '" << val << "' for object '"
<< checkable->GetName() << "'.";
<< "Ignoring invalid perfdata for checkable '"
<< checkable->GetName() << "' and command '"
<< checkCommand->GetName() << "' with value: " << val;
continue;
}
}
@ -224,7 +227,7 @@ void ElasticsearchWriter::InternalCheckResultHandler(const Checkable::Ptr& check
ts = cr->GetExecutionEnd();
}
Enqueue("checkresult", fields, ts);
Enqueue(checkable, "checkresult", fields, ts);
}
void ElasticsearchWriter::StateChangeHandler(const Checkable::Ptr& checkable, const CheckResult::Ptr& cr, StateType type)
@ -274,7 +277,7 @@ void ElasticsearchWriter::StateChangeHandlerInternal(const Checkable::Ptr& check
ts = cr->GetExecutionEnd();
}
Enqueue("statechange", fields, ts);
Enqueue(checkable, "statechange", fields, ts);
}
void ElasticsearchWriter::NotificationSentToAllUsersHandler(const Notification::Ptr& notification,
@ -343,10 +346,11 @@ void ElasticsearchWriter::NotificationSentToAllUsersHandlerInternal(const Notifi
ts = cr->GetExecutionEnd();
}
Enqueue("notification", fields, ts);
Enqueue(checkable, "notification", fields, ts);
}
void ElasticsearchWriter::Enqueue(const String& type, const Dictionary::Ptr& fields, double ts)
void ElasticsearchWriter::Enqueue(const Checkable::Ptr& checkable, const String& type,
const Dictionary::Ptr& fields, double ts)
{
/* Atomically buffer the data point. */
boost::mutex::scoped_lock lock(m_DataBufferMutex);
@ -365,7 +369,7 @@ void ElasticsearchWriter::Enqueue(const String& type, const Dictionary::Ptr& fie
String fieldsBody = JsonEncode(fields);
Log(LogDebug, "ElasticsearchWriter")
<< "Add to fields to message list: '" << fieldsBody << "'.";
<< "Checkable '" << checkable->GetName() << "' adds to metric list: '" << fieldsBody << "'.";
m_DataBuffer.emplace_back(indexBody + fieldsBody);

View File

@ -47,7 +47,8 @@ private:
const Checkable::Ptr& checkable, const std::set<User::Ptr>& users, NotificationType type,
const CheckResult::Ptr& cr, const String& author, const String& text);
void Enqueue(const String& type, const Dictionary::Ptr& fields, double ts);
void Enqueue(const Checkable::Ptr& checkable, const String& type,
const Dictionary::Ptr& fields, double ts);
Stream::Ptr Connect();
void AssertOnWorkQueue();

View File

@ -241,10 +241,10 @@ void GelfWriter::CheckResultHandlerInternal(const Checkable::Ptr& checkable, con
fields->Set("_reachable", checkable->IsReachable());
CheckCommand::Ptr commandObj = checkable->GetCheckCommand();
CheckCommand::Ptr checkCommand = checkable->GetCheckCommand();
if (commandObj)
fields->Set("_check_command", commandObj->GetName());
if (checkCommand)
fields->Set("_check_command", checkCommand->GetName());
double ts = Utility::GetTime();
@ -272,8 +272,9 @@ void GelfWriter::CheckResultHandlerInternal(const Checkable::Ptr& checkable, con
pdv = PerfdataValue::Parse(val);
} catch (const std::exception&) {
Log(LogWarning, "GelfWriter")
<< "Ignoring invalid perfdata value: '" << val << "' for object '"
<< checkable->GetName() << "'.";
<< "Ignoring invalid perfdata for checkable '"
<< checkable->GetName() << "' and command '"
<< checkCommand->GetName() << "' with value: " << val;
continue;
}
}
@ -301,7 +302,7 @@ void GelfWriter::CheckResultHandlerInternal(const Checkable::Ptr& checkable, con
}
}
SendLogMessage(ComposeGelfMessage(fields, GetSource(), ts));
SendLogMessage(checkable, ComposeGelfMessage(fields, GetSource(), ts));
}
void GelfWriter::NotificationToUserHandler(const Notification::Ptr& notification, const Checkable::Ptr& checkable,
@ -370,7 +371,7 @@ void GelfWriter::NotificationToUserHandlerInternal(const Notification::Ptr& noti
if (commandObj)
fields->Set("_check_command", commandObj->GetName());
SendLogMessage(ComposeGelfMessage(fields, GetSource(), ts));
SendLogMessage(checkable, ComposeGelfMessage(fields, GetSource(), ts));
}
void GelfWriter::StateChangeHandler(const Checkable::Ptr& checkable, const CheckResult::Ptr& cr, StateType type)
@ -426,7 +427,7 @@ void GelfWriter::StateChangeHandlerInternal(const Checkable::Ptr& checkable, con
ts = cr->GetExecutionEnd();
}
SendLogMessage(ComposeGelfMessage(fields, GetSource(), ts));
SendLogMessage(checkable, ComposeGelfMessage(fields, GetSource(), ts));
}
String GelfWriter::ComposeGelfMessage(const Dictionary::Ptr& fields, const String& source, double ts)
@ -438,7 +439,7 @@ String GelfWriter::ComposeGelfMessage(const Dictionary::Ptr& fields, const Strin
return JsonEncode(fields);
}
void GelfWriter::SendLogMessage(const String& gelfMessage)
void GelfWriter::SendLogMessage(const Checkable::Ptr& checkable, const String& gelfMessage)
{
std::ostringstream msgbuf;
msgbuf << gelfMessage;
@ -453,7 +454,7 @@ void GelfWriter::SendLogMessage(const String& gelfMessage)
try {
Log(LogDebug, "GelfWriter")
<< "Sending '" << log << "'.";
<< "Checkable '" << checkable->GetName() << "' sending message '" << log << "'.";
m_Stream->Write(log.CStr(), log.GetLength());
} catch (const std::exception& ex) {

View File

@ -50,7 +50,7 @@ private:
void StateChangeHandlerInternal(const Checkable::Ptr& checkable, const CheckResult::Ptr& cr, StateType type);
String ComposeGelfMessage(const Dictionary::Ptr& fields, const String& source, double ts);
void SendLogMessage(const String& gelfMessage);
void SendLogMessage(const Checkable::Ptr& checkable, const String& gelfMessage);
void ReconnectTimerHandler();

View File

@ -3,6 +3,7 @@
#include "perfdata/graphitewriter.hpp"
#include "perfdata/graphitewriter-ti.cpp"
#include "icinga/service.hpp"
#include "icinga/checkcommand.hpp"
#include "icinga/macroprocessor.hpp"
#include "icinga/icingaapplication.hpp"
#include "base/tcpsocket.hpp"
@ -243,31 +244,33 @@ void GraphiteWriter::CheckResultHandlerInternal(const Checkable::Ptr& checkable,
if (GetEnableSendMetadata()) {
if (service) {
SendMetric(prefixMetadata, "state", service->GetState(), ts);
SendMetric(checkable, prefixMetadata, "state", service->GetState(), ts);
} else {
SendMetric(prefixMetadata, "state", host->GetState(), ts);
SendMetric(checkable, prefixMetadata, "state", host->GetState(), ts);
}
SendMetric(prefixMetadata, "current_attempt", checkable->GetCheckAttempt(), ts);
SendMetric(prefixMetadata, "max_check_attempts", checkable->GetMaxCheckAttempts(), ts);
SendMetric(prefixMetadata, "state_type", checkable->GetStateType(), ts);
SendMetric(prefixMetadata, "reachable", checkable->IsReachable(), ts);
SendMetric(prefixMetadata, "downtime_depth", checkable->GetDowntimeDepth(), ts);
SendMetric(prefixMetadata, "acknowledgement", checkable->GetAcknowledgement(), ts);
SendMetric(prefixMetadata, "latency", cr->CalculateLatency(), ts);
SendMetric(prefixMetadata, "execution_time", cr->CalculateExecutionTime(), ts);
SendMetric(checkable, prefixMetadata, "current_attempt", checkable->GetCheckAttempt(), ts);
SendMetric(checkable, prefixMetadata, "max_check_attempts", checkable->GetMaxCheckAttempts(), ts);
SendMetric(checkable, prefixMetadata, "state_type", checkable->GetStateType(), ts);
SendMetric(checkable, prefixMetadata, "reachable", checkable->IsReachable(), ts);
SendMetric(checkable, prefixMetadata, "downtime_depth", checkable->GetDowntimeDepth(), ts);
SendMetric(checkable, prefixMetadata, "acknowledgement", checkable->GetAcknowledgement(), ts);
SendMetric(checkable, prefixMetadata, "latency", cr->CalculateLatency(), ts);
SendMetric(checkable, prefixMetadata, "execution_time", cr->CalculateExecutionTime(), ts);
}
SendPerfdata(prefixPerfdata, cr, ts);
SendPerfdata(checkable, prefixPerfdata, cr, ts);
}
void GraphiteWriter::SendPerfdata(const String& prefix, const CheckResult::Ptr& cr, double ts)
void GraphiteWriter::SendPerfdata(const Checkable::Ptr& checkable, const String& prefix, const CheckResult::Ptr& cr, double ts)
{
Array::Ptr perfdata = cr->GetPerformanceData();
if (!perfdata)
return;
CheckCommand::Ptr checkCommand = checkable->GetCheckCommand();
ObjectLock olock(perfdata);
for (const Value& val : perfdata) {
PerfdataValue::Ptr pdv;
@ -279,35 +282,37 @@ void GraphiteWriter::SendPerfdata(const String& prefix, const CheckResult::Ptr&
pdv = PerfdataValue::Parse(val);
} catch (const std::exception&) {
Log(LogWarning, "GraphiteWriter")
<< "Ignoring invalid perfdata value: " << val;
<< "Ignoring invalid perfdata for checkable '"
<< checkable->GetName() << "' and command '"
<< checkCommand->GetName() << "' with value: " << val;
continue;
}
}
String escapedKey = EscapeMetricLabel(pdv->GetLabel());
SendMetric(prefix, escapedKey + ".value", pdv->GetValue(), ts);
SendMetric(checkable, prefix, escapedKey + ".value", pdv->GetValue(), ts);
if (GetEnableSendThresholds()) {
if (pdv->GetCrit())
SendMetric(prefix, escapedKey + ".crit", pdv->GetCrit(), ts);
SendMetric(checkable, prefix, escapedKey + ".crit", pdv->GetCrit(), ts);
if (pdv->GetWarn())
SendMetric(prefix, escapedKey + ".warn", pdv->GetWarn(), ts);
SendMetric(checkable, prefix, escapedKey + ".warn", pdv->GetWarn(), ts);
if (pdv->GetMin())
SendMetric(prefix, escapedKey + ".min", pdv->GetMin(), ts);
SendMetric(checkable, prefix, escapedKey + ".min", pdv->GetMin(), ts);
if (pdv->GetMax())
SendMetric(prefix, escapedKey + ".max", pdv->GetMax(), ts);
SendMetric(checkable, prefix, escapedKey + ".max", pdv->GetMax(), ts);
}
}
}
void GraphiteWriter::SendMetric(const String& prefix, const String& name, double value, double ts)
void GraphiteWriter::SendMetric(const Checkable::Ptr& checkable, const String& prefix, const String& name, double value, double ts)
{
std::ostringstream msgbuf;
msgbuf << prefix << "." << name << " " << Convert::ToString(value) << " " << static_cast<long>(ts);
Log(LogDebug, "GraphiteWriter")
<< "Add to metric list: '" << msgbuf.str() << "'.";
<< "Checkable '" << checkable->GetName() << "' adds to metric list: '" << msgbuf.str() << "'.";
// do not send \n to debug log
msgbuf << "\n";

View File

@ -45,8 +45,8 @@ private:
void CheckResultHandler(const Checkable::Ptr& checkable, const CheckResult::Ptr& cr);
void CheckResultHandlerInternal(const Checkable::Ptr& checkable, const CheckResult::Ptr& cr);
void SendMetric(const String& prefix, const String& name, double value, double ts);
void SendPerfdata(const String& prefix, const CheckResult::Ptr& cr, double ts);
void SendMetric(const Checkable::Ptr& checkable, const String& prefix, const String& name, double value, double ts);
void SendPerfdata(const Checkable::Ptr& checkable, const String& prefix, const CheckResult::Ptr& cr, double ts);
static String EscapeMetric(const String& str);
static String EscapeMetricLabel(const String& str);
static Value EscapeMacroMetric(const Value& value);

View File

@ -246,7 +246,10 @@ void InfluxdbWriter::CheckResultHandlerWQ(const Checkable::Ptr& checkable, const
}
}
CheckCommand::Ptr checkCommand = checkable->GetCheckCommand();
Array::Ptr perfdata = cr->GetPerformanceData();
if (perfdata) {
ObjectLock olock(perfdata);
for (const Value& val : perfdata) {
@ -259,7 +262,9 @@ void InfluxdbWriter::CheckResultHandlerWQ(const Checkable::Ptr& checkable, const
pdv = PerfdataValue::Parse(val);
} catch (const std::exception&) {
Log(LogWarning, "InfluxdbWriter")
<< "Ignoring invalid perfdata value: " << val;
<< "Ignoring invalid perfdata for checkable '"
<< checkable->GetName() << "' and command '"
<< checkCommand->GetName() << "' with value: " << val;
continue;
}
}
@ -281,7 +286,7 @@ void InfluxdbWriter::CheckResultHandlerWQ(const Checkable::Ptr& checkable, const
fields->Set("unit", pdv->GetUnit());
}
SendMetric(tmpl, pdv->GetLabel(), fields, ts);
SendMetric(checkable, tmpl, pdv->GetLabel(), fields, ts);
}
}
@ -306,7 +311,7 @@ void InfluxdbWriter::CheckResultHandlerWQ(const Checkable::Ptr& checkable, const
fields->Set("latency", cr->CalculateLatency());
fields->Set("execution_time", cr->CalculateExecutionTime());
SendMetric(tmpl, Empty, fields, ts);
SendMetric(checkable, tmpl, Empty, fields, ts);
}
}
@ -349,7 +354,8 @@ String InfluxdbWriter::EscapeValue(const Value& value)
return value;
}
void InfluxdbWriter::SendMetric(const Dictionary::Ptr& tmpl, const String& label, const Dictionary::Ptr& fields, double ts)
void InfluxdbWriter::SendMetric(const Checkable::Ptr& checkable, const Dictionary::Ptr& tmpl,
const String& label, const Dictionary::Ptr& fields, double ts)
{
std::ostringstream msgbuf;
msgbuf << EscapeKeyOrTagValue(tmpl->Get("measurement"));
@ -387,10 +393,8 @@ void InfluxdbWriter::SendMetric(const Dictionary::Ptr& tmpl, const String& label
msgbuf << " " << static_cast<unsigned long>(ts);
#ifdef I2_DEBUG
Log(LogDebug, "InfluxdbWriter")
<< "Add to metric list: '" << msgbuf.str() << "'.";
#endif /* I2_DEBUG */
<< "Checkable '" << checkable->GetName() << "' adds to metric list:'" << msgbuf.str() << "'.";
// Buffer the data point
m_DataBuffer.emplace_back(msgbuf.str());

View File

@ -42,7 +42,8 @@ private:
void CheckResultHandler(const Checkable::Ptr& checkable, const CheckResult::Ptr& cr);
void CheckResultHandlerWQ(const Checkable::Ptr& checkable, const CheckResult::Ptr& cr);
void SendMetric(const Dictionary::Ptr& tmpl, const String& label, const Dictionary::Ptr& fields, double ts);
void SendMetric(const Checkable::Ptr& checkable, const Dictionary::Ptr& tmpl,
const String& label, const Dictionary::Ptr& fields, double ts);
void FlushTimeout();
void FlushTimeoutWQ();
void Flush();

View File

@ -3,6 +3,7 @@
#include "perfdata/opentsdbwriter.hpp"
#include "perfdata/opentsdbwriter-ti.cpp"
#include "icinga/service.hpp"
#include "icinga/checkcommand.hpp"
#include "icinga/macroprocessor.hpp"
#include "icinga/icingaapplication.hpp"
#include "icinga/compatutility.hpp"
@ -134,18 +135,18 @@ void OpenTsdbWriter::CheckResultHandler(const Checkable::Ptr& checkable, const C
String escaped_serviceName = EscapeMetric(serviceName);
metric = "icinga.service." + escaped_serviceName;
SendMetric(metric + ".state", tags, service->GetState(), ts);
SendMetric(checkable, metric + ".state", tags, service->GetState(), ts);
} else {
metric = "icinga.host";
SendMetric(metric + ".state", tags, host->GetState(), ts);
SendMetric(checkable, metric + ".state", tags, host->GetState(), ts);
}
SendMetric(metric + ".state_type", tags, checkable->GetStateType(), ts);
SendMetric(metric + ".reachable", tags, checkable->IsReachable(), ts);
SendMetric(metric + ".downtime_depth", tags, checkable->GetDowntimeDepth(), ts);
SendMetric(metric + ".acknowledgement", tags, checkable->GetAcknowledgement(), ts);
SendMetric(checkable, metric + ".state_type", tags, checkable->GetStateType(), ts);
SendMetric(checkable, metric + ".reachable", tags, checkable->IsReachable(), ts);
SendMetric(checkable, metric + ".downtime_depth", tags, checkable->GetDowntimeDepth(), ts);
SendMetric(checkable, metric + ".acknowledgement", tags, checkable->GetAcknowledgement(), ts);
SendPerfdata(metric, tags, cr, ts);
SendPerfdata(checkable, metric, tags, cr, ts);
metric = "icinga.check";
@ -158,19 +159,22 @@ void OpenTsdbWriter::CheckResultHandler(const Checkable::Ptr& checkable, const C
tags["type"] = "host";
}
SendMetric(metric + ".current_attempt", tags, checkable->GetCheckAttempt(), ts);
SendMetric(metric + ".max_check_attempts", tags, checkable->GetMaxCheckAttempts(), ts);
SendMetric(metric + ".latency", tags, cr->CalculateLatency(), ts);
SendMetric(metric + ".execution_time", tags, cr->CalculateExecutionTime(), ts);
SendMetric(checkable, metric + ".current_attempt", tags, checkable->GetCheckAttempt(), ts);
SendMetric(checkable, metric + ".max_check_attempts", tags, checkable->GetMaxCheckAttempts(), ts);
SendMetric(checkable, metric + ".latency", tags, cr->CalculateLatency(), ts);
SendMetric(checkable, metric + ".execution_time", tags, cr->CalculateExecutionTime(), ts);
}
void OpenTsdbWriter::SendPerfdata(const String& metric, const std::map<String, String>& tags, const CheckResult::Ptr& cr, double ts)
void OpenTsdbWriter::SendPerfdata(const Checkable::Ptr& checkable, const String& metric,
const std::map<String, String>& tags, const CheckResult::Ptr& cr, double ts)
{
Array::Ptr perfdata = cr->GetPerformanceData();
if (!perfdata)
return;
CheckCommand::Ptr checkCommand = checkable->GetCheckCommand();
ObjectLock olock(perfdata);
for (const Value& val : perfdata) {
PerfdataValue::Ptr pdv;
@ -182,7 +186,9 @@ void OpenTsdbWriter::SendPerfdata(const String& metric, const std::map<String, S
pdv = PerfdataValue::Parse(val);
} catch (const std::exception&) {
Log(LogWarning, "OpenTsdbWriter")
<< "Ignoring invalid perfdata value: " << val;
<< "Ignoring invalid perfdata for checkable '"
<< checkable->GetName() << "' and command '"
<< checkCommand->GetName() << "' with value: " << val;
continue;
}
}
@ -190,22 +196,24 @@ void OpenTsdbWriter::SendPerfdata(const String& metric, const std::map<String, S
String escaped_key = EscapeMetric(pdv->GetLabel());
boost::algorithm::replace_all(escaped_key, "::", ".");
SendMetric(metric + "." + escaped_key, tags, pdv->GetValue(), ts);
SendMetric(checkable, metric + "." + escaped_key, tags, pdv->GetValue(), ts);
if (pdv->GetCrit())
SendMetric(metric + "." + escaped_key + "_crit", tags, pdv->GetCrit(), ts);
SendMetric(checkable, metric + "." + escaped_key + "_crit", tags, pdv->GetCrit(), ts);
if (pdv->GetWarn())
SendMetric(metric + "." + escaped_key + "_warn", tags, pdv->GetWarn(), ts);
SendMetric(checkable, metric + "." + escaped_key + "_warn", tags, pdv->GetWarn(), ts);
if (pdv->GetMin())
SendMetric(metric + "." + escaped_key + "_min", tags, pdv->GetMin(), ts);
SendMetric(checkable, metric + "." + escaped_key + "_min", tags, pdv->GetMin(), ts);
if (pdv->GetMax())
SendMetric(metric + "." + escaped_key + "_max", tags, pdv->GetMax(), ts);
SendMetric(checkable, metric + "." + escaped_key + "_max", tags, pdv->GetMax(), ts);
}
}
void OpenTsdbWriter::SendMetric(const String& metric, const std::map<String, String>& tags, double value, double ts)
void OpenTsdbWriter::SendMetric(const Checkable::Ptr& checkable, const String& metric,
const std::map<String, String>& tags, double value, double ts)
{
String tags_string = "";
for (const Dictionary::Pair& tag : tags) {
tags_string += " " + tag.first + "=" + Convert::ToString(tag.second);
}
@ -219,7 +227,7 @@ void OpenTsdbWriter::SendMetric(const String& metric, const std::map<String, Str
msgbuf << "put " << metric << " " << static_cast<long>(ts) << " " << Convert::ToString(value) << " " << tags_string;
Log(LogDebug, "OpenTsdbWriter")
<< "Add to metric list:'" << msgbuf.str() << "'.";
<< "Checkable '" << checkable->GetName() << "' adds to metric list: '" << msgbuf.str() << "'.";
/* do not send \n to debug log */
msgbuf << "\n";

View File

@ -37,8 +37,10 @@ private:
Timer::Ptr m_ReconnectTimer;
void CheckResultHandler(const Checkable::Ptr& checkable, const CheckResult::Ptr& cr);
void SendMetric(const String& metric, const std::map<String, String>& tags, double value, double ts);
void SendPerfdata(const String& metric, const std::map<String, String>& tags, const CheckResult::Ptr& cr, double ts);
void SendMetric(const Checkable::Ptr& checkable, const String& metric,
const std::map<String, String>& tags, double value, double ts);
void SendPerfdata(const Checkable::Ptr& checkable, const String& metric,
const std::map<String, String>& tags, const CheckResult::Ptr& cr, double ts);
static String EscapeTag(const String& str);
static String EscapeMetric(const String& str);