Least Helpful Message Ever
I am trying to debug a problem with HTTP POST. We use it to upload a large file. The client program uses the Apache httpclient library. For some reason, the client thinks that the upload fails, while the server is of the opinion that it succeeded (like, verifying the MD5 checksum of the uploaded file, so we're really really sure that all the bytes are there.)
So after my first guess (a server-side problem with the load balancer) turns out to be bogus, I turn on debug messages on the client, following the instructions given here:
DEBUG [org.apache.http.impl.conn.DefaultClientConnection] Sending request: POST /ups HTTP/1.1
DEBUG [org.apache.http.headers] >> POST /ups HTTP/1.1
DEBUG [org.apache.http.headers] >> Content-Length: 81920654
DEBUG [org.apache.http.headers] >> Content-Type: multipart/form-data; boundary=F4hB38f8nqBAKQVNmpSSwS4umHaLkZTX_7n
DEBUG [org.apache.http.headers] >> Host: xxx.xxxxxx.xxx
DEBUG [org.apache.http.headers] >> Connection: Keep-Alive
DEBUG [org.apache.http.headers] >> User-Agent: Apache-HttpClient/4.0.1 (java 1.5)
DEBUG [org.apache.http.headers] >> Expect: 100-Continue
DEBUG [org.apache.http.impl.conn.DefaultClientConnection] Receiving response: HTTP/1.1 100 Continue
DEBUG [org.apache.http.headers] << HTTP/1.1 100 Continue
...
later
...
DEBUG [org.apache.http.impl.conn.DefaultClientConnection] Connection closed
DEBUG [org.apache.http.impl.client.DefaultHttpClient] Closing the connection.
DEBUG [org.apache.http.impl.conn.DefaultClientConnection] Connection closed
DEBUG [org.apache.http.impl.conn.DefaultClientConnection] Connection shut down
DEBUG [org.apache.http.impl.conn.SingleClientConnManager] Releasing connection org.apache.http.impl.conn.SingleClientConnManager$ConnAdapter@6fb5f204
Connection closed?!? How is this helpful? In fact, I went and looked at where that message appears and it's in the close() method of the socket wrapper--- the only thing there is a log message and a close() method call on a superclass!
The log includes every single stupid byte sent over the wire (excluded from the snippet above) but doesn't see fit to provide any reason why somebody called the close() method? I would have thought that, you know, the developers of an HTTP client library would give some thought to what was necessary to debug HTTP problems...
(And it's a good thing only one connection at a time is happening--- because you will note that there isn't any information identifying which connection any of these messages belong to. I accept blame for the lack of timestamps myself, because I knew when following the linked recipe that I would regret not having them.)
So after my first guess (a server-side problem with the load balancer) turns out to be bogus, I turn on debug messages on the client, following the instructions given here:
DEBUG [org.apache.http.impl.conn.DefaultClientConnection] Sending request: POST /ups HTTP/1.1
DEBUG [org.apache.http.headers] >> POST /ups HTTP/1.1
DEBUG [org.apache.http.headers] >> Content-Length: 81920654
DEBUG [org.apache.http.headers] >> Content-Type: multipart/form-data; boundary=F4hB38f8nqBAKQVNmpSSwS4umHaLkZTX_7n
DEBUG [org.apache.http.headers] >> Host: xxx.xxxxxx.xxx
DEBUG [org.apache.http.headers] >> Connection: Keep-Alive
DEBUG [org.apache.http.headers] >> User-Agent: Apache-HttpClient/4.0.1 (java 1.5)
DEBUG [org.apache.http.headers] >> Expect: 100-Continue
DEBUG [org.apache.http.impl.conn.DefaultClientConnection] Receiving response: HTTP/1.1 100 Continue
DEBUG [org.apache.http.headers] << HTTP/1.1 100 Continue
...
later
...
DEBUG [org.apache.http.impl.conn.DefaultClientConnection] Connection closed
DEBUG [org.apache.http.impl.client.DefaultHttpClient] Closing the connection.
DEBUG [org.apache.http.impl.conn.DefaultClientConnection] Connection closed
DEBUG [org.apache.http.impl.conn.DefaultClientConnection] Connection shut down
DEBUG [org.apache.http.impl.conn.SingleClientConnManager] Releasing connection org.apache.http.impl.conn.SingleClientConnManager$ConnAdapter@6fb5f204
Connection closed?!? How is this helpful? In fact, I went and looked at where that message appears and it's in the close() method of the socket wrapper--- the only thing there is a log message and a close() method call on a superclass!
The log includes every single stupid byte sent over the wire (excluded from the snippet above) but doesn't see fit to provide any reason why somebody called the close() method? I would have thought that, you know, the developers of an HTTP client library would give some thought to what was necessary to debug HTTP problems...
(And it's a good thing only one connection at a time is happening--- because you will note that there isn't any information identifying which connection any of these messages belong to. I accept blame for the lack of timestamps myself, because I knew when following the linked recipe that I would regret not having them.)