Skip to content

Commit

Permalink
[AMLII-1817] Added support for emitting logs with thread name (#525)
Browse files Browse the repository at this point in the history 
* Added support for emitting logs with thread name
* Making thread name in logs the default, can be disabled via system property
  • Loading branch information
@carlosroman
carlosroman authored Jun 7, 2024
1 parent d62420b commit 89e8328
Show file tree
Hide file tree
Showing 4 changed files with 127 additions and 89 deletions.
2 changes: 1 addition & 1 deletion CHANGELOG.md
View file
Original file line number Diff line number Diff line change
@@ -1,6 +1,7 @@
Changelog
=========
# 0.49.2-SNAPSHOT / TBC
* [FEATURE] Added support for emitting logs with thread name [#525][]
* [BUGFIX] Telemetry is no longer initialized when telemetry is disabled [#522][]

# 0.49.1 / 2024-04-09
Expand Down Expand Up @@ -768,7 +769,6 @@ Changelog
[#477]: https://github.com/DataDog/jmxfetch/issues/477
[#509]: https://github.com/DataDog/jmxfetch/issues/509
[#512]: https://github.com/DataDog/jmxfetch/pull/512
[#522]: https://github.com/DataDog/jmxfetch/pull/522
[@alz]: https://github.com/alz
[@aoking]: https://github.com/aoking
[@arrawatia]: https://github.com/arrawatia
Expand Down
4 changes: 2 additions & 2 deletions src/main/java/org/datadog/jmxfetch/JmxFetch.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -46,8 +46,8 @@ public static void main(String[] args) {

// Set up the logger to add file handler
CustomLogger.setup(LogLevel.fromString(config.getLogLevel()),
config.getLogLocation(),
config.isLogFormatRfc3339());
config.getLogLocation(),
config.isLogFormatRfc3339());

// Set up the shutdown hook to properly close resources
attachShutdownHook();
Expand Down
173 changes: 101 additions & 72 deletions src/main/java/org/datadog/jmxfetch/util/CustomLogger.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -2,22 +2,17 @@

import lombok.extern.slf4j.Slf4j;

import org.datadog.jmxfetch.util.LogLevel;
import org.datadog.jmxfetch.util.StdoutConsoleHandler;

import java.io.PrintWriter;
import java.io.StringWriter;
import java.text.SimpleDateFormat;
import java.util.Arrays;
import java.util.Date;
import java.util.Enumeration;
import java.util.List;
import java.util.Locale;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.logging.ConsoleHandler;
import java.util.logging.FileHandler;
import java.util.logging.Filter;
import java.util.logging.Handler;
import java.util.logging.Level;
import java.util.logging.LogManager;
Expand All @@ -41,14 +36,24 @@ public class CustomLogger {
private static boolean millisecondLogging =
System.getProperty("jmxfetch.millisecondLogging", "false").equals("true");

// Enable by setting -Djmxfetch.disableThreadLogging,
// if true, log record will not include thread name
private static final boolean disableThreadLogging =
System.getProperty("jmxfetch.disableThreadLogging", "false").equals("true");

private static final ConcurrentHashMap<String, AtomicInteger> messageCount
= new ConcurrentHashMap<String, AtomicInteger>();

private static final String DATE_JDK14_LAYOUT = "yyyy-MM-dd HH:mm:ss z";
private static final String DATE_JDK14_LAYOUT_RFC3339 = "yyyy-MM-dd'T'HH:mm:ssXXX";
private static final String JDK14_LAYOUT = "%s | JMX | %2$s | %3$s | %4$s%5$s%n";
private static final String JDK14_LAYOUT =
"%s | JMX | %2$s | %3$s | %4$s%5$s%n";
private static final String JDK14_WITH_THREADS_LAYOUT =
"%s | JMX | %2$s | %3$s | %4$s | %5$s%6$s%n";
private static final String JDK14_LAYOUT_FILE_LINE =
"%s | JMX | %2$s | %3$s:%4$d | %5$s%6$s%n";
"%s | JMX | %2$s | %3$s:%4$d | %5$s%6$s%n";
private static final String JDK14_WITH_THREADS_LAYOUT_FILE_LINE =
"%s | JMX | %2$s | %3$s | %4$s:%5$d | %6$s%7$s%n";

private static final int MAX_FILE_SIZE = 5 * 1024 * 1024;

Expand All @@ -67,66 +72,7 @@ private static boolean isStdOut(String target) {
/** setup and configure the logging. */
public static synchronized void setup(LogLevel level, String logLocation,
boolean logFormatRfc3339) {
String target = "CONSOLE";
String dateFormat = logFormatRfc3339 ? DATE_JDK14_LAYOUT_RFC3339 : DATE_JDK14_LAYOUT;
if (millisecondLogging) {
dateFormat = dateFormat.replace("ss", "ss.SSS");
}
final SimpleDateFormat dateFormatter = new SimpleDateFormat(dateFormat,
Locale.getDefault());

// log format
SimpleFormatter formatter = new SimpleFormatter() {
private static final String format = JDK14_LAYOUT;

private String simpleClassName(String str) {
int start = str.lastIndexOf('.');
int end = str.indexOf('$');
if (start == -1 || start + 1 == str.length()) {
return str;
}
if (end == -1 || end <= start || end > str.length()) {
end = str.length();
}
return str.substring(start + 1, end);
}

@Override
public synchronized String format(LogRecord lr) {
String exception = "";
if (lr.getThrown() != null) {
StringWriter writer = new StringWriter();
PrintWriter stream = new PrintWriter(writer);
stream.println();
lr.getThrown().printStackTrace(stream);
stream.close();
exception = writer.toString();
}

if (enableFileLineLogging) {
Throwable throwable = new Throwable();
StackTraceElement logEmissionFrame = throwable.getStackTrace()[6];

return String.format(JDK14_LAYOUT_FILE_LINE,
dateFormatter.format(new Date()).toString(),
LogLevel.fromJulLevel(lr.getLevel()).toString(),
logEmissionFrame.getFileName(),
logEmissionFrame.getLineNumber(),
lr.getMessage(),
exception
);

}

return String.format(format,
dateFormatter.format(new Date()).toString(),
LogLevel.fromJulLevel(lr.getLevel()).toString(),
simpleClassName(lr.getSourceClassName()),
lr.getMessage(),
exception
);
}
};
SimpleFormatter formatter = getFormatter(logFormatRfc3339);

// log level
Level julLevel = level.toJulLevel();
Expand All @@ -138,14 +84,14 @@ public synchronized String format(LogRecord lr) {
manager.reset();

// prepare the different handlers
ConsoleHandler stdoutHandler = null;
ConsoleHandler stdoutHandler;
ConsoleHandler stderrHandler = null;
FileHandler fileHandler = null;

// the logLocation isn't always containing a file, it is sometimes
// referring to a standard output. We want to create a FileHandler only
// if the logLocation is a file on the FS.
if (logLocation != null && logLocation.length() > 0) {
if (logLocation != null && !logLocation.isEmpty()) {
if (!isStdOut(logLocation) && !isStdErr(logLocation)) {
// file logging
try {
Expand Down Expand Up @@ -178,14 +124,97 @@ public synchronized String format(LogRecord lr) {
if (fileHandler != null) {
jmxfetchLogger.addHandler(fileHandler);
}
if (stdoutHandler != null) { // always non-null but doesn't cost much
jmxfetchLogger.addHandler(stdoutHandler);
}

jmxfetchLogger.addHandler(stdoutHandler);

if (stderrHandler != null) {
jmxfetchLogger.addHandler(stderrHandler);
}
}

private static SimpleFormatter getFormatter(
final boolean logFormatRfc3339) {
String dateFormat = logFormatRfc3339 ? DATE_JDK14_LAYOUT_RFC3339 : DATE_JDK14_LAYOUT;
if (millisecondLogging) {
dateFormat = dateFormat.replace("ss", "ss.SSS");
}
final SimpleDateFormat dateFormatter = new SimpleDateFormat(dateFormat,
Locale.getDefault());

// log format
return new SimpleFormatter() {

private String simpleClassName(String str) {
int start = str.lastIndexOf('.');
int end = str.indexOf('$');
if (start == -1 || start + 1 == str.length()) {
return str;
}
if (end == -1 || end <= start) {
end = str.length();
}
return str.substring(start + 1, end);
}

@Override
public synchronized String format(LogRecord lr) {
String exception = "";
if (lr.getThrown() != null) {
StringWriter writer = new StringWriter();
PrintWriter stream = new PrintWriter(writer);
stream.println();
lr.getThrown().printStackTrace(stream);
stream.close();
exception = writer.toString();
}

if (enableFileLineLogging) {
Throwable throwable = new Throwable();
StackTraceElement logEmissionFrame = throwable.getStackTrace()[6];

if (!disableThreadLogging) {
return String.format(JDK14_WITH_THREADS_LAYOUT_FILE_LINE,
dateFormatter.format(new Date()),
LogLevel.fromJulLevel(lr.getLevel()).toString(),
Thread.currentThread().getName(),
logEmissionFrame.getFileName(),
logEmissionFrame.getLineNumber(),
lr.getMessage(),
exception
);
}

return String.format(JDK14_LAYOUT_FILE_LINE,
dateFormatter.format(new Date()),
LogLevel.fromJulLevel(lr.getLevel()).toString(),
logEmissionFrame.getFileName(),
logEmissionFrame.getLineNumber(),
lr.getMessage(),
exception
);
}

if (!disableThreadLogging) {
return String.format(JDK14_WITH_THREADS_LAYOUT,
dateFormatter.format(new Date()),
LogLevel.fromJulLevel(lr.getLevel()).toString(),
Thread.currentThread().getName(),
simpleClassName(lr.getSourceClassName()),
lr.getMessage(),
exception
);
}
return String.format(JDK14_LAYOUT,
dateFormatter.format(new Date()),
LogLevel.fromJulLevel(lr.getLevel()).toString(),
simpleClassName(lr.getSourceClassName()),
lr.getMessage(),
exception
);
}
};
}

/** closeHandlers closes all opened handlers. */
public static synchronized void shutdown() {
for (Handler handler : jmxfetchLogger.getHandlers()) {
Expand Down
37 changes: 23 additions & 14 deletions src/test/java/org/datadog/jmxfetch/util/CustomLoggerPerfTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@ public final class CustomLoggerPerfTest {
private final int msgSize; // length of log message in bytes
private final int uPause; // length of log message in bytes
private final boolean rfc3339; // length of log message in bytes
private final boolean logThreadName;

private AtomicBoolean running;
private final ExecutorService executor;
Expand All @@ -42,29 +43,36 @@ public final class CustomLoggerPerfTest {

@Parameters
public static Collection<Object[]> data() {
return Arrays.asList(new Object[][] {
{ 90, 100, 1, 128, false }, // 90 seconds, 100 microsecond pause, 1 worker, 128 byte string, false
{ 90, 100, 1, 512, false }, // 90 seconds, 100 microsecond pause, 1 worker, 512 byte string, false
{ 90, 100, 1, 1024, false }, // 90 seconds, 100 microsecond pause, 1 worker, 512 byte string, false
{ 90, 100, 1, 128, true }, // 90 seconds, 100 microsecond pause, 1 worker, 128 byte string, true
{ 90, 100, 1, 512, true }, // 90 seconds, 100 microsecond pause, 1 worker, 512 byte string, true
{ 90, 100, 1, 1024, true }, // 90 seconds, 100 microsecond pause, 1 worker, 512 byte string, true
});
return Arrays.asList(new Object[][]{
{90, 100, 1, 128, false, false}, // 90 seconds, 100 microsecond pause, 1 worker, 128 byte string, false, false
{90, 100, 1, 512, false, false}, // 90 seconds, 100 microsecond pause, 1 worker, 512 byte string, false, false
{90, 100, 1, 1024, false, false}, // 90 seconds, 100 microsecond pause, 1 worker, 512 byte string, false, false
{90, 100, 1, 128, false, true}, // 90 seconds, 100 microsecond pause, 1 worker, 128 byte string, false, true
{90, 100, 1, 512, false, true}, // 90 seconds, 100 microsecond pause, 1 worker, 512 byte string, false, true
{90, 100, 1, 1024, false, true}, // 90 seconds, 100 microsecond pause, 1 worker, 512 byte string, false, true
{90, 100, 1, 128, true, false}, // 90 seconds, 100 microsecond pause, 1 worker, 128 byte string, true, false
{90, 100, 1, 512, true, false}, // 90 seconds, 100 microsecond pause, 1 worker, 512 byte string, true, false
{90, 100, 1, 1024, true, false}, // 90 seconds, 100 microsecond pause, 1 worker, 512 byte string, true, false
{90, 100, 1, 128, true, true}, // 90 seconds, 100 microsecond pause, 1 worker, 128 byte string, true, true
{90, 100, 1, 512, true, true}, // 90 seconds, 100 microsecond pause, 1 worker, 512 byte string, true, true
{90, 100, 1, 1024, true, true}, // 90 seconds, 100 microsecond pause, 1 worker, 512 byte string, true, true
});
}

public CustomLoggerPerfTest(int duration, int uPause, int testWorkers, int msgSize, boolean rfc3339) throws IOException {
public CustomLoggerPerfTest(int duration, int uPause, int testWorkers, int msgSize, boolean rfc3339, boolean logThreadName) throws IOException {
this.duration = duration;
this.testWorkers = testWorkers;
this.msgSize = msgSize;
this.uPause = uPause;
this.rfc3339 = rfc3339;
this.logThreadName =logThreadName;

this.executor = Executors.newFixedThreadPool(testWorkers);
this.running = new AtomicBoolean(true);

CustomLogger.setup(LogLevel.fromString("INFO"),
null, //stdout
rfc3339);
null, //stdout
rfc3339);
}

/**
Expand Down Expand Up @@ -117,11 +125,13 @@ public void run() {
.append(this.msgSize)
.append(" and RFC 3339 mode set to ")
.append(this.rfc3339)
.append(" and log thread name set to ")
.append(this.logThreadName)
.append(" logged ")
.append(count.get())
.append(" messsages.");

System.out.println(sb.toString());
System.out.println(sb);
}

private String getRandomString(int length) {
Expand All @@ -135,8 +145,7 @@ private String getRandomString(int length) {
(random.nextFloat() * (rightLimit - leftLimit + 1));
buffer.append((char) randomLimitedInt);
}
String generatedString = buffer.toString();

return generatedString;
return buffer.toString();
}
}

0 comments on commit 89e8328

Please sign in to comment.