Repository: vert-x3/vertx-web
Issue: Server eats exception and simply responds 500

### Description

Server log doesn't contain any info about NPE error. I think it happens for other errors too.

### Version

4.0.3

### Code sample

```
    final HttpServer server = vertx
        .createHttpServer(
            new HttpServerOptions()
                .setLogActivity(true)
        );

    final Router router = Router.router(vertx);

    router
        .route()
        .handler(ResponseContentTypeHandler.create());

    router
        .get("/somepath")
        .produces("text/xml")
        .handler(ctx -> {
              final String foo = context.get("foo").toString();
              ctx.response().end();
        });

    server
        .requestHandler(router)
        .listen(8080)
        .onSuccess(s -> System.out.format(
            "HTTP server is listening on port %s.",
            s.actualPort()));
```

### Log sample

```
HTTP server is listening on port 8080.
14:06:09.544 [vert.x-eventloop-thread-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.maxCapacityPerThread: 4096
14:06:09.544 [vert.x-eventloop-thread-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.maxSharedCapacityFactor: 2
14:06:09.544 [vert.x-eventloop-thread-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.linkCapacity: 16
14:06:09.544 [vert.x-eventloop-thread-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.ratio: 8
14:06:09.544 [vert.x-eventloop-thread-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.delayedQueue.ratio: 8
14:06:09.550 [vert.x-eventloop-thread-1] DEBUG io.netty.buffer.AbstractByteBuf - -Dio.netty.buffer.checkAccessible: true
14:06:09.550 [vert.x-eventloop-thread-1] DEBUG io.netty.buffer.AbstractByteBuf - -Dio.netty.buffer.checkBounds: true
14:06:09.551 [vert.x-eventloop-thread-1] DEBUG io.netty.util.ResourceLeakDetectorFactory - Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@6f856194
14:06:09.588 [vert.x-eventloop-thread-1] DEBUG io.netty.handler.logging.LoggingHandler - [id: 0xc962bfb4, L:/[0:0:0:0:0:0:0:1]:8080 - R:/[0:0:0:0:0:0:0:1]:50225] READ: 86B
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 47 45 54 20 2f 73 6f 6d 65 70 61 74 68 20 48 54 |GET /somepath HT|
|00000010| 54 50 2f 31 2e 31 0d 0a 48 6f 73 74 3a 20 6c 6f |TP/1.1..Host: lo|
|00000020| 63 61 6c 68 6f 73 74 3a 38 30 38 30 0d 0a 55 73 |calhost:8080..Us|
|00000030| 65 72 2d 41 67 65 6e 74 3a 20 63 75 72 6c 2f 37 |er-Agent: curl/7|
|00000040| 2e 36 34 2e 31 0d 0a 41 63 63 65 70 74 3a 20 2a |.64.1..Accept: *|
|00000050| 2f 2a 0d 0a 0d 0a                               |/*....          |
+--------+-------------------------------------------------+----------------+
14:06:09.614 [vert.x-eventloop-thread-1] DEBUG io.netty.handler.codec.compression.ZlibCodecFactory - -Dio.netty.noJdkZlibDecoder: false
14:06:09.614 [vert.x-eventloop-thread-1] DEBUG io.netty.handler.codec.compression.ZlibCodecFactory - -Dio.netty.noJdkZlibEncoder: false
14:06:09.634 [vert.x-eventloop-thread-1] DEBUG io.netty.handler.logging.LoggingHandler - [id: 0xc962bfb4, L:/[0:0:0:0:0:0:0:1]:8080 - R:/[0:0:0:0:0:0:0:1]:50225] WRITE: 103B
         +-------------------------------------------------+
         |  0  1  2  3  4  5  6  7  8  9  a  b  c  d  e  f |
+--------+-------------------------------------------------+----------------+
|00000000| 48 54 54 50 2f 31 2e 31 20 35 30 30 20 49 6e 74 |HTTP/1.1 500 Int|
|00000010| 65 72 6e 61 6c 20 53 65 72 76 65 72 20 45 72 72 |ernal Server Err|
|00000020| 6f 72 0d 0a 63 6f 6e 74 65 6e 74 2d 6c 65 6e 67 |or..content-leng|
|00000030| 74 68 3a 20 32 31 0d 0a 63 6f 6e 74 65 6e 74 2d |th: 21..content-|
|00000040| 74 79 70 65 3a 20 74 65 78 74 2f 78 6d 6c 0d 0a |type: text/xml..|
|00000050| 0d 0a 49 6e 74 65 72 6e 61 6c 20 53 65 72 76 65 |..Internal Serve|
|00000060| 72 20 45 72 72 6f 72                            |r Error         |
+--------+-------------------------------------------------+----------------+
14:06:09.635 [vert.x-eventloop-thread-1] DEBUG io.netty.handler.logging.LoggingHandler - [id: 0xc962bfb4, L:/[0:0:0:0:0:0:0:1]:8080 - R:/[0:0:0:0:0:0:0:1]:50225] READ COMPLETE
14:06:09.635 [vert.x-eventloop-thread-1] DEBUG io.netty.handler.logging.LoggingHandler - [id: 0xc962bfb4, L:/[0:0:0:0:0:0:0:1]:8080 - R:/[0:0:0:0:0:0:0:1]:50225] FLUSH
14:06:09.637 [vert.x-eventloop-thread-1] DEBUG io.netty.handler.logging.LoggingHandler - [id: 0xc962bfb4, L:/[0:0:0:0:0:0:0:1]:8080 - R:/[0:0:0:0:0:0:0:1]:50225] READ COMPLETE
14:06:09.640 [vert.x-eventloop-thread-1] DEBUG io.netty.handler.logging.LoggingHandler - [id: 0xc962bfb4, L:/[0:0:0:0:0:0:0:1]:8080 ! R:/[0:0:0:0:0:0:0:1]:50225] INACTIVE
14:06:09.640 [vert.x-eventloop-thread-1] DEBUG io.netty.handler.logging.LoggingHandler - [id: 0xc962bfb4, L:/[0:0:0:0:0:0:0:1]:8080 ! R:/[0:0:0:0:0:0:0:1]:50225] UNREGISTERED
14:06:15.228 [vert.x-eventloop-thread-1] DEBUG io.netty.buffer.PoolThreadCache - Freed 2 thread-local buffer(s) from thread: vert.x-eventloop-thread-1
```

