Add debug logging to CLI

hapi-fhir-cli/hapi-fhir-cli-api/src/main/java/ca/uhn/fhir/cli/BaseApp.java

@@ -25,7 +25,11 @@ import ch.qos.logback.classic.LoggerContext;
 import ch.qos.logback.classic.joran.JoranConfigurator;
 import ch.qos.logback.core.joran.spi.JoranException;
 import com.helger.commons.io.file.FileHelper;
-import org.apache.commons.cli.*;
+import org.apache.commons.cli.CommandLine;
+import org.apache.commons.cli.DefaultParser;
+import org.apache.commons.cli.HelpFormatter;
+import org.apache.commons.cli.Options;
+import org.apache.commons.cli.ParseException;
 import org.apache.commons.lang3.StringUtils;
 import org.apache.commons.text.WordUtils;
 import org.fusesource.jansi.Ansi;
@@ -43,11 +47,12 @@ import static org.fusesource.jansi.Ansi.ansi;
 
 @SuppressWarnings("WeakerAccess")
 public abstract class BaseApp {
+	protected static final org.slf4j.Logger ourLog;
+	static final String LINESEP = System.getProperty("line.separator");
 	private static final String STACKFILTER_PATTERN = "%xEx{full, sun.reflect, org.junit, org.eclipse, java.lang.reflect.Method, org.springframework, org.hibernate, com.sun.proxy, org.attoparser, org.thymeleaf}";
 	private static final String STACKFILTER_PATTERN_PROP = "log.stackfilter.pattern";
-	static final String LINESEP = System.getProperty("line.separator");
-	protected static final org.slf4j.Logger ourLog;
 	private static List<BaseCommand> ourCommands;
+	private static boolean ourDebugMode;
 
 	static {
 		System.setProperty(STACKFILTER_PATTERN_PROP, STACKFILTER_PATTERN);
@@ -115,13 +120,19 @@ public abstract class BaseApp {
 		System.out.println("Options:");
 		HelpFormatter fmt = new HelpFormatter();
 		PrintWriter pw = new PrintWriter(System.out);
-		fmt.printOptions(pw, columns, theCommand.getOptions(), 2, 2);
+		fmt.printOptions(pw, columns, getOptions(theCommand), 2, 2);
 		pw.flush();
 
 		// That's it!
 		System.out.println();
 	}
 
+	private Options getOptions(BaseCommand theCommand) {
+		Options options = theCommand.getOptions();
+		options.addOption(null, "debug", false, "Enable debug mode");
+		return options;
+	}
+
 	private void logUsage() {
 		logAppHeader();
 		System.out.println("Usage:");
@@ -232,7 +243,7 @@ public abstract class BaseApp {
 		myShutdownHook = new MyShutdownHook(command);
 		Runtime.getRuntime().addShutdownHook(myShutdownHook);
 
-		Options options = command.getOptions();
+		Options options = getOptions(command);
 		DefaultParser parser = new DefaultParser();
 		CommandLine parsedOptions;
 
@@ -247,6 +258,11 @@ public abstract class BaseApp {
 				throw new ParseException("Unrecognized argument: " + parsedOptions.getArgList().get(0));
 			}
 
+			if (parsedOptions.hasOption("debug")) {
+				loggingConfigOnDebug();
+				ourDebugMode = true;
+			}
+
 			// Actually execute the command
 			command.run(parsedOptions);
 
@@ -290,7 +306,7 @@ public abstract class BaseApp {
 	private void exitDueToException(Throwable e) {
 		if ("true".equals(System.getProperty("test"))) {
 			if (e instanceof CommandFailureException) {
-				throw (CommandFailureException)e;
+				throw (CommandFailureException) e;
 			}
 			throw new Error(e);
 		} else {
@@ -316,6 +332,24 @@ public abstract class BaseApp {
 		}
 	}
 
+	private class MyShutdownHook extends Thread {
+		private final BaseCommand myFinalCommand;
+
+		MyShutdownHook(BaseCommand theFinalCommand) {
+			myFinalCommand = theFinalCommand;
+		}
+
+		@Override
+		public void run() {
+			ourLog.info(provideProductName() + " is shutting down...");
+			myFinalCommand.cleanup();
+		}
+	}
+
+	public static boolean isDebugMode() {
+		return ourDebugMode;
+	}
+
 	private static void loggingConfigOff() {
 		try {
 			JoranConfigurator configurator = new JoranConfigurator();
@@ -337,18 +371,16 @@ public abstract class BaseApp {
 		}
 	}
 
-
+	private static void loggingConfigOnDebug() {
-	private class MyShutdownHook extends Thread {
+		try {
-		private final BaseCommand myFinalCommand;
+			JoranConfigurator configurator = new JoranConfigurator();
-
+			configurator.setContext((LoggerContext) LoggerFactory.getILoggerFactory());
-		MyShutdownHook(BaseCommand theFinalCommand) {
+			((LoggerContext) LoggerFactory.getILoggerFactory()).reset();
-			myFinalCommand = theFinalCommand;
+			configurator.doConfigure(App.class.getResourceAsStream("/logback-cli-on-debug.xml"));
+		} catch (JoranException e) {
+			e.printStackTrace();
 		}
 
-		@Override
+		ourLog.info("Debug logging is enabled");
-		public void run() {
-			ourLog.info(provideProductName() + " is shutting down...");
-			myFinalCommand.cleanup();
-		}
 	}
 }

hapi-fhir-cli/hapi-fhir-cli-api/src/main/resources/logback-cli-on-debug.xml

@@ -0,0 +1,38 @@
+<configuration>
+
+	<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
+		<useJansi>true</useJansi>
+		<encoder>
+			<pattern>%green(%d{yyyy-MM-dd}) %boldGreen(%d{HH:mm:ss.SS}) %white([%thread] [%file:%line]) %white(%-5level) %boldBlue(%logger{20}) %boldWhite(%msg%n)
+			</pattern>
+		</encoder>
+	</appender>
+
+	<logger name="ca.uhn.fhir" additivity="false" level="debug">
+		<appender-ref ref="STDOUT" />
+	</logger>
+	<logger name="ca.cdr" additivity="false" level="debug">
+		<appender-ref ref="STDOUT" />
+	</logger>
+
+	<!-- These two are used by the websocket client -->
+	<logger name="websocket.RECV" additivity="false" level="info">
+		<appender-ref ref="STDOUT" />
+	</logger>
+	<logger name="websocket.SEND" additivity="false" level="info">
+		<appender-ref ref="STDOUT" />
+	</logger>
+
+	<!-- These two are used by SynchronizeFhirServersCommand -->
+	<logger name="sync.SOURCE" additivity="false" level="info">
+		<appender-ref ref="STDOUT" />
+	</logger>
+	<logger name="sync.TARGET" additivity="false" level="info">
+		<appender-ref ref="STDOUT" />
+	</logger>
+
+	<root level="warn">
+		<appender-ref ref="STDOUT" />
+	</root>
+
+</configuration>

hapi-fhir-docs/src/main/resources/ca/uhn/hapi/fhir/docs/tools/hapi_fhir_cli.md

@@ -38,6 +38,9 @@ java version "1.8.0_60"
 Java(TM) SE Runtime Environment (build 1.8.0_60-b27)
 Java HotSpot(TM) 64-Bit Server VM (build 25.60-b23, mixed mode)
 ```
+
+Individual commands can be troubleshooted by adding the `--debug` command line argument.
+
 If this does not help, please post a question on our [Google Group](https://groups.google.com/d/forum/hapi-fhir).
 
 # Server (run-server)