| <!-- |
| /*************************************************************************************************************************** |
| * Licensed to the Apache Software Foundation (ASF) under one or more contributor license agreements. See the NOTICE file |
| * distributed with this work for additional information regarding copyright ownership. The ASF licenses this file |
| * to you 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 |
| * |
| * 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. See the License for the |
| * specific language governing permissions and limitations under the License. |
| ***************************************************************************************************************************/ |
| --> |
| |
| {8.1.0-new} |
| Logging / Debugging |
| |
| <p> |
| The REST APIs provides support for fine-tuned control of logging for HTTP requests and responses. |
| </p> |
| <p> |
| The APIs involved are: |
| </p> |
| <ul class='javatree'> |
| <li class='ja'> |
| {@link oajr.annotation.Rest} |
| <ul> |
| <li class='jm'>{@link oajr.annotation.Rest#logging() logging()} - Class-level logging configuration and rules. |
| <li class='jm'>{@link oajr.annotation.Rest#debug() debug()} - Enable debug mode. |
| </ul> |
| </li> |
| <li class='ja'> |
| {@link oajr.annotation.RestMethod} |
| <ul> |
| <li class='jm'>{@link oajr.annotation.RestMethod#logging() logging()} - Class-level logging configuration. |
| <li class='jm'>{@link oajr.annotation.RestMethod#debug() debug()} - Enable debug mode. |
| </ul> |
| </li> |
| <li class='jc'> |
| {@link oajr.RestContext} |
| <ul> |
| <li class='jf'>{@link oajr.RestContext#REST_callLoggerConfig REST_callLoggerConfig} - Underlying configuration property for {@link oajr.annotation.Rest#logging() @Rest(logging)}. |
| <li class='jf'>{@link oajr.RestContext#REST_debug REST_debug} - Underlying configuration property for {@link oajr.annotation.Rest#debug() @Rest(debug)}. |
| </ul> |
| </li> |
| <li class='ja'> |
| {@link oajr.annotation.Logging} - Annotation for {@link oajr.annotation.Rest#logging() @Rest(logging)} and {@link oajr.annotation.RestMethod#logging() @RestMethod(logging)} |
| <ul> |
| <li class='jm'>{@link oajr.annotation.Logging#level() level()} - The logging level. |
| <li class='jm'>{@link oajr.annotation.Logging#rules() rules()} - The logging rules. |
| <li class='jm'>{@link oajr.annotation.Logging#useStackTraceHashing() useStackTraceHashing()} - Enables de-duplication of logged stack traces and replacement with hash IDs. |
| <li class='jm'>{@link oajr.annotation.Logging#stackTraceHashingTimeout() stackTraceHashingTimeout()} - Controls how frequently hashed stack traces are re-logged. |
| <li class='jm'>{@link oajr.annotation.Logging#disabled() disabled()} - Disables logging completely or per-request. |
| </ul> |
| </li> |
| <li class='ja'> |
| {@link oajr.annotation.LoggingRule} - Annotation for {@link oajr.annotation.Logging#rules() @Logging(rules)} |
| <ul> |
| <li class='jm'>{@link oajr.annotation.LoggingRule#level() level()} - The logging level. |
| <li class='jm'>{@link oajr.annotation.LoggingRule#codes() codes()} - Status code patterns and ranges to match against. |
| <li class='jm'>{@link oajr.annotation.LoggingRule#exceptions() exceptions()} - Exception class names and patterns to match against. |
| <li class='jm'>{@link oajr.annotation.LoggingRule#debugOnly() debugOnly()} - Match only if debug is set on the request. |
| <li class='jm'>{@link oajr.annotation.LoggingRule#req() req()} - The level of request detail. |
| <li class='jm'>{@link oajr.annotation.LoggingRule#res() res()} - The level of response detail. |
| <li class='jm'>{@link oajr.annotation.LoggingRule#verbose() verbose()} - Shortcut for <jsf>LONG</jsf> request and response detail. |
| <li class='jm'>{@link oajr.annotation.LoggingRule#disabled() disabled()} - Disables logging completely or per-request. |
| </ul> |
| </li> |
| </ul> |
| |
| <h5 class='topic'>Request/response details</h5> |
| <p> |
| The amount of detail on requests and responses is controlled via the {@link oajr.annotation.LoggingRule#req() @LoggingRule(req)} |
| and {@link oajr.annotation.LoggingRule#res() @LoggingRule(res)} annotations: |
| </p> |
| <ul> |
| <li><js>"short"</js> - Results in simple one-line log lines containing the HTTP method + url + response code. |
| <li><js>"medium"</js> - Also includes headers and body length information (if debug enabled). |
| <li><js>"large"</js> - Dumps the entire request/response bodies (if debug enabled). |
| </ul> |
| <p> |
| The following code shows the output produced using the <js>"short"</js> setting: |
| </p> |
| <p class='bpcode'> |
| <ja>@Rest</ja>( |
| logging=<ja>@Logging</ja>( |
| level=<js>"info"</js>, |
| rules={ |
| <ja>@LoggingRule</ja>(codes<js>"500-"</js>, level=<js>"warning"</js>, req=<js>"short"</js>, res=<js>"short"</js>) |
| } |
| ) |
| ) |
| <jk>public static class</jk> MyRestClass { |
| |
| <ja>@RestMethod</ja>(method=<js>"POST"</js>, path=<js>"foo"</js>) |
| <jk>public</jk> String myRestMethod(RestRequest req, RestResponse res) <jk>throws</jk> Exception { |
| res.setStatus(500); |
| res.setHeader(<js>"Foo"</js>, <js>"bar"</js>); |
| res.setException(<jk>new</jk> StringIndexOutOfBoundsException()); <jc>// Could also throw.</jc> |
| <jk>return</jk> req.getBody().asString(); |
| } |
| } |
| |
| <jk>static</jk> MockRest <jsf>MY_REST</jsf> = MockRest.<jsm>build</jsm>(MyRestClass.<jk>class</jk>, <jk>null</jk>); |
| |
| <ja>@Test</ja> |
| <jk>public void</jk> test() <jk>throws</jk> Exception { |
| <jsf>MY_REST</jsf>.<jsm>post</jsm>(<js>"/foo?foo=bar"</js>, <js>"Foo"</js>).header(<js>"Foo"</js>, <js>"bar"</js>).execute().assertStatus(500); |
| } |
| </p> |
| <p> |
| The log output produced from the code above looks like this: |
| </p> |
| <p class='bpcode'> |
| WARNING: [500] HTTP POST /foo |
| java.lang.StringIndexOutOfBoundsException |
| at org.apache.juneau.rest.annotation.RestResourceLoggingTest$MyRestClass.myRestMethod(RestResourceLoggingTest.java:672) |
| at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) |
| at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) |
| at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) |
| at java.lang.reflect.Method.invoke(Method.java:498) |
| ... |
| </p> |
| <p> |
| In comparison, using <js>"long"</js> formatting adds information about headers and body. |
| </p> |
| <p class='bpcode'> |
| <ja>@Rest</ja>( |
| debug=<js>"true"</js>, <jc>// Needed to capture request/response bodies for logging.</jc> |
| logging=<ja>@Logging</ja>( |
| level=<js>"info"</js>, |
| rules={ |
| <ja>@LoggingRule</ja>(codes<js>"500-"</js>, level=<js>"warning"</js>, req=<js>"long"</js>, res=<js>"long"</js>) |
| } |
| ) |
| ) |
| </p> |
| <p> |
| Request/response bodies are only cached for logging if debugging is enabled via the <c class='snippet'>debug=<js>"true"</js></c> flag. |
| </p> |
| <p> |
| The log file now contains the following with shows the contents of the request and response bodies in both UTF-8 |
| and spaced-hex: |
| <p> |
| <p class='bpcode'> |
| WARNING: |
| === HTTP Request (incoming) =================================================== |
| [500] HTTP POST /foo?foo=bar |
| Request length: 3 bytes |
| Response code: 500 |
| Response length: 3 bytes |
| Exec time: 20ms |
| ---Request Headers--- |
| Foo: bar |
| ---Response Headers--- |
| Foo: bar |
| Content-Type: text/plain |
| ---Request Body UTF-8--- |
| Foo |
| ---Request Body Hex--- |
| 46 6F 6F |
| ---Response Body UTF-8--- |
| Foo |
| ---Response Body Hex--- |
| 46 6F 6F |
| === END =================================================================== |
| java.lang.StringIndexOutOfBoundsException |
| at org.apache.juneau.rest.annotation.RestResourceLoggingTest$MyRestClass.myRestMethod(RestResourceLoggingTest.java:672) |
| at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) |
| at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) |
| at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) |
| at java.lang.reflect.Method.invoke(Method.java:498) |
| ... |
| </p> |
| |
| <h5 class='topic'>Rule matching</h5> |
| <p> |
| Logging rules can match against status codes, exception class names, and the debug flag. |
| <br>The following shows various examples of logging rule matches. |
| </p> |
| |
| <p class='bpcode'> |
| <ja>@Rest</ja>( |
| logging=<ja>@Logging</ja>( |
| rules={ |
| <jc>// Individual status codes.</jc> |
| <ja>@LoggingRule</ja>(codes=<js>"300"</js>, ...) |
| |
| <jc>// Ranges of status codes.</jc> |
| <ja>@LoggingRule</ja>(codes=<js>"400-499"</js>, ...) |
| <ja>@LoggingRule</ja>(codes=<js>">=500"</js>, ...) |
| |
| <jc>// All codes.</jc> |
| <ja>@LoggingRule</ja>(codes=<js>"*"</js>, ...) |
| |
| <jc>// Full class names of exceptions.</jc> |
| <ja>@LoggingRule</ja>(exceptions=<js>"java.lang.StringIndexOutOfBoundsException"</js>, ...) |
| |
| <jc>// Exception class name patterns.</jc> |
| <ja>@LoggingRule</ja>(exceptions=<js>"String*Exception *Foo*Exception"</js>, ...) |
| |
| <jc>// Match when debug enabled only.</jc> |
| <ja>@LoggingRule</ja>(codes=<js>"*"</js>, debugOnly=<js>"true"</js>, ...) |
| } |
| ) |
| ) |
| </p> |
| <p> |
| Rules are matched in the order listed on the annotation. |
| Rules on methods are matched before rules on classes. |
| Rules on child methods/classes are matched before rules on parent classes. |
| </p> |
| |
| <h5 class='topic'>Debug mode</h5> |
| <p> |
| The debug mode setting allows HTTP request/response bodies to be cached in memory for logging purposes: |
| </p> |
| <p class='bpcode'> |
| <ja>@Rest</ja>( |
| debug=<js>"true"</js> |
| ) |
| </p> |
| |
| <p> |
| The possible values for the debug setting are (case-insensitive): |
| </p> |
| <ul> |
| <li><js>"true"</js> - Debug mode enabled. |
| <li><js>"false"</js> (default) - Debug mode disabled. |
| <li><js>"per-request"</js> - Debug mode is enabled only on requests containing an <c class='snippet'>X-Debug: true</c> header. |
| </ul> |
| <p> |
| Note that caching HTTP bodies in memory can produce significant performance penalties, so use the setting wisely. |
| <br>In particular, do not leave this setting enabled on production instances since it can easily lead to |
| denial-of-service attacks. |
| </p> |
| <p> |
| Servlet code can check the debug setting via the {@link oajr.RestRequest#isDebug()} method allowing it to be used |
| for custom purposes. |
| </p> |
| <p> |
| Debug mode can also be enabled on a request by calling the {@link oajr.RestRequest#setDebug(Boolean)} or |
| {@link oajr.RestResponse#setDebug(Boolean)} methods. Note however that you must be sure not to have already consumed |
| the request or started writing the response before calling this method. |
| </p> |
| |
| <h5 class='topic'>No-trace (disabled) mode</h5> |
| <p> |
| The {@link oajr.annotation.Logging#disabled() @Logging(disabled)} and {@link oajr.annotation.LoggingRule#disabled() @LoggingRule(disabled)} annotations |
| can be used to disable logging entirely or on a per-request basis: |
| </p> |
| <p class='bpcode'> |
| <ja>@Rest</ja>( |
| logging=<ja>@Logging</ja>( |
| disabled=<js>"true"</js> |
| rules={ |
| <ja>@LoggingRule</ja>( |
| codes<js>"500-"</js>, |
| disabled=<js>"false"</js> |
| ) |
| } |
| ) |
| ) |
| </p> |
| <p> |
| The possible values for the disabled setting are (case-insensitive): |
| </p> |
| <ul> |
| <li><js>"true"</js> - Logging disabled. |
| <li><js>"false"</js> (default) - Logging not disabled. |
| <li><js>"per-request"</js> - Logging is disabled only on requests containing a <c class='snippet'>X-NoTrace: true</c> header. |
| </ul> |
| <p> |
| Disabled logging is particularly useful when running testcases that are expected to throw exceptions or cause |
| other errors and you don't want these errors logged. |
| </p> |
| <p> |
| Disabled logging can also be set on a request by calling the {@link oajr.RestRequest#setNoTrace(Boolean)} or |
| {@link oajr.RestResponse#setNoTrace(Boolean)} methods. |
| </p> |
| |
| <h5 class='topic'>Stacktrace hashing</h5> |
| <p> |
| The {@link oajr.annotation.Logging#useStackTraceHashing() @Logging(useStackTraceHashing)} setting can be used to eliminate duplicate stacktraces |
| in your log file by logging them once and then logging identifying hash IDs. |
| </p> |
| <p> |
| In the example below, we're causing two exceptions but only logging the first one: |
| </p> |
| <p class='bpcode'> |
| <ja>@Rest</ja>( |
| logging=<ja>@Logging</ja>( |
| useStackTraceHashing=<js>"true"</js>, |
| rules={ |
| <ja>@LoggingRule</ja>(codes<js>">=500"</js>, level=<js>"warning"</js>, req=<js>"short"</js>, res=<js>"short"</js>) |
| } |
| ) |
| ) |
| <jk>public static class</jk> MyRestClass { |
| |
| <ja>@RestMethod</ja>(method=<js>"POST"</js>, path=<js>"foo"</js>) |
| <jk>public</jk> String myRestMethod(RestRequest req, RestResponse res) <jk>throws</jk> Exception { |
| res.setHeader(<js>"Foo"</js>, <js>"bar"</js>); |
| |
| // Equivalent to throwing an exception. |
| res.setStatus(500); |
| res.setException(<jk>new</jk> StringIndexOutOfBoundsException()); |
| |
| <jk>return</jk> req.getBody().asString(); |
| } |
| } |
| |
| <jk>static</jk> MockRest <jsf>MY_REST</jsf> = MockRest.<jsm>build</jsm>(MyRestClass.<jk>class</jk>, <jk>null</jk>); |
| |
| <ja>@Test</ja> |
| <jk>public void</jk> test() <jk>throws</jk> Exception { |
| <jsf>MY_REST</jsf>.<jsm>post</jsm>(<js>"/foo?foo=bar"</js>, <js>"Foo"</js>).header(<js>"Foo"</js>, <js>"bar"</js>).execute().assertStatus(500); |
| <jsf>MY_REST</jsf>.<jsm>post</jsm>(<js>"/foo?foo=bar"</js>, <js>"Foo"</js>).header(<js>"Foo"</js>, <js>"bar"</js>).execute().assertStatus(500); |
| } |
| </p> |
| <p> |
| The log file will show a 4 byte hash ID <js>"9b85cc96"</js> and count <js>".1"</js> as shown below: |
| </p> |
| <p class='bpcode'> |
| Jul 11, 2019 3:38:48 PM org.apache.juneau.rest.BasicRestCallLogger log |
| WARNING: [500,9b85cc96.1] HTTP POST /foo |
| java.lang.StringIndexOutOfBoundsException |
| at org.apache.juneau.rest.annotation.RestResourceLoggingTest$MyRestClass.myRestMethod(RestResourceLoggingTest.java:671) |
| at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) |
| at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) |
| at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) |
| at java.lang.reflect.Method.invoke(Method.java:498) |
| ... |
| |
| WARNING: [500,9b85cc96.2] HTTP POST /foo |
| </p> |
| <p> |
| The {@link oajr.annotation.Logging#stackTraceHashingTimeout() @Logging(stackTraceHashingTimeout)} setting can be used to periodically log the stacktrace |
| to the log file again. |
| </p> |