Changed files:
vertx-web/src/test/java/io/vertx/ext/web/handler/BodyHandlerTest.java, vertx-web/src/main/java/io/vertx/ext/web/impl/RoutingContextImplBase.java

diff --git a/vertx-web/src/main/java/io/vertx/ext/web/impl/RoutingContextImplBase.java b/vertx-web/src/main/java/io/vertx/ext/web/impl/RoutingContextImplBase.java
index c7e87fce0..4432edcb6 100644
--- a/vertx-web/src/main/java/io/vertx/ext/web/impl/RoutingContextImplBase.java
+++ b/vertx-web/src/main/java/io/vertx/ext/web/impl/RoutingContextImplBase.java
@@ -180,9 +180,6 @@ public abstract class RoutingContextImplBase implements RoutingContextInternal {
   }
 
   private void handleInHandlerRuntimeFailure(RouterImpl router, boolean failed, Throwable t) {
-    if (LOG.isTraceEnabled()) {
-      LOG.trace("Throwable thrown from handler", t);
-    }
     if (!failed) {
       if (LOG.isTraceEnabled()) {
         LOG.trace("Failing the routing");
@@ -199,6 +196,8 @@ public abstract class RoutingContextImplBase implements RoutingContextInternal {
 
 
   protected void unhandledFailure(int statusCode, Throwable failure, RouterImpl router) {
+    LOG.error("Unhandled exception in router", failure);
+
     int code = statusCode != -1 ?
       statusCode :
       (failure instanceof HttpException) ?
diff --git a/vertx-web/src/test/java/io/vertx/ext/web/handler/BodyHandlerTest.java b/vertx-web/src/test/java/io/vertx/ext/web/handler/BodyHandlerTest.java
index 79da1fc79..9fdb3e145 100644
--- a/vertx-web/src/test/java/io/vertx/ext/web/handler/BodyHandlerTest.java
+++ b/vertx-web/src/test/java/io/vertx/ext/web/handler/BodyHandlerTest.java
@@ -115,7 +115,7 @@ public class BodyHandlerTest extends WebTestBase {
       req.setChunked(true);
       req.putHeader("content-type", "text/plain;charset=ISO-8859-1");
       byte b = str.getBytes(StandardCharsets.ISO_8859_1)[0];
-      req.write(Buffer.buffer(new byte[] { b }));
+      req.write(Buffer.buffer(new byte[]{b}));
     }, 200, "OK", null);
   }
 
@@ -315,20 +315,20 @@ public class BodyHandlerTest extends WebTestBase {
 
   @Test
   public void testFileDeleteOnLargeUpload() throws Exception {
-      String uploadsDirectory = tempUploads.newFolder().getPath();
-      router.clear();
-      router.route().handler(BodyHandler.create()
-        .setDeleteUploadedFilesOnEnd(true)
-        .setBodyLimit(10000)
-        .setUploadsDirectory(uploadsDirectory));
-      router.route().handler(ctx -> {
-        fail();
-        ctx.fail(500);
-      });
+    String uploadsDirectory = tempUploads.newFolder().getPath();
+    router.clear();
+    router.route().handler(BodyHandler.create()
+      .setDeleteUploadedFilesOnEnd(true)
+      .setBodyLimit(10000)
+      .setUploadsDirectory(uploadsDirectory));
+    router.route().handler(ctx -> {
+      fail();
+      ctx.fail(500);
+    });
 
-      sendFileUploadRequest(TestUtils.randomBuffer(20000), 413, "Request Entity Too Large");
+    sendFileUploadRequest(TestUtils.randomBuffer(20000), 413, "Request Entity Too Large");
 
-      assertWaitUntil(() -> vertx.fileSystem().readDirBlocking(uploadsDirectory).isEmpty());
+    assertWaitUntil(() -> vertx.fileSystem().readDirBlocking(uploadsDirectory).isEmpty());
   }
 
   @Test
@@ -392,8 +392,8 @@ public class BodyHandlerTest extends WebTestBase {
     String uploadsDirectory = tempUploads.newFolder().getPath();
     router.clear();
     router.route().handler(BodyHandler.create()
-            .setDeleteUploadedFilesOnEnd(deletedUploadedFilesOnEnd)
-            .setUploadsDirectory(uploadsDirectory));
+      .setDeleteUploadedFilesOnEnd(deletedUploadedFilesOnEnd)
+      .setUploadsDirectory(uploadsDirectory));
     router.route().handler(requestHandler);
 
     sendFileUploadRequest(TestUtils.randomBuffer(50), statusCode, statusMessage);
@@ -500,13 +500,13 @@ public class BodyHandlerTest extends WebTestBase {
 
       for (int i = 0; i < uploads; i++) {
         String header =
-            "--" + boundary + "\\r\\n" +
-                "Content-Disposition: form-data; name=\\"file" + i + "\\"; filename=\\"file" + i + "\\"\\r\\n" +
-                "Content-Type: application/octet-stream\\r\\n" +
-                "Content-Transfer-Encoding: binary\\r\\n" +
-                "\\r\\n";
+          "--" + boundary + "\\r\\n" +
+            "Content-Disposition: form-data; name=\\"file" + i + "\\"; filename=\\"file" + i + "\\"\\r\\n" +
+            "Content-Type: application/octet-stream\\r\\n" +
+            "Content-Transfer-Encoding: binary\\r\\n" +
+            "\\r\\n";
         buffer.appendString(header);
-        buffer.appendBuffer(TestUtils.randomBuffer(4096*16));
+        buffer.appendBuffer(TestUtils.randomBuffer(4096 * 16));
         buffer.appendString("\\r\\n");
       }
       buffer.appendString("--" + boundary + "\\r\\n");
@@ -543,10 +543,10 @@ public class BodyHandlerTest extends WebTestBase {
       Buffer buffer = Buffer.buffer();
       String str =
         "--" + boundary + "\\r\\n" +
-        "Content-Disposition: form-data; name=\\"attr1\\"\\r\\n\\r\\nTim\\r\\n" +
-        "--" + boundary + "\\r\\n" +
-        "Content-Disposition: form-data; name=\\"attr2\\"\\r\\n\\r\\nJulien\\r\\n" +
-        "--" + boundary + "--\\r\\n";
+          "Content-Disposition: form-data; name=\\"attr1\\"\\r\\n\\r\\nTim\\r\\n" +
+          "--" + boundary + "\\r\\n" +
+          "Content-Disposition: form-data; name=\\"attr2\\"\\r\\n\\r\\nJulien\\r\\n" +
+          "--" + boundary + "--\\r\\n";
       buffer.appendString(str);
       req.headers().set("content-length", String.valueOf(buffer.length()));
       req.headers().set("content-type", "multipart/form-data; boundary=" + boundary);
@@ -561,7 +561,7 @@ public class BodyHandlerTest extends WebTestBase {
 
     router.clear();
     router.route().handler(BodyHandler.create()
-        .setUploadsDirectory(uploadsDirectory));
+      .setUploadsDirectory(uploadsDirectory));
     router.route().handler(ctx -> {
       assertNull(ctx.getBody());
       assertEquals(1, ctx.fileUploads().size());
@@ -575,11 +575,11 @@ public class BodyHandlerTest extends WebTestBase {
       String boundary = "dLV9Wyq26L_-JQxk6ferf-RT153LhOO";
       Buffer buffer = Buffer.buffer();
       String header =
-          "--" + boundary + "\\r\\n" +
-              "Content-Disposition: form-data; name=\\"" + name + "\\"; filename=\\"" + fileName + "\\"\\r\\n" +
-              "Content-Type: " + contentType + "\\r\\n" +
-              "Content-Transfer-Encoding: binary\\r\\n" +
-              "\\r\\n";
+        "--" + boundary + "\\r\\n" +
+          "Content-Disposition: form-data; name=\\"" + name + "\\"; filename=\\"" + fileName + "\\"\\r\\n" +
+          "Content-Type: " + contentType + "\\r\\n" +
+          "Content-Transfer-Encoding: binary\\r\\n" +
+          "\\r\\n";
       buffer.appendString(header);
       buffer.appendBuffer(TestUtils.randomBuffer(50));
       String footer = "\\r\\n--" + boundary + "--\\r\\n";
@@ -591,8 +591,7 @@ public class BodyHandlerTest extends WebTestBase {
   }
 
   @Test
-  public void testNoUploadDirMultiPartFormData() throws Exception
-  {
+  public void testNoUploadDirMultiPartFormData() throws Exception {
     String dirName = getNotCreatedTemporaryFolderName();
     router.clear();
     router.route().handler(BodyHandler.create(false).setUploadsDirectory(dirName));
@@ -612,7 +611,7 @@ public class BodyHandlerTest extends WebTestBase {
 
   @Test
   public void testFormMultipartFormDataWithAllowedFilesUploadFalse2() throws Exception {
-      testFormMultipartFormDataWithAllowedFilesUploadFalse(false);
+    testFormMultipartFormDataWithAllowedFilesUploadFalse(false);
   }
 
   private void testFormMultipartFormDataWithAllowedFilesUploadFalse(boolean mergeAttributes) throws Exception {
@@ -645,7 +644,7 @@ public class BodyHandlerTest extends WebTestBase {
       Buffer buffer = Buffer.buffer();
       String boundary = "dLV9Wyq26L_-JQxk6ferf-RT153LhOO";
       String header =
-          "--" + boundary + "\\r\\n" +
+        "--" + boundary + "\\r\\n" +
           "Content-Disposition: form-data; name=\\"attr1\\"\\r\\n\\r\\nTim\\r\\n" +
           "--" + boundary + "\\r\\n" +
           "Content-Disposition: form-data; name=\\"attr2\\"\\r\\n\\r\\nTommaso\\r\\n" +
@@ -654,8 +653,8 @@ public class BodyHandlerTest extends WebTestBase {
           "Content-Type: application/octet-stream\\r\\n" +
           "Content-Transfer-Encoding: binary\\r\\n" +
           "\\r\\n";
-        buffer.appendString(header);
-        buffer.appendBuffer(TestUtils.randomBuffer(50));
+      buffer.appendString(header);
+      buffer.appendBuffer(TestUtils.randomBuffer(50));
       buffer.appendString("\\r\\n--" + boundary + "--\\r\\n");
       req.headers().set("content-length", String.valueOf(buffer.length()));
       req.headers().set("content-type", "multipart/form-data; boundary=" + boundary);
@@ -664,8 +663,7 @@ public class BodyHandlerTest extends WebTestBase {
   }
 
   @Test
-  public void testNoUploadDirFormURLEncoded() throws Exception
-  {
+  public void testNoUploadDirFormURLEncoded() throws Exception {
     String dirName = getNotCreatedTemporaryFolderName();
     router.clear();
     router.route().handler(BodyHandler.create(false).setUploadsDirectory(dirName));
@@ -676,16 +674,14 @@ public class BodyHandlerTest extends WebTestBase {
   }
 
   @Test
-  public void testBodyHandlerCreateTrueWorks() throws Exception
-  {
+  public void testBodyHandlerCreateTrueWorks() throws Exception {
     router.clear();
     router.route().handler(BodyHandler.create(true));
     testFormURLEncoded();
   }
 
   @Test
-  public void testSetHandleFileUploads() throws Exception
-  {
+  public void testSetHandleFileUploads() throws Exception {
     String dirName = getNotCreatedTemporaryFolderName();
     router.clear();
 
@@ -709,8 +705,7 @@ public class BodyHandlerTest extends WebTestBase {
   }
 
   @Test
-  public void testRerouteWithHandleFileUploadsFalse() throws Exception
-  {
+  public void testRerouteWithHandleFileUploadsFalse() throws Exception {
     String fileName = "test.bin";
     router.clear();
     router.route().handler(BodyHandler.create(false).setMergeFormAttributes(true));
@@ -735,7 +730,7 @@ public class BodyHandlerTest extends WebTestBase {
       Buffer buffer = Buffer.buffer();
       String boundary = "dLV9Wyq26L_-JQxk6ferf-RT153LhOO";
       String header =
-          "--" + boundary + "\\r\\n" +
+        "--" + boundary + "\\r\\n" +
           "Content-Disposition: form-data; name=\\"attr1\\"\\r\\n\\r\\nTim\\r\\n" +
           "--" + boundary + "\\r\\n" +
           "Content-Disposition: form-data; name=\\"attr2\\"\\r\\n\\r\\nTommaso\\r\\n" +
@@ -744,8 +739,8 @@ public class BodyHandlerTest extends WebTestBase {
           "Content-Type: application/octet-stream\\r\\n" +
           "Content-Transfer-Encoding: binary\\r\\n" +
           "\\r\\n";
-        buffer.appendString(header);
-        buffer.appendBuffer(TestUtils.randomBuffer(50));
+      buffer.appendString(header);
+      buffer.appendBuffer(TestUtils.randomBuffer(50));
       buffer.appendString("\\r\\n--" + boundary + "--\\r\\n");
       req.headers().set("content-length", String.valueOf(buffer.length()));
       req.headers().set("content-type", "multipart/form-data; boundary=" + boundary);
@@ -754,8 +749,7 @@ public class BodyHandlerTest extends WebTestBase {
   }
 
   @Test
-  public void testBodyLimitWithHandleFileUploadsFalse() throws Exception
-  {
+  public void testBodyLimitWithHandleFileUploadsFalse() throws Exception {
     router.clear();
 
     BodyHandler bodyHandler = BodyHandler.create(false).setBodyLimit(2048);
@@ -768,8 +762,7 @@ public class BodyHandlerTest extends WebTestBase {
     sendFileUploadRequest(fileData, 413, "Request Entity Too Large");
   }
 
-  private String getNotCreatedTemporaryFolderName() throws IOException
-  {
+  private String getNotCreatedTemporaryFolderName() throws IOException {
     File dir = tempUploads.newFolder();
     dir.delete();
     return dir.getPath();
@@ -882,24 +875,22 @@ public class BodyHandlerTest extends WebTestBase {
     router.clear();
     router.route().handler(BodyHandler.create());
     router.route().handler(rc -> {
-      MultiMap attrs = rc.request().formAttributes();
-      assertNotNull(attrs);
-      int size = 0;
-      assertNotNull(attrs.get("attr1"));
-      size += attrs.get("attr1").length();
-      assertNotNull(attrs.get("attr2"));
-      size += attrs.get("attr2").length();
-      assertTrue(size > 2048);
-      rc.response().end();
+      fail("Should not get here");
+    }).failureHandler(ctx -> {
+      assertNotNull(ctx.failure());
+      assertTrue(ctx.failure() instanceof IOException);
+      assertEquals("Size exceed allowed maximum capacity", ctx.failure().getMessage());
+      ctx.next();
     });
+
     testRequest(HttpMethod.POST, "/?p1=foo", req -> {
       Buffer buffer = Buffer.buffer();
       String boundary = "dLV9Wyq26L_-JQxk6ferf-RT153LhOO";
       String header =
         "--" + boundary + "\\r\\n" +
-          "Content-Disposition: form-data; name=\\"attr1\\"\\r\\n\\r\\n" + Base64.getUrlEncoder().encodeToString(TestUtils.randomBuffer(1024).getBytes()) + "\\r\\n" +
+          "Content-Disposition: form-data; name=\\"attr1\\"\\r\\n\\r\\n" + Base64.getUrlEncoder().encodeToString(TestUtils.randomBuffer(2048).getBytes()) + "\\r\\n" +
           "--" + boundary + "\\r\\n" +
-          "Content-Disposition: form-data; name=\\"attr2\\"\\r\\n\\r\\n" + Base64.getUrlEncoder().encodeToString(TestUtils.randomBuffer(1024).getBytes()) + "\\r\\n" +
+          "Content-Disposition: form-data; name=\\"attr2\\"\\r\\n\\r\\n" + Base64.getUrlEncoder().encodeToString(TestUtils.randomBuffer(2048).getBytes()) + "\\r\\n" +
           "--" + boundary + "\\r\\n" +
           "Content-Disposition: form-data; name=\\"" + name + "\\"; filename=\\"file\\"\\r\\n" +
           "Content-Type: application/octet-stream\\r\\n" +
@@ -911,7 +902,19 @@ public class BodyHandlerTest extends WebTestBase {
       req.headers().set("content-length", String.valueOf(buffer.length()));
       req.headers().set("content-type", "multipart/form-data; boundary=" + boundary);
       req.write(buffer);
-    }, 200, "OK", null);
+    }, 400, "Bad Request", null);
+  }
+
+  @Test
+  public void testLogExceptions() throws Exception {
+    router.clear();
+    router.route().handler(BodyHandler.create());
+
+    router.route().handler(ctx -> {
+      throw new NullPointerException();
+    });
+    testRequest(HttpMethod.GET, "/", req -> {
+    }, 500, "Internal Server Error", null);
   }
 
 }