From af280d700b1a354dc506b34b90ca270203ef423a Mon Sep 17 00:00:00 2001 From: lxning Date: Mon, 13 Dec 2021 15:42:36 -0800 Subject: [PATCH 1/8] draft --- frontend/archive/build.gradle | 4 +- frontend/build.gradle | 2 +- frontend/gradle.properties | 6 +- .../java/org/pytorch/serve/job/GRPCJob.java | 6 +- .../java/org/pytorch/serve/job/RestJob.java | 6 +- .../serve/metrics/MetricCollector.java | 6 +- .../org/pytorch/serve/util/ConfigManager.java | 31 +-------- .../org/pytorch/serve/util/NettyUtils.java | 10 +-- .../serve/util/logging/JSONLayout.java | 22 ------- .../serve/util/logging/QLogLayout.java | 17 ++++- .../org/pytorch/serve/wlm/WorkerThread.java | 8 +-- frontend/server/src/main/resources/log4j2.xml | 65 +++++++++++++++++++ .../pytorch/serve/util/ConfigManagerTest.java | 9 ++- 13 files changed, 111 insertions(+), 81 deletions(-) delete mode 100644 frontend/server/src/main/java/org/pytorch/serve/util/logging/JSONLayout.java create mode 100644 frontend/server/src/main/resources/log4j2.xml diff --git a/frontend/archive/build.gradle b/frontend/archive/build.gradle index b8d6e992a4..d7a3660b6b 100644 --- a/frontend/archive/build.gradle +++ b/frontend/archive/build.gradle @@ -1,9 +1,11 @@ dependencies { api "commons-io:commons-io:2.6" api "org.slf4j:slf4j-api:${slf4j_api_version}" - api "org.slf4j:slf4j-log4j12:${slf4j_log4j12_version}" + api "org.apache.logging.log4j:log4j-slf4j-impl:${slf4j_log4j_version}" api "com.google.code.gson:gson:${gson_version}" + annotationProcessor "org.apache.logging.log4j:log4j-core:2.15.0" + implementation "org.apache.logging.log4j:log4j-core:2.15.0" testImplementation "commons-cli:commons-cli:${commons_cli_version}" testImplementation "org.testng:testng:${testng_version}" } diff --git a/frontend/build.gradle b/frontend/build.gradle index ecf62bcd0a..2feaef8a7a 100644 --- a/frontend/build.gradle +++ b/frontend/build.gradle @@ -59,7 +59,7 @@ configure(javaProjects()) { test.finalizedBy(project.tasks.jacocoTestReport) compileJava { - options.compilerArgs << "-Xlint:all,-options,-static" << "-Werror" + options.compilerArgs << "-proc:none" << "-Xlint:all,-options,-static" << "-Werror" } jacocoTestCoverageVerification { diff --git a/frontend/gradle.properties b/frontend/gradle.properties index ed190933df..c6a0f3669f 100644 --- a/frontend/gradle.properties +++ b/frontend/gradle.properties @@ -4,10 +4,10 @@ commons_cli_version=1.3.1 gson_version=2.8.5 prometheus_version=0.9.0 netty_version=4.1.53.Final -slf4j_api_version=1.7.25 -slf4j_log4j12_version=1.7.25 +slf4j_api_version=1.7.30 +slf4j_log4j_version=2.15.0 testng_version=7.1.0 torchserve_sdk_version=0.0.4 snakeyaml_version=1.8 grpc_version=1.31.1 -protoc_version=3.13.0 +protoc_version=3.13.0 \ No newline at end of file diff --git a/frontend/server/src/main/java/org/pytorch/serve/job/GRPCJob.java b/frontend/server/src/main/java/org/pytorch/serve/job/GRPCJob.java index d7a90e01ac..09ecdfec8a 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/job/GRPCJob.java +++ b/frontend/server/src/main/java/org/pytorch/serve/job/GRPCJob.java @@ -17,8 +17,8 @@ public class GRPCJob extends Job { private static final Logger logger = LoggerFactory.getLogger(Job.class); - private static final org.apache.log4j.Logger loggerTsMetrics = - org.apache.log4j.Logger.getLogger(ConfigManager.MODEL_SERVER_METRICS_LOGGER); + private static final Logger loggerTsMetrics = + LoggerFactory.getLogger(ConfigManager.MODEL_SERVER_METRICS_LOGGER); private static final Dimension DIMENSION = new Dimension("Level", "Host"); private StreamObserver predictionResponseObserver; @@ -54,7 +54,7 @@ public void response( String.valueOf( TimeUnit.MILLISECONDS.convert( getScheduled() - getBegin(), TimeUnit.NANOSECONDS)); - loggerTsMetrics.info( + loggerTsMetrics.info("{}", new Metric( "QueueTime", queueTime, diff --git a/frontend/server/src/main/java/org/pytorch/serve/job/RestJob.java b/frontend/server/src/main/java/org/pytorch/serve/job/RestJob.java index e65e04680b..0c32a81a10 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/job/RestJob.java +++ b/frontend/server/src/main/java/org/pytorch/serve/job/RestJob.java @@ -23,8 +23,8 @@ public class RestJob extends Job { private static final Logger logger = LoggerFactory.getLogger(Job.class); - private static final org.apache.log4j.Logger loggerTsMetrics = - org.apache.log4j.Logger.getLogger(ConfigManager.MODEL_SERVER_METRICS_LOGGER); + private static final Logger loggerTsMetrics = + LoggerFactory.getLogger(ConfigManager.MODEL_SERVER_METRICS_LOGGER); private static final Dimension DIMENSION = new Dimension("Level", "Host"); private ChannelHandlerContext ctx; @@ -86,7 +86,7 @@ public void response( String.valueOf( TimeUnit.MILLISECONDS.convert( getScheduled() - getBegin(), TimeUnit.NANOSECONDS)); - loggerTsMetrics.info( + loggerTsMetrics.info("{}", new Metric( "QueueTime", queueTime, diff --git a/frontend/server/src/main/java/org/pytorch/serve/metrics/MetricCollector.java b/frontend/server/src/main/java/org/pytorch/serve/metrics/MetricCollector.java index 7aef927c25..de8cf9e0e8 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/metrics/MetricCollector.java +++ b/frontend/server/src/main/java/org/pytorch/serve/metrics/MetricCollector.java @@ -20,8 +20,8 @@ public class MetricCollector implements Runnable { private static final Logger logger = LoggerFactory.getLogger(MetricCollector.class); - private static final org.apache.log4j.Logger loggerMetrics = - org.apache.log4j.Logger.getLogger(ConfigManager.MODEL_SERVER_METRICS_LOGGER); + private static final Logger loggerMetrics = + LoggerFactory.getLogger(ConfigManager.MODEL_SERVER_METRICS_LOGGER); private ConfigManager configManager; public MetricCollector(ConfigManager configManager) { @@ -77,7 +77,7 @@ public void run() { if (metric == null) { logger.warn("Parse metrics failed: " + line); } else { - loggerMetrics.info(metric); + loggerMetrics.info("{}", metric); metricsSystem.add(metric); } } diff --git a/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java b/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java index a5e2a6ce00..e495704a57 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java +++ b/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java @@ -43,9 +43,6 @@ import org.apache.commons.cli.Option; import org.apache.commons.cli.Options; import org.apache.commons.io.IOUtils; -import org.apache.log4j.Appender; -import org.apache.log4j.AsyncAppender; -import org.apache.log4j.Logger; import org.pytorch.serve.servingsdk.snapshot.SnapshotSerializer; import org.pytorch.serve.snapshot.SnapshotSerializerFactory; @@ -682,30 +679,8 @@ private File findTsHome() { } private void enableAsyncLogging() { - enableAsyncLogging(Logger.getRootLogger()); - enableAsyncLogging(Logger.getLogger(MODEL_METRICS_LOGGER)); - enableAsyncLogging(Logger.getLogger(MODEL_LOGGER)); - enableAsyncLogging(Logger.getLogger(MODEL_SERVER_METRICS_LOGGER)); - enableAsyncLogging(Logger.getLogger("ACCESS_LOG")); - enableAsyncLogging(Logger.getLogger("org.pytorch.serve")); - } - - private void enableAsyncLogging(Logger logger) { - AsyncAppender asyncAppender = new AsyncAppender(); - - @SuppressWarnings("unchecked") - Enumeration en = logger.getAllAppenders(); - while (en.hasMoreElements()) { - Appender appender = en.nextElement(); - if (appender instanceof AsyncAppender) { - // already async - return; - } - - logger.removeAppender(appender); - asyncAppender.addAppender(appender); - } - logger.addAppender(asyncAppender); + System.setProperty("log4j2.contextSelector", + "org.apache.logging.log4j.core.async.AsyncLoggerContextSelector"); } public HashMap getBackendConfiguration() { @@ -826,7 +801,7 @@ public int getJsonIntValue(String modelName, String version, String element, int value = defaultVal; } } catch (ClassCastException | IllegalStateException e) { - Logger.getRootLogger() + org.apache.logging.log4j.LogManager.getRootLogger() .error( "Invalid value for model: " + modelName diff --git a/frontend/server/src/main/java/org/pytorch/serve/util/NettyUtils.java b/frontend/server/src/main/java/org/pytorch/serve/util/NettyUtils.java index c2bb18af40..31d873d02d 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/util/NettyUtils.java +++ b/frontend/server/src/main/java/org/pytorch/serve/util/NettyUtils.java @@ -63,8 +63,8 @@ public final class NettyUtils { ConfigManager.getInstance().getHostName(), DIMENSION); - private static final org.apache.log4j.Logger loggerTsMetrics = - org.apache.log4j.Logger.getLogger(ConfigManager.MODEL_SERVER_METRICS_LOGGER); + private static final Logger loggerTsMetrics = + LoggerFactory.getLogger(ConfigManager.MODEL_SERVER_METRICS_LOGGER); private NettyUtils() {} @@ -157,11 +157,11 @@ public static void sendHttpResponse( } int code = resp.status().code(); if (code >= 200 && code < 300) { - loggerTsMetrics.info(REQUESTS_2_XX); + loggerTsMetrics.info("{}", REQUESTS_2_XX); } else if (code >= 400 && code < 500) { - loggerTsMetrics.info(REQUESTS_4_XX); + loggerTsMetrics.info("{}", REQUESTS_4_XX); } else { - loggerTsMetrics.info(REQUESTS_5_XX); + loggerTsMetrics.info("{}", REQUESTS_5_XX); } String allowedOrigin = configManager.getCorsAllowedOrigin(); diff --git a/frontend/server/src/main/java/org/pytorch/serve/util/logging/JSONLayout.java b/frontend/server/src/main/java/org/pytorch/serve/util/logging/JSONLayout.java deleted file mode 100644 index d32a1aeacf..0000000000 --- a/frontend/server/src/main/java/org/pytorch/serve/util/logging/JSONLayout.java +++ /dev/null @@ -1,22 +0,0 @@ -package org.pytorch.serve.util.logging; - -import org.apache.log4j.PatternLayout; -import org.apache.log4j.spi.LoggingEvent; -import org.pytorch.serve.metrics.Metric; -import org.pytorch.serve.util.JsonUtils; - -public class JSONLayout extends PatternLayout { - - @Override - public String format(LoggingEvent event) { - Object eventMessage = event.getMessage(); - if (eventMessage == null) { - return null; - } - if (eventMessage instanceof Metric) { - Metric metric = (Metric) event.getMessage(); - return JsonUtils.GSON_PRETTY.toJson(metric) + '\n'; - } - return eventMessage.toString() + '\n'; - } -} diff --git a/frontend/server/src/main/java/org/pytorch/serve/util/logging/QLogLayout.java b/frontend/server/src/main/java/org/pytorch/serve/util/logging/QLogLayout.java index 338832e480..f9c01b4def 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/util/logging/QLogLayout.java +++ b/frontend/server/src/main/java/org/pytorch/serve/util/logging/QLogLayout.java @@ -1,11 +1,22 @@ package org.pytorch.serve.util.logging; -import org.apache.log4j.PatternLayout; -import org.apache.log4j.spi.LoggingEvent; import org.pytorch.serve.metrics.Dimension; import org.pytorch.serve.metrics.Metric; +import org.apache.logging.log4j.core.Layout; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.config.Node; +import org.apache.logging.log4j.core.config.plugins.Plugin; +import org.apache.logging.log4j.core.layout.AbstractStringLayout; +@Plugin( + name = "QLogLayout", + category = Node.CATEGORY, + elementType = Layout.ELEMENT_TYPE, + printObject = true) public class QLogLayout extends PatternLayout { + public QLogLayout() { + super(null, null, null); + } /** * Model server also supports query log formatting. @@ -61,7 +72,7 @@ public class QLogLayout extends PatternLayout { * @return */ @Override - public String format(LoggingEvent event) { + public String toSerializable(LoggingEvent event) { Object eventMessage = event.getMessage(); String programName = getStringOrDefault(System.getenv("MXNETMODELSERVER_PROGRAM"), "MXNetModelServer"); diff --git a/frontend/server/src/main/java/org/pytorch/serve/wlm/WorkerThread.java b/frontend/server/src/main/java/org/pytorch/serve/wlm/WorkerThread.java index 6ec5db67e4..0e2b1dedbe 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/wlm/WorkerThread.java +++ b/frontend/server/src/main/java/org/pytorch/serve/wlm/WorkerThread.java @@ -41,8 +41,8 @@ public class WorkerThread implements Runnable { private static final Logger logger = LoggerFactory.getLogger(WorkerThread.class); - private static final org.apache.log4j.Logger loggerTsMetrics = - org.apache.log4j.Logger.getLogger(ConfigManager.MODEL_SERVER_METRICS_LOGGER); + private static final Logger loggerTsMetrics = + LoggerFactory.getLogger(ConfigManager.MODEL_SERVER_METRICS_LOGGER); private Metric workerLoadTime; @@ -220,7 +220,7 @@ public void run() { req = null; String workerThreadTime = String.valueOf(((System.currentTimeMillis() - wtStartTime) - duration)); - loggerTsMetrics.info( + loggerTsMetrics.info("{}", new Metric( "WorkerThreadTime", workerThreadTime, @@ -412,7 +412,7 @@ public void setState(WorkerState newState, int status) { workerLoadTime.setValue(String.valueOf(timeTaken)); workerLoadTime.setTimestamp( String.valueOf(TimeUnit.MILLISECONDS.toSeconds(System.currentTimeMillis()))); - loggerTsMetrics.info(workerLoadTime); + loggerTsMetrics.info("{}", workerLoadTime); } } diff --git a/frontend/server/src/main/resources/log4j2.xml b/frontend/server/src/main/resources/log4j2.xml new file mode 100644 index 0000000000..dc8b11b118 --- /dev/null +++ b/frontend/server/src/main/resources/log4j2.xml @@ -0,0 +1,65 @@ + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + + \ No newline at end of file diff --git a/frontend/server/src/test/java/org/pytorch/serve/util/ConfigManagerTest.java b/frontend/server/src/test/java/org/pytorch/serve/util/ConfigManagerTest.java index 7fe3dab8b5..15daf18dad 100644 --- a/frontend/server/src/test/java/org/pytorch/serve/util/ConfigManagerTest.java +++ b/frontend/server/src/test/java/org/pytorch/serve/util/ConfigManagerTest.java @@ -69,13 +69,12 @@ public void test() throws IOException, GeneralSecurityException, ReflectiveOpera metrics.add(createMetric("TestMetric1", "12345")); metrics.add(createMetric("TestMetric2", "23478")); - org.apache.log4j.Logger logger = - org.apache.log4j.Logger.getLogger(ConfigManager.MODEL_SERVER_METRICS_LOGGER); - logger.debug(metrics); + Logger logger = LoggerFactory.getLogger(ConfigManager.MODEL_SERVER_METRICS_LOGGER); + logger.debug("{}", metrics); Assert.assertTrue(new File("build/logs/ts_metrics.log").exists()); - logger = org.apache.log4j.Logger.getLogger(ConfigManager.MODEL_METRICS_LOGGER); - logger.debug(metrics); + logger = LoggerFactory.getLogger(ConfigManager.MODEL_METRICS_LOGGER); + logger.debug("{}", metrics); Assert.assertTrue(new File("build/logs/model_metrics.log").exists()); Logger modelLogger = LoggerFactory.getLogger(ConfigManager.MODEL_LOGGER); From bf02b433d40ec876cf86c9f6bec23f6e8225ace8 Mon Sep 17 00:00:00 2001 From: lxning Date: Mon, 13 Dec 2021 16:03:13 -0800 Subject: [PATCH 2/8] update --- frontend/archive/build.gradle | 6 ++---- .../src/main/java/org/pytorch/serve/util/ConfigManager.java | 3 ++- 2 files changed, 4 insertions(+), 5 deletions(-) diff --git a/frontend/archive/build.gradle b/frontend/archive/build.gradle index d7a3660b6b..3777df73ce 100644 --- a/frontend/archive/build.gradle +++ b/frontend/archive/build.gradle @@ -1,11 +1,9 @@ dependencies { api "commons-io:commons-io:2.6" - api "org.slf4j:slf4j-api:${slf4j_api_version}" - api "org.apache.logging.log4j:log4j-slf4j-impl:${slf4j_log4j_version}" + implementation "org.slf4j:slf4j-api:${slf4j_api_version}" + implementation "org.apache.logging.log4j:log4j-slf4j-impl:${slf4j_log4j_version}" api "com.google.code.gson:gson:${gson_version}" - annotationProcessor "org.apache.logging.log4j:log4j-core:2.15.0" - implementation "org.apache.logging.log4j:log4j-core:2.15.0" testImplementation "commons-cli:commons-cli:${commons_cli_version}" testImplementation "org.testng:testng:${testng_version}" } diff --git a/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java b/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java index e495704a57..cbaf36677a 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java +++ b/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java @@ -45,6 +45,7 @@ import org.apache.commons.io.IOUtils; import org.pytorch.serve.servingsdk.snapshot.SnapshotSerializer; import org.pytorch.serve.snapshot.SnapshotSerializerFactory; +import org.slf4j.LoggerFactory; public final class ConfigManager { // Variables that can be configured through config.properties and Environment Variables @@ -801,7 +802,7 @@ public int getJsonIntValue(String modelName, String version, String element, int value = defaultVal; } } catch (ClassCastException | IllegalStateException e) { - org.apache.logging.log4j.LogManager.getRootLogger() + LoggerFactory.getLogger() .error( "Invalid value for model: " + modelName From c130a87e1b89124fc28042b21c875877e8c7a854 Mon Sep 17 00:00:00 2001 From: lxning Date: Mon, 13 Dec 2021 16:19:50 -0800 Subject: [PATCH 3/8] update --- .../java/org/pytorch/serve/util/ConfigManager.java | 10 ++-------- frontend/server/src/main/resources/log4j2.xml | 3 ++- 2 files changed, 4 insertions(+), 9 deletions(-) diff --git a/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java b/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java index cbaf36677a..864b53c5c3 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java +++ b/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java @@ -802,14 +802,8 @@ public int getJsonIntValue(String modelName, String version, String element, int value = defaultVal; } } catch (ClassCastException | IllegalStateException e) { - LoggerFactory.getLogger() - .error( - "Invalid value for model: " - + modelName - + ":" - + version - + ", parameter: " - + element); + LoggerFactory.getLogger(). + error("Invalid value for model: {}:{}, parameter: {}", modelName, version, element); return defaultVal; } } diff --git a/frontend/server/src/main/resources/log4j2.xml b/frontend/server/src/main/resources/log4j2.xml index dc8b11b118..24d0d79acc 100644 --- a/frontend/server/src/main/resources/log4j2.xml +++ b/frontend/server/src/main/resources/log4j2.xml @@ -59,7 +59,8 @@ - + + \ No newline at end of file From 0738185d1ee51421ef3b5e6530657b3b33754162 Mon Sep 17 00:00:00 2001 From: lxning Date: Mon, 13 Dec 2021 19:35:18 -0800 Subject: [PATCH 4/8] migrate to log4j 2 --- frontend/archive/build.gradle | 4 +- frontend/gradle.properties | 2 +- frontend/server/build.gradle | 13 ++++--- .../java/org/pytorch/serve/job/GRPCJob.java | 3 +- .../java/org/pytorch/serve/job/RestJob.java | 3 +- .../org/pytorch/serve/util/ConfigManager.java | 11 ++++-- .../serve/util/logging/QLogLayout.java | 8 ++-- .../org/pytorch/serve/wlm/WorkerThread.java | 3 +- frontend/server/src/main/resources/log4j2.xml | 39 ++++++++++++++----- .../src/test/resources/config.properties | 1 + 10 files changed, 59 insertions(+), 28 deletions(-) diff --git a/frontend/archive/build.gradle b/frontend/archive/build.gradle index 3777df73ce..53f31b57e1 100644 --- a/frontend/archive/build.gradle +++ b/frontend/archive/build.gradle @@ -1,7 +1,7 @@ dependencies { api "commons-io:commons-io:2.6" - implementation "org.slf4j:slf4j-api:${slf4j_api_version}" - implementation "org.apache.logging.log4j:log4j-slf4j-impl:${slf4j_log4j_version}" + api "org.slf4j:slf4j-api:${slf4j_api_version}" + api "org.apache.logging.log4j:log4j-core:${slf4j_log4j_version}" api "com.google.code.gson:gson:${gson_version}" testImplementation "commons-cli:commons-cli:${commons_cli_version}" diff --git a/frontend/gradle.properties b/frontend/gradle.properties index c6a0f3669f..202654a51a 100644 --- a/frontend/gradle.properties +++ b/frontend/gradle.properties @@ -4,7 +4,7 @@ commons_cli_version=1.3.1 gson_version=2.8.5 prometheus_version=0.9.0 netty_version=4.1.53.Final -slf4j_api_version=1.7.30 +slf4j_api_version=1.7.32 slf4j_log4j_version=2.15.0 testng_version=7.1.0 torchserve_sdk_version=0.0.4 diff --git a/frontend/server/build.gradle b/frontend/server/build.gradle index 9076e8d257..a1382f75d6 100644 --- a/frontend/server/build.gradle +++ b/frontend/server/build.gradle @@ -6,6 +6,7 @@ dependencies { implementation project(":archive") implementation "commons-cli:commons-cli:${commons_cli_version}" implementation "org.pytorch:torchserve-plugins-sdk:${torchserve_sdk_version}" + implementation "org.apache.logging.log4j:log4j-core:${slf4j_log4j_version}" testImplementation "org.testng:testng:${testng_version}" } @@ -26,8 +27,10 @@ jar { exclude "META-INF//NOTICE*" } -test.doFirst { - systemProperty "tsConfigFile", 'src/test/resources/config.properties' - systemProperty "METRICS_LOCATION","build/logs" - systemProperty "LOG_LOCATION","build/logs" -} +test { + doFirst { + systemProperty "tsConfigFile", 'src/test/resources/config.properties' + } + environment "METRICS_LOCATION","build/logs" + environment "LOG_LOCATION","build/logs" +} \ No newline at end of file diff --git a/frontend/server/src/main/java/org/pytorch/serve/job/GRPCJob.java b/frontend/server/src/main/java/org/pytorch/serve/job/GRPCJob.java index 09ecdfec8a..102ca7043f 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/job/GRPCJob.java +++ b/frontend/server/src/main/java/org/pytorch/serve/job/GRPCJob.java @@ -54,7 +54,8 @@ public void response( String.valueOf( TimeUnit.MILLISECONDS.convert( getScheduled() - getBegin(), TimeUnit.NANOSECONDS)); - loggerTsMetrics.info("{}", + loggerTsMetrics.info( + "{}", new Metric( "QueueTime", queueTime, diff --git a/frontend/server/src/main/java/org/pytorch/serve/job/RestJob.java b/frontend/server/src/main/java/org/pytorch/serve/job/RestJob.java index 0c32a81a10..644f999d69 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/job/RestJob.java +++ b/frontend/server/src/main/java/org/pytorch/serve/job/RestJob.java @@ -86,7 +86,8 @@ public void response( String.valueOf( TimeUnit.MILLISECONDS.convert( getScheduled() - getBegin(), TimeUnit.NANOSECONDS)); - loggerTsMetrics.info("{}", + loggerTsMetrics.info( + "{}", new Metric( "QueueTime", queueTime, diff --git a/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java b/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java index 864b53c5c3..3bf54a71a4 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java +++ b/frontend/server/src/main/java/org/pytorch/serve/util/ConfigManager.java @@ -680,7 +680,8 @@ private File findTsHome() { } private void enableAsyncLogging() { - System.setProperty("log4j2.contextSelector", + System.setProperty( + "log4j2.contextSelector", "org.apache.logging.log4j.core.async.AsyncLoggerContextSelector"); } @@ -802,8 +803,12 @@ public int getJsonIntValue(String modelName, String version, String element, int value = defaultVal; } } catch (ClassCastException | IllegalStateException e) { - LoggerFactory.getLogger(). - error("Invalid value for model: {}:{}, parameter: {}", modelName, version, element); + LoggerFactory.getLogger(ConfigManager.class) + .error( + "Invalid value for model: {}:{}, parameter: {}", + modelName, + version, + element); return defaultVal; } } diff --git a/frontend/server/src/main/java/org/pytorch/serve/util/logging/QLogLayout.java b/frontend/server/src/main/java/org/pytorch/serve/util/logging/QLogLayout.java index f9c01b4def..8da50e0c22 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/util/logging/QLogLayout.java +++ b/frontend/server/src/main/java/org/pytorch/serve/util/logging/QLogLayout.java @@ -1,19 +1,19 @@ package org.pytorch.serve.util.logging; -import org.pytorch.serve.metrics.Dimension; -import org.pytorch.serve.metrics.Metric; import org.apache.logging.log4j.core.Layout; import org.apache.logging.log4j.core.LogEvent; import org.apache.logging.log4j.core.config.Node; import org.apache.logging.log4j.core.config.plugins.Plugin; import org.apache.logging.log4j.core.layout.AbstractStringLayout; +import org.pytorch.serve.metrics.Dimension; +import org.pytorch.serve.metrics.Metric; @Plugin( name = "QLogLayout", category = Node.CATEGORY, elementType = Layout.ELEMENT_TYPE, printObject = true) -public class QLogLayout extends PatternLayout { +public class QLogLayout extends AbstractStringLayout { public QLogLayout() { super(null, null, null); } @@ -72,7 +72,7 @@ public QLogLayout() { * @return */ @Override - public String toSerializable(LoggingEvent event) { + public String toSerializable(LogEvent event) { Object eventMessage = event.getMessage(); String programName = getStringOrDefault(System.getenv("MXNETMODELSERVER_PROGRAM"), "MXNetModelServer"); diff --git a/frontend/server/src/main/java/org/pytorch/serve/wlm/WorkerThread.java b/frontend/server/src/main/java/org/pytorch/serve/wlm/WorkerThread.java index 0e2b1dedbe..55e7ef29aa 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/wlm/WorkerThread.java +++ b/frontend/server/src/main/java/org/pytorch/serve/wlm/WorkerThread.java @@ -220,7 +220,8 @@ public void run() { req = null; String workerThreadTime = String.valueOf(((System.currentTimeMillis() - wtStartTime) - duration)); - loggerTsMetrics.info("{}", + loggerTsMetrics.info( + "{}", new Metric( "WorkerThreadTime", workerThreadTime, diff --git a/frontend/server/src/main/resources/log4j2.xml b/frontend/server/src/main/resources/log4j2.xml index 24d0d79acc..0e3e459b32 100644 --- a/frontend/server/src/main/resources/log4j2.xml +++ b/frontend/server/src/main/resources/log4j2.xml @@ -1,43 +1,62 @@ - + - + + - + - + + - + - + + - + - + + - + - + + diff --git a/frontend/server/src/test/resources/config.properties b/frontend/server/src/test/resources/config.properties index 1c433b2775..7b8f3e29a2 100644 --- a/frontend/server/src/test/resources/config.properties +++ b/frontend/server/src/test/resources/config.properties @@ -28,6 +28,7 @@ max_request_size=2047093252 # blacklist_env_vars=.*USERNAME.*|.*PASSWORD.* # decode_input_request=true enable_envvars_config=true +# default_service_handler=/path/to/service.py:handle models={\ "noop": {\ "1.11": {\ From 9ad9c608b41ae0d8946d1814364c66015b54c44f Mon Sep 17 00:00:00 2001 From: lxning Date: Mon, 13 Dec 2021 19:53:08 -0800 Subject: [PATCH 5/8] update pkg log4j-slf4j-imp --- frontend/archive/build.gradle | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/frontend/archive/build.gradle b/frontend/archive/build.gradle index 53f31b57e1..cce015aa26 100644 --- a/frontend/archive/build.gradle +++ b/frontend/archive/build.gradle @@ -1,7 +1,7 @@ dependencies { api "commons-io:commons-io:2.6" api "org.slf4j:slf4j-api:${slf4j_api_version}" - api "org.apache.logging.log4j:log4j-core:${slf4j_log4j_version}" + api "org.apache.logging.log4j:log4j-slf4j-impl:${slf4j_log4j_version}" api "com.google.code.gson:gson:${gson_version}" testImplementation "commons-cli:commons-cli:${commons_cli_version}" From c6e0fb06e1d085304ba7b76c176d097d9b14ab12 Mon Sep 17 00:00:00 2001 From: lxning Date: Tue, 14 Dec 2021 11:39:39 -0800 Subject: [PATCH 6/8] Trigger build From 607079ed91b4e84534cd9f6ce423ecfd6e6b0fa7 Mon Sep 17 00:00:00 2001 From: lxning Date: Tue, 14 Dec 2021 13:01:15 -0800 Subject: [PATCH 7/8] Trigger build From 45c0777639de6a5c10199feaa9f1e00ccb9bab2a Mon Sep 17 00:00:00 2001 From: lxning Date: Tue, 14 Dec 2021 14:16:57 -0800 Subject: [PATCH 8/8] upgrade Qlog --- frontend/gradle.properties | 2 +- .../serve/util/logging/QLogLayout.java | 92 ++++++++++--------- 2 files changed, 48 insertions(+), 46 deletions(-) diff --git a/frontend/gradle.properties b/frontend/gradle.properties index 202654a51a..1b6370362b 100644 --- a/frontend/gradle.properties +++ b/frontend/gradle.properties @@ -5,7 +5,7 @@ gson_version=2.8.5 prometheus_version=0.9.0 netty_version=4.1.53.Final slf4j_api_version=1.7.32 -slf4j_log4j_version=2.15.0 +slf4j_log4j_version=2.16.0 testng_version=7.1.0 torchserve_sdk_version=0.0.4 snakeyaml_version=1.8 diff --git a/frontend/server/src/main/java/org/pytorch/serve/util/logging/QLogLayout.java b/frontend/server/src/main/java/org/pytorch/serve/util/logging/QLogLayout.java index 8da50e0c22..3dab543feb 100644 --- a/frontend/server/src/main/java/org/pytorch/serve/util/logging/QLogLayout.java +++ b/frontend/server/src/main/java/org/pytorch/serve/util/logging/QLogLayout.java @@ -5,6 +5,7 @@ import org.apache.logging.log4j.core.config.Node; import org.apache.logging.log4j.core.config.plugins.Plugin; import org.apache.logging.log4j.core.layout.AbstractStringLayout; +import org.apache.logging.log4j.message.Message; import org.pytorch.serve.metrics.Dimension; import org.pytorch.serve.metrics.Metric; @@ -73,66 +74,67 @@ public QLogLayout() { */ @Override public String toSerializable(LogEvent event) { - Object eventMessage = event.getMessage(); + Message eventMessage = event.getMessage(); + if (eventMessage == null || eventMessage.getParameters() == null) { + return null; + } String programName = getStringOrDefault(System.getenv("MXNETMODELSERVER_PROGRAM"), "MXNetModelServer"); String domain = getStringOrDefault(System.getenv("DOMAIN"), "Unknown"); long currentTimeInSec = System.currentTimeMillis() / 1000; + Object[] parameters = eventMessage.getParameters(); - if (eventMessage == null) { - return null; - } - if (eventMessage instanceof Metric) { - String marketPlace = System.getenv("REALM"); + StringBuilder stringBuilder = new StringBuilder(); + for (Object obj : parameters) { + if (obj instanceof Metric) { + Metric metric = (Metric) obj; + String marketPlace = System.getenv("REALM"); - StringBuilder stringBuilder = new StringBuilder(); - Metric metric = (Metric) eventMessage; - stringBuilder.append("HostName=").append(metric.getHostName()); + stringBuilder.append("HostName=").append(metric.getHostName()); - if (metric.getRequestId() != null && !metric.getRequestId().isEmpty()) { - stringBuilder.append("\nRequestId=").append(metric.getRequestId()); - } + if (metric.getRequestId() != null && !metric.getRequestId().isEmpty()) { + stringBuilder.append("\nRequestId=").append(metric.getRequestId()); + } - // Marketplace format should be : :: - if (marketPlace != null && !marketPlace.isEmpty()) { - stringBuilder - .append("\nMarketplace=") - .append(programName) - .append(':') - .append(domain) - .append(':') - .append(marketPlace); - } + // Marketplace format should be : :: + if (marketPlace != null && !marketPlace.isEmpty()) { + stringBuilder + .append("\nMarketplace=") + .append(programName) + .append(':') + .append(domain) + .append(':') + .append(marketPlace); + } - stringBuilder - .append("\nStartTime=") - .append( - getStringOrDefault( - metric.getTimestamp(), Long.toString(currentTimeInSec))); + stringBuilder + .append("\nStartTime=") + .append( + getStringOrDefault( + metric.getTimestamp(), Long.toString(currentTimeInSec))); - stringBuilder - .append("\nProgram=") - .append(programName) - .append("\nMetrics=") - .append(metric.getMetricName()) - .append('=') - .append(metric.getValue()) - .append(' ') - .append(metric.getUnit()); - for (Dimension dimension : metric.getDimensions()) { stringBuilder + .append("\nProgram=") + .append(programName) + .append("\nMetrics=") + .append(metric.getMetricName()) + .append('=') + .append(metric.getValue()) .append(' ') - .append(dimension.getName()) - .append('|') - .append(dimension.getValue()) - .append(' '); + .append(metric.getUnit()); + for (Dimension dimension : metric.getDimensions()) { + stringBuilder + .append(' ') + .append(dimension.getName()) + .append('|') + .append(dimension.getValue()) + .append(' '); + } + stringBuilder.append("\nEOE\n"); } - stringBuilder.append("\nEOE\n"); - - return stringBuilder.toString(); } - return eventMessage.toString(); + return stringBuilder.toString(); } private static String getStringOrDefault(String val, String defVal) {