#339 Logger in RequestDispatcher generates two separate log lines on exception (5XX response)

Author: Igor Polevoy

activeweb/src/main/java/org/javalite/activeweb/RequestDispatcher.java

@@ -284,11 +284,6 @@ private void renderSystemError(String template, String layout, int status, Throw
 
             logDone(e);
 
-            if(status >= 500){
-                logger.error("ERROR!", e);
-            }
-
-
             HttpServletRequest req = RequestContext.getHttpRequest();
             String requestedWith = req.getHeader("x-requested-with") == null ?
                     req.getHeader("X-Requested-With") : req.getHeader("x-requested-with");
@@ -337,10 +332,15 @@ private void logDone(Throwable throwable) {
                 + "\",\"action\":\"" + action
                 + "\",\"duration_millis\":" + millis
                 + ",\"method\":\"" + method
-                + ",\"url\":\"" + url
+                + "\",\"url\":\"" + url
                 + (throwable != null ? "\",\"error\":\"" + JsonHelper.sanitize(throwable.getMessage() != null ? throwable.getMessage() : throwable.toString()) : "")
                 + "\",\"status\":" + status + "}";
-        logger.info(log);
+
+        if(throwable != null && status >= 500){
+            logger.error(log, throwable);
+        }else {
+            logger.info(log);
+        }
     }
 
     public void destroy() {

activeweb/src/test/java/org/javalite/activeweb/controller_filters/JSONLogSpec.java

@@ -78,7 +78,6 @@ public void shouldPrintControllerException() throws IOException, ServletExceptio
         Map log0 = JsonHelper.toMap(logs[0]);
         the(log0.get("level")).shouldBeEqual("INFO");
         the(log0.get("logger")).shouldBeEqual("org.javalite.activeweb.RequestDispatcher");
-
         Map message = (Map) log0.get("message");
         the(message.get("info")).shouldBeEqual("executing controller");
         the(message.get("controller")).shouldBeEqual("app.controllers.LoggingController");
@@ -87,33 +86,24 @@ public void shouldPrintControllerException() throws IOException, ServletExceptio
 
         //Line 1
         Map log1 = JsonHelper.toMap(logs[1]);
-        the(log1.get("level")).shouldBeEqual("INFO");
+        the(log1.get("level")).shouldBeEqual("ERROR");
         the(log1.get("timestamp")).shouldNotBeNull();
         the(log1.get("logger")).shouldBeEqual("org.javalite.activeweb.RequestDispatcher");
-
         message = (Map) log1.get("message");
         the(message.get("controller")).shouldBeEqual("app.controllers.LoggingController");
         the(message.get("duration_millis")).shouldNotBeNull();
         the(message.get("method")).shouldBeEqual("GET");
         the(message.get("status")).shouldBeEqual(500);
+        Map exception = (Map) log1.get("exception");
+        the(exception.get("message")).shouldBeEqual("blah!");
+        the(exception.get("stacktrace")).shouldContain("java.lang.RuntimeException: blah!\njava.lang.RuntimeException: blah!\n\tat app.controllers.LoggingController.error");
 
         //Line 2
         Map log2 = JsonHelper.toMap(logs[2]);
-        the(log2.get("level")).shouldBeEqual("ERROR");
+        the(log2.get("level")).shouldBeEqual("INFO");
         the(log2.get("timestamp")).shouldNotBeNull();
-        the(log2.get("logger")).shouldBeEqual("org.javalite.activeweb.RequestDispatcher");
-        the(log2.get("message")).shouldBeEqual("ERROR!");
-
-        Map exception = (Map) log2.get("exception");
-        the(exception.get("message")).shouldBeEqual("blah!");
-        the(exception.get("stacktrace")).shouldContain("java.lang.RuntimeException: blah!\njava.lang.RuntimeException: blah!\n\tat app.controllers.LoggingController.error");
-
-        //Line 3
-        Map log3 = JsonHelper.toMap(logs[3]);
-        the(log3.get("level")).shouldBeEqual("INFO");
-        the(log3.get("timestamp")).shouldNotBeNull();
-        the(log3.get("logger")).shouldBeEqual("org.javalite.activeweb.freemarker.FreeMarkerTemplateManager");
-        the(log3.get("message")).shouldBeEqual("rendering template: '/system/error' with layout: '/layouts/default_layout");
+        the(log2.get("logger")).shouldBeEqual("org.javalite.activeweb.freemarker.FreeMarkerTemplateManager");
+        the(log2.get("message")).shouldBeEqual("rendering template: '/system/error' with layout: '/layouts/default_layout");
     }
 
     @Test