How to log properly http requests with Spring MVC
Hello I’ve been trying to figure out generic way to log http requests in my application, so far no luck, here is how I handle the logging right now i.e:
@RequestMapping(value="register", method = RequestMethod.POST) @ResponseBody public String register(@RequestParam(value="param1",required=false) String param1, @RequestParam("param2") String param2, @RequestParam("param3") String param3, HttpServletRequest request) < long start = System.currentTimeMillis(); logger.info("!--REQUEST START--!"); logger.info("Request URL: " + request.getRequestURL().toString()); ListrequestParameterNames = Collections.list((Enumeration)request.getParameterNames()); logger.info("Parameter number: " + requestParameterNames.size()); for (String parameterName : requestParameterNames) < logger.info("Parameter name: " + parameterName + " - Parameter value: " + request.getParameter(parameterName)); >//Some processing logic, call to the various services/methods with different parameters, response is always String(Json) String response = service.callSomeServiceMethods(param1,param2,param3); logger.info("Response is: " + response); long end = System.currentTimeMillis(); logger.info("Requested completed in: " + (end-start) + "ms"); logger.info("!--REQUEST END--!"); return response; > So what I do right now for different controllers/methods is copy everything from beginning of the inside of the method until the processing logic which differs from method to method and then copy everything from below of that as showed in above template. It is kind of messy, and there is a lot of code repetition(which I don’t like). But I need to log everything. Does anyone have more experience with this kinds of logging, can anyone shed some light on this?
How to log request/response using java.net.http.HttpClient?
The HttpClient introduced experimentally in Java 9 is now stable in Java 11, but not surprisingly, very few projects seem to actually use it. Documentation is almost non-existing. One of the most commons asks while making a HTTP call is logging of request/response. How would you do that using the HttpClient , without of course, logging it manually in every single call? Is there an interceptor mechanism like that offered by all other HTTP clients?
That API looks like a catastrophe. It doesn’t even have a mockable interface. (Not to mention, as you’ve observed, the apparent lack of any generalizable interceptor mechanism that’s been standard on HTTP clients for 20 years in favor of special-cased top-level interfaces.)
It’s hard to agree with «Documentation is almost non-existing.» First of all, there’s a good javadoc full of examples. Secondly, there are bunch of webcasts on youtube from the guys who created it, e.g. youtube.com/watch?v=BornfFsSlc8 or youtube.com/watch?v=lAW_NhJ3kqs
@pavel You must be looking at a different one than this javadoc; if that’s “good”, your expectations are pretty low. And webcasts are a weak excuse for good documentation.
@AbhijitSarkar, you might be mistaking javadoc for a tutorial/guide/manual. Please define documentation.
3 Answers 3
You can log request and responses by specifying
-Djdk.httpclient.HttpClient.log=requests on the Java command line.
Depending on what you are looking to achieve you could use a «DelegatingHttpClient» to intercept and log requests and responses too.
Besides the Java API documentation there’s also some high level documentation at http://openjdk.java.net/groups/net/httpclient/index.html
The jdk.httpclient.HttpClient.log property is an implementation specific property whose value is a comma separated list which can be configured on the Java command line for diagnosis/debugging purposes with the following values:
-Djdk.httpclient.HttpClient.log= errors,requests,headers, frames[:control:data:window:all],content,ssl,trace,channel,all What are the possible values for jdk.httpclient.HttpClient.log ? How did you find out that argument, is it documented somewhere? Please elaborate in your answer.
The additional note sets the wrong property, should be -Djdk.httpclient.HttpClient.log=errors,requests,headers,frames[:control:data:window:all],content,ssl,trace,channel
Seems like it doesn’t log the request/response bodies. I guess if it’s a GET request, URL will contain all the parameters but for others, this is pretty useless. Bang up job, Oracle!
The possible values for jdk.httpclient.HttpClient.log are mentioned in jdk11 source code in the the class jdk.httpclient.HttpClient.log.Log.java
NOTE: DNS requests are not being logged. To see DNS requests, this tool seems to be handy: genady.net/dns (I have not found any easier to use. Please add comment if there is something nice)
If we look at jdk.internal.net.http.common.DebugLogger source code we can see a few loggers using System.Logger , which in turn will use System.LoggerFinder to select the logger framework. JUL is the default choice. The logger names are:
- jdk.internal.httpclient.debug
- jdk.internal.httpclient.websocket.debug
- jdk.internal.httpclient.hpack.debug
They can be enabled by setting them as a system property. For example running with -Djdk.internal.httpclient.debug=true will produce:
DEBUG: [main] [147ms] HttpClientImpl(1) proxySelector is sun.net.spi.DefaultProxySelector@6dde5c8c (user-supplied=false) DEBUG: [main] [183ms] HttpClientImpl(1) ClientImpl (async) send https://http2.github.io/ GET DEBUG: [main] [189ms] Exchange establishing exchange for https://http2.github.io/ GET, proxy=null DEBUG: [main] [227ms] PlainHttpConnection(?) Initial receive buffer size is: 43690 DEBUG: [main] [237ms] PlainHttpConnection(SocketTube(1)) registering connect event DEBUG: [HttpClient-1-SelectorManager] [239ms] SelectorAttachment Registering jdk.internal.net.http.PlainHttpConnection$ConnectEvent@354bf356 for 8 (true) . From the Javadoc, «The system default LoggerFinder implementation uses java.util.logging as the backend framework when the java.logging module is present.». java —list-modules | grep logging shows java.logging@11.0.1 , so I guess, the answer to my question «yes it uses JUL unless you mess with it». 🙂
I ended up switching to OkHttp because the logs were too verbose to be useful. I’ll accept your answer as it applies to my question. Wish the client design allowed for easily plugging in interceptors — logging everything at debug or nothing at all seems silly.
The -Djdk.internal.httpclient.debug logger is primarily intended for JDK developers who fix bugs in the HttpClient implementation, not for users of the API. I wouldn’t recommend anybody else to use it. -Djdk.httpclient.HttpClient.log=errors,requests,headers,frames[:control:data:window:all..],content,ssl,trace,channel is probably more suited for users of the API.
On our side, we did not find the logging provided by -Djdk.internal.httpclient.debug readable enough. The solution we came up with is to wrap the HttpClient with a decorator that will be able to intercept the calls and provide logging. Here how it somehow looks (should be done not only for send but sendAsync methods) :
public class HttpClientLoggingDecorator extends HttpClient < private static final Logger logger = Logger.getLogger(HttpClientLoggingDecorator.class.getName()); private final HttpClient client; . @Override public HttpResponse send(HttpRequest req, HttpResponse.BodyHandler responseBodyHandler) throws IOException, InterruptedException < subscribeLoggerToRequest(req); HttpResponseresponse = client.send(req, responseBodyHandler); logResponse(response); return response; > private void subscribeLoggerToRequest(HttpRequest req) < // define a consumer for how you want to log // ConsumerbodyConsumer = . ; if (req.bodyPublisher().isPresent()) < req.bodyPublisher().get().subscribe(new HttpBodySubscriber(bodyConsumer))); >else < bodyConsumer.accept(NO_REQUEST_BODY); >> private void logResponse(HttpResponse response) < // String responseLog = . ; logger.info(responseLog); >> And here is the HttpBodySubscriber :
public class HttpBodySubscriber implements Flow.Subscriber < private static final long UNBOUNDED = Long.MAX_VALUE; private final Consumerlogger; public HttpBodySubscriber(Consumer logger) < this.logger = logger; >@Override public void onSubscribe(Flow.Subscription subscription) < subscription.request(UNBOUNDED); >@Override public void onNext(ByteBuffer item) < logger.accept(new String(item.array(), StandardCharsets.UTF_8)); >@Override public void onError(Throwable throwable) < >@Override public void onComplete() < >> Jsoup http logging
How can I log the http request and response? Please mind that I want the HTTP and not just the HTML that will be parsed.
3 Answers 3
By default jsoup uses a implementation of java.net.HttpURLConnection So I suppose you need to turn on logging for that implementation (probably: sun.net.www.protocol.http.HttpURLConnection) or for java.net .
There is a system property that will enable logging for java net utils
As Jsoup lacks logging (version I’m using: 1.12.1 ) and using the -Djavax.net.debug=all JVM argument logs are too verbose, the best way I found is to decorate the HttpConnection class, so one can customize what is logged. To achive this, the execute method call needs to be surrounded by logging the properties of the Connection.Request and Connection.Response .
Sample implementation using SLF4J :
import org.jsoup.Connection; import org.jsoup.helper.HttpConnection; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import java.io.IOException; public class DiagnosticConnection extends HttpConnection < static final Logger LOG = LoggerFactory.getLogger(DiagnosticConnection.class); @Override public Connection.Response execute() throws IOException < log(this.request()); Connection.Response response = super.execute(); log(response); return response; >public static Connection connect(String url) < Connection connection = new DiagnosticConnection(); connection.url(url); return connection; >private static void log(Connection.Request request) < LOG.info("========================================"); LOG.info("[url] <>", request.url()); LOG.info("== REQUEST =="); logBase(request); LOG.info("[method] <>", request.method()); LOG.info("[data] <>", request.data()); LOG.info("[request body] <>", request.requestBody()); > private static void log(Connection.Response response) < LOG.info("== RESPONSE =="); logBase(response); LOG.info("[code] <>", response.statusCode()); LOG.info("[status msg] <>", response.statusMessage()); LOG.info("[body] <>", response.body()); LOG.info("========================================"); > private static void logBase(Connection.Base base) < LOG.info("[headers] <>", base.headers()); LOG.info("[cookies] <>", base.cookies()); > > When using the decorator, instead of Jsoup.connect() you should use DiagnosticConnection.connect()
I’m gettin error because HttpConnection has not public constructor. Error: There is not default constructor available in ‘org.jsoup.helper.HttpConnection’
Based on Gergely Toth response, I have created my own LoggerHttpConnection and I’m working with that.
import android.util.Log import org.jsoup.Connection import org.jsoup.helper.HttpConnection import org.jsoup.nodes.Document import org.jsoup.parser.Parser import java.io.InputStream import java.net.Proxy import java.net.URL import javax.net.ssl.SSLSocketFactory class LoggerHttpConnection private constructor( private val delegate: HttpConnection, private val saveFile: Boolean ) : Connection < private val tag = "LoggerHttpConnection" companion object < fun connect(url: String, saveFile: Boolean = false): LoggerHttpConnection < return LoggerHttpConnection( HttpConnection.connect(url) as HttpConnection, saveFile ) >> private fun log(request: Connection.Request): String < Log.i(tag, "========================================") var line = "[url] $" var log = "$line\n\n== REQUEST ==\n" Log.i(tag, line) Log.i(tag, "== REQUEST ==") log += logBase(request) line = "[method] $" log += "$line\n" Log.i(tag, line) for (data in request.data()) < line = "[data] $=$" log += "$line\n" Log.i(tag, line) > line = "[request body] $" log += "$line\n" Log.i(tag, line) return log > private fun log(response: Connection.Response): String < var line = "" var log = "\n== RESPONSE ==\n" Log.i(tag, "== RESPONSE ==") log += logBase(response) line = "[code] $" log += "$line\n" Log.i(tag, line) line = "[status msg] $" log += "$line\n" Log.i(tag, line) line = "[body] $" log += "$line\n" Log.i(tag, line) Log.i(tag, "========================================") return log > private fun logBase(base: Connection.Base): String < var line = "" var log = "" for (header in base.headers()) < line = "[header] $=$" log += "$line\n" Log.i(tag, line) > for (cookie in base.cookies()) < line = "[cookie] $: $" log += "$line\n" Log.i(tag, line) > return log > override fun execute(): Connection.Response < var logs = log(request()) val response = delegate.execute() logs += log(response) if (saveFile) logs.saveToFile("request_log") //do something to save your log in a file if its necesary return response >override fun ignoreContentType(ignoreContentType: Boolean): Connection < delegate.ignoreContentType(ignoreContentType) return this >override fun postDataCharset(charset: String?): Connection < delegate.postDataCharset(charset) return this >override fun get(): Document < return delegate.get() >override fun post(): Document < return delegate.post() >/** Continue implementing necessary methods for Connection */ > Now just declare your request using LoggerHttpConnection instead Jsoup and everything will work
Connection.Response res = LoggerHttpConnection.connect("LOGIN_URL_HERE") .data("user", "USER", "pass", "PASS") .method(Connection.Method.POST) .execute(); Set restAssured to log all requests and responses globally
Put this line of code on your @BeforeClass method and every given call will create a log just like using log.all() after every given:
RestAssured.filters(new RequestLoggingFilter(), new ResponseLoggingFilter()); I think you need to see the logs then test fails, in this case just use this configuration from rest assured:
In what context? I tried putting that line in @BeforeClass but got java.lang.NoClassDefFoundError: org/apache/groovy/io/StringBuilderWriter
Add logging filters to RestAssured defaults, see filters and defaults.
To create a filter you need to implement the io.restassured.filter.Filter interface. To use a filter you can do:
given().filter(new MyFilter()). ..There are a couple of filters provided by REST Assured that are ready to use:
1. io.restassured.filter.log.RequestLoggingFilter: A filter that’ll print the request specification details.
2. io.restassured.filter.log.ResponseLoggingFilter: A filter that’ll print the response details if the response matches a given status code.
3. io.restassured.filter.log.ErrorLoggingFilter: A filter that’ll print the response body if an error occurred (status code is between 400 and 500)
Any filter could be added to request, spec or global defaults:
RestAssured.filters(..); // List of default filters