Prefix log messages from nodes running as separate processes with the node name

acceptance-tests/src/test/java/tech/pegasys/pantheon/tests/acceptance/dsl/node/ProcessPantheonNodeRunner.java

@@ -18,8 +18,11 @@
 import tech.pegasys.pantheon.ethereum.jsonrpc.RpcApi;
 import tech.pegasys.pantheon.ethereum.jsonrpc.RpcApis;
 
+import java.io.BufferedReader;
 import java.io.File;
 import java.io.IOException;
+import java.io.InputStreamReader;
+import java.lang.ProcessBuilder.Redirect;
 import java.net.URI;
 import java.nio.file.Files;
 import java.nio.file.Path;
@@ -28,6 +31,8 @@
 import java.util.HashMap;
 import java.util.List;
 import java.util.Map;
+import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
 import java.util.concurrent.TimeUnit;
 import java.util.stream.Collectors;
 
@@ -38,8 +43,10 @@
 public class ProcessPantheonNodeRunner implements PantheonNodeRunner {
 
   private final Logger LOG = LogManager.getLogger();
+  private final Logger PROCESS_LOG = LogManager.getLogger("tech.pegasys.pantheon.SubProcessLog");
 
   private final Map<String, Process> pantheonProcesses = new HashMap<>();
+  private final ExecutorService outputProcessorExecutor = Executors.newCachedThreadPool();
 
   ProcessPantheonNodeRunner() {
     Runtime.getRuntime().addShutdownHook(new Thread(this::shutdown));
@@ -157,10 +164,12 @@ public void startNode(final PantheonNode node) {
     final ProcessBuilder processBuilder =
         new ProcessBuilder(params)
             .directory(new File(System.getProperty("user.dir")).getParentFile())
-            .inheritIO();
+            .redirectErrorStream(true)
+            .redirectInput(Redirect.INHERIT);
 
     try {
       final Process process = processBuilder.start();
+      outputProcessorExecutor.submit(() -> printOutput(node, process));
       pantheonProcesses.put(node.getName(), process);
     } catch (final IOException e) {
       LOG.error("Error starting PantheonNode process", e);
@@ -169,6 +178,19 @@ public void startNode(final PantheonNode node) {
     waitForPortsFile(dataDir);
   }
 
+  private void printOutput(final PantheonNode node, final Process process) {
+    try (final BufferedReader in =
+        new BufferedReader(new InputStreamReader(process.getInputStream(), UTF_8))) {
+      String line = in.readLine();
+      while (line != null) {
+        PROCESS_LOG.info("{}: {}", node.getName(), line);
+        line = in.readLine();
+      }
+    } catch (final IOException e) {
+      LOG.error("Failed to read output from process", e);
+    }
+  }
+
   private Path createGenesisFile(final PantheonNode node, final EthNetworkConfig ethNetworkConfig) {
     try {
       final Path genesisFile = Files.createTempFile(node.homeDirectory(), "genesis", "");
@@ -197,6 +219,15 @@ public void stopNode(final PantheonNode node) {
   public synchronized void shutdown() {
     final HashMap<String, Process> localMap = new HashMap<>(pantheonProcesses);
     localMap.forEach(this::killPantheonProcess);
+    outputProcessorExecutor.shutdown();
+    try {
+      if (!outputProcessorExecutor.awaitTermination(5, TimeUnit.SECONDS)) {
+        LOG.error("Output processor executor did not shutdown cleanly.");
+      }
+    } catch (final InterruptedException e) {
+      LOG.error("Interrupted while already shutting down", e);
+      Thread.currentThread().interrupt();
+    }
   }
 
   @Override

acceptance-tests/src/test/resources/log4j2.xml

@@ -7,8 +7,14 @@
     <Console name="Console" target="SYSTEM_OUT">
       <PatternLayout pattern="%d{HH:mm:ss.SSS} | %t | %-5level | %c{1} | %msg%n" />
     </Console>
+    <Console name="SubProcessConsole" target="SYSTEM_OUT">
+      <PatternLayout pattern="Process %msg%n" />
+    </Console>
   </Appenders>
   <Loggers>
+    <Logger name="tech.pegasys.pantheon.SubProcessLog" level="INFO" additivity="false">
+      <AppenderRef ref="SubProcessConsole" />
+    </Logger>
     <Root level="${sys:root.log.level}">
       <AppenderRef ref="Console" />
     </Root>

ethereum/p2p/src/main/java/tech/pegasys/pantheon/ethereum/p2p/discovery/PeerDiscoveryAgent.java

@@ -201,13 +201,6 @@ protected void handleIncomingPacket(final Endpoint sourceEndpoint, final Packet
    * @param packet the packet to send
    */
   protected void handleOutgoingPacket(final DiscoveryPeer peer, final Packet packet) {
-    LOG.trace(
-        ">>> Sending {} discovery packet to {} ({}): {}",
-        packet.getType(),
-        peer.getEndpoint(),
-        peer.getId().slice(0, 16),
-        packet);
-
     sendOutgoingPacket(peer, packet)
         .whenComplete(
             (res, err) -> {

ethereum/p2p/src/main/java/tech/pegasys/pantheon/ethereum/p2p/discovery/internal/DiscoveryProtocolLogger.java

@@ -23,7 +23,7 @@ public class DiscoveryProtocolLogger {
 
   static void logSendingPacket(final Peer peer, final Packet packet) {
     LOG.trace(
-        "<<< Sending  {} packet from peer {} ({}): {}",
+        "<<< Sending  {} packet to peer {} ({}): {}",
         shortenPacketType(packet),
         peer.getId().slice(0, 16),
         peer.getEndpoint(),