wbtiger
/
foundationdb
mirror of https://github.com/apple/foundationdb.git
1
0
Fork 0
Code Issues Packages Projects Releases Wiki Activity

log the base trace event before the endpoint messages

This commit is contained in:
Evan Tschannen 2020-01-03 12:15:38 -08:00
parent 6e473c3a83
commit 7152469cc3
3 changed files with 42 additions and 31 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

3
fdbrpc/LoadBalance.actor.h
View File

@ -287,9 +287,10 @@ Future< REPLY_TYPE(Request) > loadBalance(
ev.detail("Backoff", backoff);
ev.detail("TriedAllOptions", triedAllOptions);
if(ev.isEnabled()) {
ev.log();
for(int alternativeNum=0; alternativeNum<alternatives->size(); alternativeNum++) {
RequestStream<Request> const* thisStream = &alternatives->get( alternativeNum, channel );
TraceEvent(g_network->isSimulated() ? SevWarn : SevWarnAlways, "LoadBalanceTooLongEndpoint").detail("Addr", thisStream->getEndpoint().getPrimaryAddress()).detail("Token", thisStream->getEndpoint().token).detail("Failed", IFailureMonitor::failureMonitor().getState( thisStream->getEndpoint() ).failed);
TraceEvent(SevWarn, "LoadBalanceTooLongEndpoint").detail("Addr", thisStream->getEndpoint().getPrimaryAddress()).detail("Token", thisStream->getEndpoint().token).detail("Failed", IFailureMonitor::failureMonitor().getState( thisStream->getEndpoint() ).failed);
}
}
}

67
flow/Trace.cpp
View File

@ -653,13 +653,13 @@ void removeTraceRole(std::string role) {
g_traceLog.removeRole(role);
}
TraceEvent::TraceEvent( const char* type, UID id ) : id(id), type(type), severity(SevInfo), initialized(false), enabled(true) {
TraceEvent::TraceEvent( const char* type, UID id ) : id(id), type(type), severity(SevInfo), initialized(false), enabled(true), logged(false) {
g_trace_depth++;
setMaxFieldLength(0);
setMaxEventLength(0);
}
TraceEvent::TraceEvent( Severity severity, const char* type, UID id )
: id(id), type(type), severity(severity), initialized(false),
: id(id), type(type), severity(severity), initialized(false), logged(false),
enabled(g_network == nullptr || FLOW_KNOBS->MIN_TRACE_SEVERITY <= severity) {
g_trace_depth++;
setMaxFieldLength(0);
@ -668,7 +668,7 @@ TraceEvent::TraceEvent( Severity severity, const char* type, UID id )
TraceEvent::TraceEvent( TraceInterval& interval, UID id )
: id(id), type(interval.type),
severity(interval.severity),
initialized(false),
initialized(false), logged(false),
enabled(g_network == nullptr || FLOW_KNOBS->MIN_TRACE_SEVERITY <= interval.severity) {
g_trace_depth++;
@ -680,7 +680,7 @@ TraceEvent::TraceEvent( TraceInterval& interval, UID id )
TraceEvent::TraceEvent( Severity severity, TraceInterval& interval, UID id )
: id(id), type(interval.type),
severity(severity),
initialized(false),
initialized(false), logged(false),
enabled(g_network == nullptr || FLOW_KNOBS->MIN_TRACE_SEVERITY <= severity) {
g_trace_depth++;
@ -938,40 +938,47 @@ TraceEvent& TraceEvent::backtrace(const std::string& prefix) {
return detail(prefix + "Backtrace", platform::get_backtrace());
}
TraceEvent::~TraceEvent() {
init();
try {
if (enabled) {
if (this->severity == SevError) {
severity = SevInfo;
backtrace();
severity = SevError;
}
void TraceEvent::log() {
if(!logged) {
logged = true;
init();
try {
if (enabled) {
if (this->severity == SevError) {
severity = SevInfo;
backtrace();
severity = SevError;
}
if(isNetworkThread()) {
TraceEvent::eventCounts[severity/10]++;
}
if(isNetworkThread()) {
TraceEvent::eventCounts[severity/10]++;
}
g_traceLog.writeEvent( fields, trackingKey, severity > SevWarnAlways );
g_traceLog.writeEvent( fields, trackingKey, severity > SevWarnAlways );
if (g_traceLog.isOpen()) {
// Log Metrics
if(g_traceLog.logTraceEventMetrics && isNetworkThread()) {
// Get the persistent Event Metric representing this trace event and push the fields (details) accumulated in *this to it and then log() it.
// Note that if the event metric is disabled it won't actually be logged BUT any new fields added to it will be registered.
// If the event IS logged, a timestamp will be returned, if not then 0. Either way, pass it through to be used if possible
// in the Sev* event metrics.
if (g_traceLog.isOpen()) {
// Log Metrics
if(g_traceLog.logTraceEventMetrics && isNetworkThread()) {
// Get the persistent Event Metric representing this trace event and push the fields (details) accumulated in *this to it and then log() it.
// Note that if the event metric is disabled it won't actually be logged BUT any new fields added to it will be registered.
// If the event IS logged, a timestamp will be returned, if not then 0. Either way, pass it through to be used if possible
// in the Sev* event metrics.
uint64_t event_ts = DynamicEventMetric::getOrCreateInstance(format("TraceEvent.%s", type), StringRef(), true)->setFieldsAndLogFrom(tmpEventMetric);
g_traceLog.log(severity, type, id, event_ts);
uint64_t event_ts = DynamicEventMetric::getOrCreateInstance(format("TraceEvent.%s", type), StringRef(), true)->setFieldsAndLogFrom(tmpEventMetric);
g_traceLog.log(severity, type, id, event_ts);
}
}
}
} catch( Error &e ) {
TraceEvent(SevError, "TraceEventDestructorError").error(e,true);
}
} catch( Error &e ) {
TraceEvent(SevError, "TraceEventDestructorError").error(e,true);
delete tmpEventMetric;
g_trace_depth--;
}
delete tmpEventMetric;
g_trace_depth--;
}
TraceEvent::~TraceEvent() {
log();
}
thread_local bool TraceEvent::networkThread = false;

3
flow/Trace.h
View File

@ -464,6 +464,8 @@ public:
return enabled;
}
void log();
~TraceEvent(); // Actually logs the event
// Return the number of invocations of TraceEvent() at the specified logging level.
@ -474,6 +476,7 @@ public:
private:
bool initialized;
bool enabled;
bool logged;
std::string trackingKey;
TraceEventFields fields;
Severity severity;