Microservice debugging changes.

In an attempt to help determine the cause of the intermittent REST call failures in the juneau-microservice-test project, I've made some debugging enhancements to the microservice.

The test project will now generate 3 log files...

The jetty-requests.log is generated by adding this to the jetty.xml file...

<Set name="requestLog">
  <New id="RequestLogImpl" class="org.eclipse.jetty.server.NCSARequestLog">
    <Set name="filename"><Property name="jetty.logs" default="$C{Logging/logDir,logs}"/>/jetty-requests.log</Set>
    <Set name="filenameDateFormat">yyyy_MM_dd</Set>
    <Set name="LogTimeZone">GMT</Set>
    <Set name="retainDays">90</Set>
    <Set name="append">false</Set>
    <Set name="LogLatency">true</Set>
  </New>
</Set>

Note that the jetty.xml file now supports embedded Juneau variables (e.g. $C{Logging/logDir}).

I also created a separate Jetty section in the config file...

#=======================================================================================================================
# Jetty settings
#=======================================================================================================================
[Jetty]
# Path of the jetty.xml file used to configure the Jetty server.
config = jetty.xml

# Resolve Juneau variables in the jetty.xml file.
resolveVars = true

# Port to use for the jetty server.
# You can specify multiple ports. The first available will be used. '0' indicates to try a random port.
# The resulting available port gets set as the system property "availablePort" which can be referenced in the 
# jetty.xml file as "$S{availablePort}" (assuming resolveVars is enabled).
port = 10000,0,0,0

Note that we now support dynamically specifying the port again through the use of the $S{availablePort} variable.

The test.0.log file now contains the entire debug logging generated by Jetty (yea...it's big...7.8MB). I had to create a new org.apache.juneau.microservice.JettyLogger class to serve as a simple bridge between Jetty logging and java-util-logging, but it now allows all the logging to be directed to a single log file. The configuration for doing this is shown below:

[Logging]
logDir = $S{user.dir}/target/logs
logFile = test.%g.log
levels = 
  { 
    '':'WARNING', 
    org.apache.juneau: 'WARNING', 
    org.eclipse.jetty: 'FINEST' 
  }
consoleLevel = WARNING
fileLevel = FINEST


[SystemProperties]
org.eclipse.jetty.util.log.class = org.apache.juneau.microservice.JettyLogger
org.eclipse.jetty.LEVEL = ALL

The third-party-proxy-resource.txt file contains

public static FileWriter logFile;
static {
  try {
    logFile = new FileWriter("./target/logs/third-party-proxy-resource.txt", false);
  } catch (IOException e) {
    e.printStackTrace();
  }
}


@RestHook(HookEvent.START_CALL)
public static void startCall(HttpServletRequest req) {
try {
logFile.append("START["+new Date()+"]-").append(req.getQueryString()).append("\n");
logFile.flush();
} catch (IOException e) {
e.printStackTrace();
}
}


@RestHook(HookEvent.PRE_CALL)
public static void preCall(HttpServletRequest req) {
  try {
    logFile.append("PRE["+new Date()+"]-").append(req.getQueryString()).append("\n");
    logFile.flush();
  } catch (IOException e) {
    e.printStackTrace();
  }
}


@RestHook(HookEvent.POST_CALL)
public static void postCall(HttpServletRequest req) {
  try {
    logFile.append("POST["+new Date()+"]-").append(req.getQueryString()).append("\n");
    logFile.flush();
  } catch (IOException e) {
    e.printStackTrace();
  }
}


@RestHook(HookEvent.END_CALL)
public static void endCall(HttpServletRequest req) {
  try {
    Exception e = (Exception)req.getAttribute("Exception");
    Long execTime = (Long)req.getAttribute("ExecTime");
    logFile.append("END["+new Date()+"]-").append(req.getQueryString()).append(", time=").append(""+execTime).append(", exception=").append(e == null ? null : e.toString()).append("\n");
    logFile.flush();
  } catch (IOException e) {
    e.printStackTrace();
  }
}

Space shortcuts

Blog