Skip to content

Commit

Permalink
Allow logs to be output in single-line json format to stdout
Browse files Browse the repository at this point in the history
  • Loading branch information
shs96c committed Nov 27, 2018
1 parent 8a7e3a2 commit 988667f
Show file tree
Hide file tree
Showing 20 changed files with 225 additions and 37 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down
6 changes: 4 additions & 2 deletions java/server/src/org/openqa/selenium/grid/commands/Hub.java
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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 {
Expand Down Expand Up @@ -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);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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);
Expand Down
13 changes: 13 additions & 0 deletions java/server/src/org/openqa/selenium/grid/log/BUCK
Original file line number Diff line number Diff line change
@@ -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/...",
],
)
13 changes: 13 additions & 0 deletions java/server/src/org/openqa/selenium/grid/log/BUILD.bazel
Original file line number Diff line number Diff line change
@@ -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__",
],
)
37 changes: 37 additions & 0 deletions java/server/src/org/openqa/selenium/grid/log/FlushingHandler.java
Original file line number Diff line number Diff line change
@@ -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();
}
}
}
45 changes: 45 additions & 0 deletions java/server/src/org/openqa/selenium/grid/log/JsonFormatter.java
Original file line number Diff line number Diff line change
@@ -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<String, Object> 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();
}
}
62 changes: 62 additions & 0 deletions java/server/src/org/openqa/selenium/grid/log/LoggingOptions.java
Original file line number Diff line number Diff line change
@@ -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<String> 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);
}
}

}
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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 -> {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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);
Expand Down
3 changes: 2 additions & 1 deletion java/server/src/org/openqa/selenium/grid/server/BUCK
Original file line number Diff line number Diff line change
Expand Up @@ -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",
Expand Down
4 changes: 4 additions & 0 deletions java/server/src/org/openqa/selenium/grid/server/BUILD.bazel
Original file line number Diff line number Diff line change
Expand Up @@ -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",
],
Expand All @@ -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",
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
}
Expand Down

0 comments on commit 988667f

Please sign in to comment.