Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[AMLII-1817] Added support for emitting logs with thread name #525

Merged
merged 3 commits into from
Jun 7, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion CHANGELOG.md
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:/DataDog/jmxfetch/issues/477
[#509]: https:/DataDog/jmxfetch/issues/509
[#512]: https:/DataDog/jmxfetch/pull/512
[#522]: https:/DataDog/jmxfetch/pull/522
[@alz]: https:/alz
[@aoking]: https:/aoking
[@arrawatia]: https:/arrawatia
Expand Down
4 changes: 2 additions & 2 deletions src/main/java/org/datadog/jmxfetch/JmxFetch.java
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
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
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();
}
}
Loading