More verbose logging to debug failures (refs #110) (#111)

src/main/java/ru/yandex/qatools/embed/postgresql/InitDbProcess.java

@@ -1,17 +1,17 @@
 /**
  * Copyright (C) 2011
- *   Michael Mosmann <[email protected]>
- *   Martin Jöhren <[email protected]>
- *
+ * Michael Mosmann <[email protected]>
+ * Martin Jöhren <[email protected]>
+ * <p>
  * with contributions from
- * 	konstantin-ba@github, Archimedes Trajano (trajano@github), Christian Bayer ([email protected])
- *
+ * konstantin-ba@github, Archimedes Trajano (trajano@github), Christian Bayer ([email protected])
+ * <p>
  * Licensed under the Apache License, Version 2.0 (the "License");
  * you may not use this file except in compliance with the License.
  * You may obtain a copy of the License at
- *
- *         http://www.apache.org/licenses/LICENSE-2.0
- *
+ * <p>
+ * http://www.apache.org/licenses/LICENSE-2.0
+ * <p>
  * Unless required by applicable law or agreed to in writing, software
  * distributed under the License is distributed on an "AS IS" BASIS,
  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
@@ -25,29 +25,32 @@
 import de.flapdoodle.embed.process.distribution.Distribution;
 import de.flapdoodle.embed.process.distribution.Platform;
 import de.flapdoodle.embed.process.extract.IExtractedFileSet;
-import de.flapdoodle.embed.process.io.LogWatchStreamProcessor;
 import de.flapdoodle.embed.process.io.Processors;
 import de.flapdoodle.embed.process.io.StreamToLineProcessor;
 import de.flapdoodle.embed.process.io.file.Files;
 import de.flapdoodle.embed.process.runtime.ProcessControl;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
 import ru.yandex.qatools.embed.postgresql.config.PostgresConfig;
+import ru.yandex.qatools.embed.postgresql.ext.LogWatchStreamProcessor;
 import ru.yandex.qatools.embed.postgresql.ext.SubdirTempDir;
 
 import java.io.File;
 import java.io.IOException;
 import java.util.ArrayList;
-import java.util.HashSet;
 import java.util.List;
 
 import static de.flapdoodle.embed.process.io.file.Files.createTempFile;
 import static java.util.Arrays.asList;
+import static java.util.Collections.singleton;
 import static java.util.UUID.randomUUID;
 
 /**
  * initdb process
  * (helper to initialize the DB)
  */
 class InitDbProcess<E extends InitDbExecutable> extends AbstractPGProcess<E, InitDbProcess> {
+    private static final Logger LOGGER = LoggerFactory.getLogger(InitDbProcess.class);
 
     public InitDbProcess(Distribution distribution, PostgresConfig config, IRuntimeConfig runtimeConfig, E executable) throws IOException {
         super(distribution, config, runtimeConfig, executable);
@@ -80,10 +83,10 @@ protected List<String> getCommandLine(Distribution distribution, PostgresConfig
 
     @Override
     protected void onAfterProcessStart(ProcessControl process, IRuntimeConfig runtimeConfig) throws IOException {
-        ProcessOutput outputConfig = runtimeConfig.getProcessOutput();
-        LogWatchStreamProcessor logWatch = new LogWatchStreamProcessor(
-                "database system is ready to accept connections",
-                new HashSet<>(asList("[initdb error]")), StreamToLineProcessor.wrap(outputConfig.getOutput()));
+        final ProcessOutput outputConfig = runtimeConfig.getProcessOutput();
+        final LogWatchStreamProcessor logWatch = new LogWatchStreamProcessor(
+                "performing post-bootstrap initialization",
+                singleton("[initdb error]"), StreamToLineProcessor.wrap(outputConfig.getOutput()));
         Processors.connect(process.getReader(), logWatch);
         Processors.connect(process.getError(), StreamToLineProcessor.wrap(outputConfig.getError()));
         logWatch.waitForResult(getConfig().timeout().startupTimeout());

src/main/java/ru/yandex/qatools/embed/postgresql/PostgresProcess.java

@@ -118,6 +118,9 @@ private static String runCmd(boolean silent,
                     .prepare(postgresConfig);
             AbstractPGProcess proc = exec.start();
             logWatch.waitForResult(DEFAULT_CMD_TIMEOUT);
+            if (!logWatch.isInitWithSuccess() && !silent) {
+                LOGGER.warn("Possibly failed to run {}:\n{}", cmd.commandName(), logWatch.getOutput());
+            }
             proc.waitFor();
             return logWatch.getOutput();
         } catch (IOException | InterruptedException e) {
@@ -190,8 +193,7 @@ protected void onBeforeProcess(IRuntimeConfig runtimeConfig)
             return;
         }
 
-        runCmd(config, runtimeConfig, InitDb,
-                "Success. You can now start the database server using", emptySet());
+        runCmd(config, runtimeConfig, InitDb, "Success", singleton("[initdb error]"));
     }
 
     @Override

src/main/java/ru/yandex/qatools/embed/postgresql/ext/LogWatchStreamProcessor.java

@@ -6,7 +6,7 @@
 
 import java.util.Set;
 
-import static org.apache.commons.lang3.StringUtils.isEmpty;
+import static java.util.Optional.ofNullable;
 
 /**
  * @author Ilya Sadykov
@@ -18,18 +18,20 @@ public class LogWatchStreamProcessor extends de.flapdoodle.embed.process.io.LogW
     private final String success;
     private final Set<String> failures;
     private volatile boolean found = false;
+    private volatile boolean initWithSuccess = false;
 
     public LogWatchStreamProcessor(String success, Set<String> failures, IStreamProcessor destination) {
         super(success, failures, destination);
-        this.success = success;
+        this.success = ofNullable(success).orElse("");
         this.failures = failures;
     }
 
     @Override
     public void process(String block) {
         LOGGER.debug(block);
         output.append(block).append("\n");
-        if (containsSuccess(block) || containsFailure(block)) {
+        initWithSuccess = containsSuccess(block);
+        if (initWithSuccess || containsFailure(block)) {
             synchronized (mutex) {
                 found = true;
                 mutex.notifyAll();
@@ -52,21 +54,27 @@ private boolean containsFailure(String block) {
         return false;
     }
 
+    @Override
     public void waitForResult(long timeout) {
         synchronized (mutex) {
             try {
                 if (!found) {
                     mutex.wait(timeout);
                 }
             } catch (InterruptedException e) {
+                LOGGER.error("Failed to wait for the result: '{}' not found in: \n{}", success, output);
                 e.printStackTrace();
             }
         }
     }
 
+    @Override
+    public boolean isInitWithSuccess() {
+        return initWithSuccess || getOutput().contains(success);
+    }
+
     @Override
     public String getOutput() {
-        String res = output.toString();
-        return isEmpty(res) ? null : res;
+        return output.toString();
     }
 }