Skip to content

Commit

Permalink
Allowing Tags to be injected at the log site. While this is a very ra…
Browse files Browse the repository at this point in the history
…re use case, right now the logger will silently replace these with any injected tags, which is bad.

RELNOTES=Allowing Tags given at the log site to be merged with injected tags.
PiperOrigin-RevId: 398673817
  • Loading branch information
hagbard authored and Flogger Team committed Sep 24, 2021
1 parent 4f0ea71 commit 6e97e9e
Show file tree
Hide file tree
Showing 3 changed files with 69 additions and 29 deletions.
64 changes: 35 additions & 29 deletions api/src/main/java/com/google/common/flogger/LogContext.java
Original file line number Diff line number Diff line change
Expand Up @@ -145,28 +145,33 @@ public void emitRepeated(Iterator<Object> keys, KeyValueHandler out) {
MetadataKey.single("forced", Boolean.class);

/**
* The key associated with any injected metadata (in the form of a {@code Tags} instance.
* <p>
* If tags are injected, they are added after post-processing if the log site is enabled. Thus
* they are not available to the {@code postProcess()} method itself. The rationale is that a
* log statement's behavior should only be affected by code at the log site (other than
* The key associated with any injected {@link Tags}.
*
* <p>If tags are injected, they are added after post-processing if the log site is enabled.
* Thus they are not available to the {@code postProcess()} method itself. The rationale is that
* a log statement's behavior should only be affected by code at the log site (other than
* "forcing" log statements, which is slightly a special case).
*
* <p>Tags can be added at the log site, although this should rarely be necessary and using
* normal log message arguments is always the preferred way to indicate unstrctured log data.
* Users should never build new {@link Tags} instances just to pass them into a log statement.
*/
public static final MetadataKey<Tags> TAGS = new MetadataKey<Tags>("tags", Tags.class, false) {
@Override
public void emit(Tags tags, KeyValueHandler out) {
for (Map.Entry<String, ? extends Set<Object>> e : tags.asMap().entrySet()) {
Set<Object> values = e.getValue();
if (!values.isEmpty()) {
for (Object v : e.getValue()) {
out.handle(e.getKey(), v);
public static final MetadataKey<Tags> TAGS =
new MetadataKey<Tags>("tags", Tags.class, false) {
@Override
public void emit(Tags tags, KeyValueHandler out) {
for (Map.Entry<String, ? extends Set<Object>> e : tags.asMap().entrySet()) {
Set<Object> values = e.getValue();
if (!values.isEmpty()) {
for (Object v : e.getValue()) {
out.handle(e.getKey(), v);
}
} else {
out.handle(e.getKey(), null);
}
}
} else {
out.handle(e.getKey(), null);
}
}
}
};
};

/**
* Key associated with the metadata for specifying additional stack information with a log
Expand Down Expand Up @@ -588,17 +593,7 @@ private boolean shouldLog() {
logSiteKey = specializeLogSiteKeyFromMetadata(logSiteKey, metadata);
}
}
if (!postProcess(logSiteKey)) {
return false;
}
// Right at the end of post processing add any tags injected by the platform. Alternately this
// could be done in logImpl(), but it would have the same effect. This should be the last piece
// of metadata added to a LogData instance (but users are not allowed to rely on that).
Tags tags = Platform.getInjectedTags();
if (!tags.isEmpty()) {
addMetadata(Key.TAGS, tags);
}
return true;
return postProcess(logSiteKey);
}

// WARNING: If we ever start to use combined log-site and scoped context metadata here via
Expand Down Expand Up @@ -650,6 +645,17 @@ private void logImpl(String message, Object... args) {
if (message != LITERAL_VALUE_MESSAGE) {
this.templateContext = new TemplateContext(getMessageParser(), message);
}
// Right at the end of processing add any tags injected by the platform. Any tags supplied at
// the log site are merged with the injected tags (though this should be very rare).
Tags tags = Platform.getInjectedTags();
if (!tags.isEmpty()) {
Tags logSiteTags = getMetadata().findValue(Key.TAGS);
if (logSiteTags != null) {
tags = tags.merge(logSiteTags);
}
addMetadata(Key.TAGS, tags);
}
// Pass the completed log data to the backend (it should not be modified after this point).
getLogger().write(this);
}

Expand Down
15 changes: 15 additions & 0 deletions api/src/test/java/com/google/common/flogger/LogContextTest.java
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@
import com.google.common.collect.ImmutableList;
import com.google.common.collect.Iterators;
import com.google.common.flogger.LogContext.Key;
import com.google.common.flogger.context.Tags;
import com.google.common.flogger.testing.FakeLogSite;
import com.google.common.flogger.testing.FakeLoggerBackend;
import com.google.common.flogger.testing.FakeMetadata;
Expand Down Expand Up @@ -173,6 +174,20 @@ public void testMetadataKeys() {
backend.assertLogged(3).metadata().containsUniqueEntry(FLAG_KEY, true);
}

// For testing that log-site tags are correctly merged with metadata, see
// AbstractScopedLoggingContextTest.
@Test
public void testLoggedTags() {
FakeLoggerBackend backend = new FakeLoggerBackend();
FluentLogger logger = new FluentLogger(backend);

Tags tags = Tags.of("foo", "bar");
logger.atInfo().with(Key.TAGS, tags).log("With tags");

assertThat(backend.getLoggedCount()).isEqualTo(1);
backend.assertLogged(0).metadata().containsUniqueEntry(Key.TAGS, tags);
}

@Test
public void testAtMostEvery() {
FakeLoggerBackend backend = new FakeLoggerBackend();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@

package com.google.common.flogger.testing;

import static com.google.common.flogger.LogContext.Key.TAGS;
import static com.google.common.flogger.testing.MetadataSubject.assertThat;
import static com.google.common.truth.Truth.assertThat;
import static com.google.common.truth.Truth.assertWithMessage;
Expand All @@ -28,6 +29,7 @@
import com.google.common.flogger.context.LogLevelMap;
import com.google.common.flogger.context.ScopeType;
import com.google.common.flogger.context.ScopedLoggingContext;
import com.google.common.flogger.context.ScopedLoggingContexts;
import com.google.common.flogger.context.Tags;
import com.google.common.truth.BooleanSubject;
import java.util.Map;
Expand Down Expand Up @@ -99,6 +101,23 @@ public void testNewContext_withTags() {
checkDone();
}

// Note that general Metadata isn't merged automatically in the same way as Tags at the moment,
// so there's no equivalent test for it.
@Test
public void testLoggedTags_areMerged() {
FakeLoggerBackend backend = new FakeLoggerBackend();
TestLogger logger = TestLogger.create(backend);

ScopedLoggingContexts.newContext()
.withTags(Tags.of("foo", "baz"))
.run(() -> logger.atInfo().with(TAGS, Tags.of("foo", "bar")).log("With tags"));

// Tag values are ordered based on the values.
Tags merged = Tags.builder().addTag("foo", "bar").addTag("foo", "baz").build();
assertThat(backend.getLoggedCount()).isEqualTo(1);
backend.assertLogged(0).metadata().containsUniqueEntry(TAGS, merged);
}

@Test
public void testNewContext_withMetadata() {
assertThat(getMetadata()).hasSize(0);
Expand Down

0 comments on commit 6e97e9e

Please sign in to comment.