diff --git a/java/server/src/org/openqa/grid/selenium/GridLauncherV3.java b/java/server/src/org/openqa/grid/selenium/GridLauncherV3.java index bd6045add9da0..5579ce401c575 100644 --- a/java/server/src/org/openqa/grid/selenium/GridLauncherV3.java +++ b/java/server/src/org/openqa/grid/selenium/GridLauncherV3.java @@ -35,10 +35,10 @@ import org.openqa.grid.shared.Stoppable; import org.openqa.grid.web.Hub; import org.openqa.selenium.BuildInfo; +import org.openqa.selenium.grid.log.TerseFormatter; import org.openqa.selenium.net.PortProber; import org.openqa.selenium.remote.server.SeleniumServer; import org.openqa.selenium.remote.server.log.LoggingOptions; -import org.openqa.selenium.remote.server.log.TerseFormatter; import java.io.File; import java.io.IOException; diff --git a/java/server/src/org/openqa/selenium/grid/commands/Hub.java b/java/server/src/org/openqa/selenium/grid/commands/Hub.java index a790fa05bbcbc..ba129b4f33faf 100644 --- a/java/server/src/org/openqa/selenium/grid/commands/Hub.java +++ b/java/server/src/org/openqa/selenium/grid/commands/Hub.java @@ -36,7 +36,7 @@ import org.openqa.selenium.grid.server.BaseServerFlags; import org.openqa.selenium.grid.server.BaseServerOptions; import org.openqa.selenium.grid.server.HelpFlags; -import org.openqa.selenium.grid.server.LoggingOptions; +import org.openqa.selenium.grid.log.LoggingOptions; import org.openqa.selenium.grid.server.Server; import org.openqa.selenium.grid.server.W3CCommandHandler; import org.openqa.selenium.grid.sessionmap.SessionMap; @@ -90,7 +90,9 @@ public Executable configure(String... args) { new EnvConfig(), new ConcatenatingConfig("selenium", '.', System.getProperties())); - DistributedTracer tracer = new LoggingOptions(config).getTracer(); + LoggingOptions loggingOptions = new LoggingOptions(config); + loggingOptions.configureLogging(); + DistributedTracer tracer = loggingOptions.getTracer(); GlobalDistributedTracer.setInstance(tracer); SessionMap sessions = new LocalSessionMap(tracer); diff --git a/java/server/src/org/openqa/selenium/grid/commands/Standalone.java b/java/server/src/org/openqa/selenium/grid/commands/Standalone.java index 35dd17d5f7752..5e4e136f61453 100644 --- a/java/server/src/org/openqa/selenium/grid/commands/Standalone.java +++ b/java/server/src/org/openqa/selenium/grid/commands/Standalone.java @@ -38,7 +38,7 @@ import org.openqa.selenium.grid.server.BaseServerFlags; import org.openqa.selenium.grid.server.BaseServerOptions; import org.openqa.selenium.grid.server.HelpFlags; -import org.openqa.selenium.grid.server.LoggingOptions; +import org.openqa.selenium.grid.log.LoggingOptions; import org.openqa.selenium.grid.server.Server; import org.openqa.selenium.grid.server.W3CCommandHandler; import org.openqa.selenium.grid.sessionmap.SessionMap; @@ -50,6 +50,7 @@ import java.net.URI; import java.net.URISyntaxException; +import java.util.logging.Logger; @AutoService(CliCommand.class) public class Standalone implements CliCommand { @@ -96,7 +97,12 @@ public Executable configure(String... args) { new EnvConfig(), new ConcatenatingConfig("selenium", '.', System.getProperties())); - DistributedTracer tracer = new LoggingOptions(config).getTracer(); + LoggingOptions loggingOptions = new LoggingOptions(config); + loggingOptions.configureLogging(); + + Logger.getLogger("selenium").info("Logging configured."); + + DistributedTracer tracer = loggingOptions.getTracer(); GlobalDistributedTracer.setInstance(tracer); SessionMap sessions = new LocalSessionMap(tracer); diff --git a/java/server/src/org/openqa/selenium/grid/distributor/httpd/DistributorServer.java b/java/server/src/org/openqa/selenium/grid/distributor/httpd/DistributorServer.java index 5a991c25e2ba7..ddf3b30d144bd 100644 --- a/java/server/src/org/openqa/selenium/grid/distributor/httpd/DistributorServer.java +++ b/java/server/src/org/openqa/selenium/grid/distributor/httpd/DistributorServer.java @@ -30,11 +30,11 @@ import org.openqa.selenium.grid.config.EnvConfig; import org.openqa.selenium.grid.distributor.Distributor; import org.openqa.selenium.grid.distributor.local.LocalDistributor; +import org.openqa.selenium.grid.log.LoggingOptions; import org.openqa.selenium.grid.server.BaseServer; import org.openqa.selenium.grid.server.BaseServerFlags; import org.openqa.selenium.grid.server.BaseServerOptions; import org.openqa.selenium.grid.server.HelpFlags; -import org.openqa.selenium.grid.server.LoggingOptions; import org.openqa.selenium.grid.server.Server; import org.openqa.selenium.grid.server.W3CCommandHandler; import org.openqa.selenium.grid.web.Routes; @@ -86,7 +86,9 @@ public Executable configure(String... args) { new EnvConfig(), new ConcatenatingConfig("distributor", '.', System.getProperties())); - DistributedTracer tracer = new LoggingOptions(config).getTracer(); + LoggingOptions loggingOptions = new LoggingOptions(config); + loggingOptions.configureLogging(); + DistributedTracer tracer = loggingOptions.getTracer(); GlobalDistributedTracer.setInstance(tracer); Distributor distributor = new LocalDistributor(tracer); diff --git a/java/server/src/org/openqa/selenium/grid/log/BUCK b/java/server/src/org/openqa/selenium/grid/log/BUCK new file mode 100644 index 0000000000000..1b627e1c697dd --- /dev/null +++ b/java/server/src/org/openqa/selenium/grid/log/BUCK @@ -0,0 +1,13 @@ +java_library( + name = "log", + srcs = glob(["*.java"]), + deps = [ + "//java/client/src/org/openqa/selenium/remote:remote", + "//java/client/src/org/openqa/selenium/remote/tracing:tracing", + "//java/server/src/org/openqa/selenium/grid/config:config", + ], + visibility = [ + "//java/server/src/org/openqa/...", + "//java/server/test/org/openqa/...", + ], +) diff --git a/java/server/src/org/openqa/selenium/grid/log/BUILD.bazel b/java/server/src/org/openqa/selenium/grid/log/BUILD.bazel new file mode 100644 index 0000000000000..d7a8f42b1f1cc --- /dev/null +++ b/java/server/src/org/openqa/selenium/grid/log/BUILD.bazel @@ -0,0 +1,13 @@ +java_library( + name = "log", + srcs = glob(["*.java"]), + deps = [ + "//java/client/src/org/openqa/selenium/remote", + "//java/client/src/org/openqa/selenium/remote/tracing", + "//java/server/src/org/openqa/selenium/grid/config", + ], + visibility = [ + "//java/server/src/org/openqa:__subpackages__", + "//java/server/test/org/openqa:__subpackages__", + ], +) diff --git a/java/server/src/org/openqa/selenium/grid/log/FlushingHandler.java b/java/server/src/org/openqa/selenium/grid/log/FlushingHandler.java new file mode 100644 index 0000000000000..e3aa7e1ee8dfa --- /dev/null +++ b/java/server/src/org/openqa/selenium/grid/log/FlushingHandler.java @@ -0,0 +1,37 @@ +package org.openqa.selenium.grid.log; + +import java.io.OutputStream; +import java.util.Objects; +import java.util.logging.LogRecord; +import java.util.logging.StreamHandler; + +class FlushingHandler extends StreamHandler { + + private OutputStream out; + + FlushingHandler(OutputStream out) { + setOutputStream(out); + } + + @Override + protected synchronized void setOutputStream(OutputStream out) throws SecurityException { + super.setOutputStream(out); + this.out = out; + } + + @Override + public synchronized void publish(LogRecord record) { + super.publish(record); + flush(); + } + + @Override + public synchronized void close() throws SecurityException { + // Avoid closing sysout or syserr + if (Objects.equals(System.out, out) || Objects.equals(System.err, out)) { + flush(); + } else { + super.close(); + } + } +} diff --git a/java/server/src/org/openqa/selenium/grid/log/JsonFormatter.java b/java/server/src/org/openqa/selenium/grid/log/JsonFormatter.java new file mode 100644 index 0000000000000..06eae7f6f7fbf --- /dev/null +++ b/java/server/src/org/openqa/selenium/grid/log/JsonFormatter.java @@ -0,0 +1,45 @@ +package org.openqa.selenium.grid.log; + +import static java.time.ZoneOffset.UTC; +import static java.time.format.DateTimeFormatter.ISO_OFFSET_DATE_TIME; + +import org.openqa.selenium.json.Json; +import org.openqa.selenium.json.JsonOutput; + +import java.time.Instant; +import java.time.ZoneId; +import java.time.ZonedDateTime; +import java.util.Map; +import java.util.TreeMap; +import java.util.logging.Formatter; +import java.util.logging.LogRecord; + +class JsonFormatter extends Formatter { + + public static final Json JSON = new Json(); + + @Override + public String format(LogRecord record) { + Map logRecord = new TreeMap<>(); + + Instant instant = Instant.ofEpochMilli(record.getMillis()); + ZonedDateTime local = ZonedDateTime.ofInstant(instant, ZoneId.systemDefault()); + + logRecord.put("log-time-local", ISO_OFFSET_DATE_TIME.format(local)); + logRecord.put("log-time-utc", ISO_OFFSET_DATE_TIME.format(local.withZoneSameInstant(UTC))); + + String[] split = record.getSourceClassName().split("\\."); + logRecord.put("class", split[split.length - 1]); + logRecord.put("method", record.getSourceMethodName()); + logRecord.put("log-name", record.getLoggerName()); + logRecord.put("log-level", record.getLevel()); + logRecord.put("log-message", record.getMessage()); + + StringBuilder text = new StringBuilder(); + try (JsonOutput json = JSON.newOutput(text).setPrettyPrint(false)) { + json.write(logRecord); + text.append('\n'); + } + return text.toString(); + } +} diff --git a/java/server/src/org/openqa/selenium/grid/log/LoggingOptions.java b/java/server/src/org/openqa/selenium/grid/log/LoggingOptions.java new file mode 100644 index 0000000000000..0b7e98658e6c9 --- /dev/null +++ b/java/server/src/org/openqa/selenium/grid/log/LoggingOptions.java @@ -0,0 +1,62 @@ +package org.openqa.selenium.grid.log; + +import org.openqa.selenium.grid.config.Config; +import org.openqa.selenium.remote.tracing.DistributedTracer; + +import java.util.Arrays; +import java.util.Enumeration; +import java.util.Objects; +import java.util.logging.Handler; +import java.util.logging.LogManager; +import java.util.logging.Logger; + +public class LoggingOptions { + + private final Config config; + + public LoggingOptions(Config config) { + this.config = Objects.requireNonNull(config); + } + + public boolean isUsingStructuredLogging() { + return config.getBool("logging", "structured-logs").orElse(false); + } + + public boolean isUsingPlainLogs() { + return config.getBool("logging", "plain-logs").orElse(true); + } + + public DistributedTracer getTracer() { + return DistributedTracer.builder().detect().build(); + } + + public void configureLogging() { + if (!config.getBool("logging", "enable").orElse(true)) { + return; + } + + // Remove all handlers from existing loggers + LogManager logManager = LogManager.getLogManager(); + Enumeration names = logManager.getLoggerNames(); + while (names.hasMoreElements()) { + Logger logger = logManager.getLogger(names.nextElement()); + Arrays.stream(logger.getHandlers()).forEach(logger::removeHandler); + } + + // Now configure the root logger, since everything should flow up to that + Logger logger = logManager.getLogger(""); + + if (isUsingPlainLogs()) { + Handler handler = new FlushingHandler(System.out); + handler.setFormatter(new TerseFormatter()); + logger.addHandler(handler); + } + + if (isUsingStructuredLogging()) { + Handler handler = new FlushingHandler(System.out); + handler.setFormatter(new JsonFormatter()); + logger.addHandler(handler); + } + } + +} diff --git a/java/server/src/org/openqa/selenium/remote/server/log/TerseFormatter.java b/java/server/src/org/openqa/selenium/grid/log/TerseFormatter.java similarity index 98% rename from java/server/src/org/openqa/selenium/remote/server/log/TerseFormatter.java rename to java/server/src/org/openqa/selenium/grid/log/TerseFormatter.java index 8d075f146e62b..a20f0841a71d0 100644 --- a/java/server/src/org/openqa/selenium/remote/server/log/TerseFormatter.java +++ b/java/server/src/org/openqa/selenium/grid/log/TerseFormatter.java @@ -15,7 +15,7 @@ // specific language governing permissions and limitations // under the License. -package org.openqa.selenium.remote.server.log; +package org.openqa.selenium.grid.log; import java.io.PrintWriter; import java.io.StringWriter; diff --git a/java/server/src/org/openqa/selenium/grid/node/httpd/NodeServer.java b/java/server/src/org/openqa/selenium/grid/node/httpd/NodeServer.java index f2d7202f1ad4f..9d25bbc8c3ed4 100644 --- a/java/server/src/org/openqa/selenium/grid/node/httpd/NodeServer.java +++ b/java/server/src/org/openqa/selenium/grid/node/httpd/NodeServer.java @@ -38,7 +38,7 @@ import org.openqa.selenium.grid.server.BaseServerFlags; import org.openqa.selenium.grid.server.BaseServerOptions; import org.openqa.selenium.grid.server.HelpFlags; -import org.openqa.selenium.grid.server.LoggingOptions; +import org.openqa.selenium.grid.log.LoggingOptions; import org.openqa.selenium.grid.server.Server; import org.openqa.selenium.grid.server.W3CCommandHandler; import org.openqa.selenium.grid.sessionmap.SessionMap; @@ -103,7 +103,9 @@ public Executable configure(String... args) { new EnvConfig(), new ConcatenatingConfig("node", '.', System.getProperties())); - DistributedTracer tracer = new LoggingOptions(config).getTracer(); + LoggingOptions loggingOptions = new LoggingOptions(config); + loggingOptions.configureLogging(); + DistributedTracer tracer = loggingOptions.getTracer(); GlobalDistributedTracer.setInstance(tracer); SessionMapOptions sessionsOptions = new SessionMapOptions(config); diff --git a/java/server/src/org/openqa/selenium/grid/node/local/AutoConfigureNode.java b/java/server/src/org/openqa/selenium/grid/node/local/AutoConfigureNode.java index 6def2b94ec7e7..56fb95302b854 100644 --- a/java/server/src/org/openqa/selenium/grid/node/local/AutoConfigureNode.java +++ b/java/server/src/org/openqa/selenium/grid/node/local/AutoConfigureNode.java @@ -34,11 +34,14 @@ import java.util.ArrayList; import java.util.List; import java.util.ServiceLoader; +import java.util.logging.Logger; import java.util.stream.Collectors; import java.util.stream.StreamSupport; public class AutoConfigureNode { + public static final Logger log = Logger.getLogger("selenium"); + public static void addSystemDrivers(LocalNode.Builder node) { // We don't expect duplicates, but they're fine @@ -55,8 +58,7 @@ public static void addSystemDrivers(LocalNode.Builder node) { Capabilities caps = info.getCanonicalCapabilities(); builders.stream() .filter(builder -> builder.score(caps) > 0) - .peek(builder -> System.err - .format("Adding %s %d times\n", caps, info.getMaximumSimultaneousSessions())) + .peek(builder -> log.info(String.format("Adding %s %d times", caps, info.getMaximumSimultaneousSessions()))) .forEach(builder -> { for (int i = 0; i < info.getMaximumSimultaneousSessions(); i++) { node.add(caps, c -> { diff --git a/java/server/src/org/openqa/selenium/grid/router/httpd/RouterServer.java b/java/server/src/org/openqa/selenium/grid/router/httpd/RouterServer.java index 214919432e961..e773b047972c2 100644 --- a/java/server/src/org/openqa/selenium/grid/router/httpd/RouterServer.java +++ b/java/server/src/org/openqa/selenium/grid/router/httpd/RouterServer.java @@ -37,7 +37,7 @@ import org.openqa.selenium.grid.server.BaseServerFlags; import org.openqa.selenium.grid.server.BaseServerOptions; import org.openqa.selenium.grid.server.HelpFlags; -import org.openqa.selenium.grid.server.LoggingOptions; +import org.openqa.selenium.grid.log.LoggingOptions; import org.openqa.selenium.grid.server.Server; import org.openqa.selenium.grid.server.W3CCommandHandler; import org.openqa.selenium.grid.sessionmap.SessionMap; @@ -97,7 +97,9 @@ public Executable configure(String... args) { new EnvConfig(), new ConcatenatingConfig("router", '.', System.getProperties())); - DistributedTracer tracer = new LoggingOptions(config).getTracer(); + LoggingOptions loggingOptions = new LoggingOptions(config); + loggingOptions.configureLogging(); + DistributedTracer tracer = loggingOptions.getTracer(); GlobalDistributedTracer.setInstance(tracer); SessionMapOptions sessionsOptions = new SessionMapOptions(config); diff --git a/java/server/src/org/openqa/selenium/grid/server/BUCK b/java/server/src/org/openqa/selenium/grid/server/BUCK index 7d5ebba87d781..0d6cfb9996a1e 100644 --- a/java/server/src/org/openqa/selenium/grid/server/BUCK +++ b/java/server/src/org/openqa/selenium/grid/server/BUCK @@ -6,13 +6,14 @@ java_library( ], exported_deps = [ "//java/server/src/org/openqa/selenium/grid/component:component", + "//java/server/src/org/openqa/selenium/grid/log:log", + "//java/server/src/org/openqa/selenium/grid/web:web", ], deps = [ "//java/client/src/org/openqa/selenium/remote:remote", "//java/client/src/org/openqa/selenium/remote/tracing:tracing", "//java/server/src/org/openqa/selenium/injector:injector", "//java/server/src/org/openqa/selenium/grid/config:config", - "//java/server/src/org/openqa/selenium/grid/web:web", "//third_party/java/beust:jcommander", "//third_party/java/guava:guava", "//third_party/java/jetty:jetty", diff --git a/java/server/src/org/openqa/selenium/grid/server/BUILD.bazel b/java/server/src/org/openqa/selenium/grid/server/BUILD.bazel index 97d9b6f9b0ef2..a1de10609437e 100644 --- a/java/server/src/org/openqa/selenium/grid/server/BUILD.bazel +++ b/java/server/src/org/openqa/selenium/grid/server/BUILD.bazel @@ -9,6 +9,9 @@ java_library( # Exported because Server implements HasLifecycle "//java/server/src/org/openqa/selenium/grid/component", + # Used by the BaseServerOptions" + "//java/server/src/org/openqa/selenium/grid/log", + # Exported because of Server.addRoute "//java/server/src/org/openqa/selenium/grid/web", ], @@ -20,6 +23,7 @@ java_library( "//java/client/src/org/openqa/selenium/remote/tracing", "//java/server/src/org/openqa/selenium/grid/component", "//java/server/src/org/openqa/selenium/grid/config", + "//java/server/src/org/openqa/selenium/grid/log", "//java/server/src/org/openqa/selenium/grid/web", "//java/server/src/org/openqa/selenium/injector", "//third_party/java/beust:jcommander", diff --git a/java/server/src/org/openqa/selenium/grid/server/BaseServerFlags.java b/java/server/src/org/openqa/selenium/grid/server/BaseServerFlags.java index 6da0c7e13030d..f5a361ec4918c 100644 --- a/java/server/src/org/openqa/selenium/grid/server/BaseServerFlags.java +++ b/java/server/src/org/openqa/selenium/grid/server/BaseServerFlags.java @@ -37,6 +37,18 @@ public class BaseServerFlags { @ConfigValue(section = "server", name = "max-threads") private int maxThreads = Runtime.getRuntime().availableProcessors() * 3; + @Parameter(description = "Configure logging", hidden = true, arity = 1) + @ConfigValue(section = "logging", name = "enable") + private boolean configureLogging = true; + + @Parameter(description = "Use structured logs", names = "--structured-logs") + @ConfigValue(section = "logging", name = "structured-logs") + private boolean structuredLogs = false; + + @Parameter(description = "Use plain log lines", names = "--plain-logs", arity = 1) + @ConfigValue(section = "logging", name = "plain-logs") + private boolean plainLogs = true; + public BaseServerFlags(int defaultPort) { this.port = defaultPort; } diff --git a/java/server/src/org/openqa/selenium/grid/server/LoggingOptions.java b/java/server/src/org/openqa/selenium/grid/server/LoggingOptions.java deleted file mode 100644 index 9b497e41ba929..0000000000000 --- a/java/server/src/org/openqa/selenium/grid/server/LoggingOptions.java +++ /dev/null @@ -1,20 +0,0 @@ -package org.openqa.selenium.grid.server; - -import org.openqa.selenium.grid.config.Config; -import org.openqa.selenium.remote.tracing.DistributedTracer; - -import java.util.Objects; - -public class LoggingOptions { - - private final Config config; - - public LoggingOptions(Config config) { - this.config = Objects.requireNonNull(config); - } - - public DistributedTracer getTracer() { - return DistributedTracer.builder().detect().build(); - } - -} diff --git a/java/server/src/org/openqa/selenium/grid/sessionmap/httpd/SessionMapServer.java b/java/server/src/org/openqa/selenium/grid/sessionmap/httpd/SessionMapServer.java index 93914ce5d821d..1f2e335c54ca8 100644 --- a/java/server/src/org/openqa/selenium/grid/sessionmap/httpd/SessionMapServer.java +++ b/java/server/src/org/openqa/selenium/grid/sessionmap/httpd/SessionMapServer.java @@ -34,7 +34,7 @@ import org.openqa.selenium.grid.server.BaseServerFlags; import org.openqa.selenium.grid.server.BaseServerOptions; import org.openqa.selenium.grid.server.HelpFlags; -import org.openqa.selenium.grid.server.LoggingOptions; +import org.openqa.selenium.grid.log.LoggingOptions; import org.openqa.selenium.grid.server.Server; import org.openqa.selenium.grid.server.W3CCommandHandler; import org.openqa.selenium.grid.sessionmap.SessionMap; @@ -86,7 +86,9 @@ public Executable configure(String... args) { new EnvConfig(), new ConcatenatingConfig("sessions", '.', System.getProperties())); - DistributedTracer tracer = new LoggingOptions(config).getTracer(); + LoggingOptions loggingOptions = new LoggingOptions(config); + loggingOptions.configureLogging(); + DistributedTracer tracer = loggingOptions.getTracer(); GlobalDistributedTracer.setInstance(tracer); SessionMap sessions = new LocalSessionMap(tracer); diff --git a/java/server/src/org/openqa/selenium/remote/server/log/BUCK b/java/server/src/org/openqa/selenium/remote/server/log/BUCK index ec15b719237a6..0e822fc555f1e 100644 --- a/java/server/src/org/openqa/selenium/remote/server/log/BUCK +++ b/java/server/src/org/openqa/selenium/remote/server/log/BUCK @@ -3,6 +3,7 @@ java_library(name = 'log', deps = [ '//java/client/src/org/openqa/selenium:selenium', '//java/client/src/org/openqa/selenium/remote:remote', + '//java/server/src/org/openqa/selenium/grid/log:log', '//third_party/java/guava:guava', ], visibility = [ diff --git a/java/server/src/org/openqa/selenium/remote/server/log/LoggingManager.java b/java/server/src/org/openqa/selenium/remote/server/log/LoggingManager.java index 0096c89511a63..11e220c4587cd 100644 --- a/java/server/src/org/openqa/selenium/remote/server/log/LoggingManager.java +++ b/java/server/src/org/openqa/selenium/remote/server/log/LoggingManager.java @@ -17,6 +17,8 @@ package org.openqa.selenium.remote.server.log; +import org.openqa.selenium.grid.log.TerseFormatter; + import java.util.logging.ConsoleHandler; import java.util.logging.Formatter; import java.util.logging.Handler;