Here's more food for thought. Is the following appropriate depth for debug
logging? One nice thing you see here is how clearly the non-blocking I/O is
working by virtue of thread names:
Cheers,
-Adrian
2009-10-10 10:43:07,025 DEBUG [org.jclouds.rest.internal.RestClientProxy]
(main) Converted SDNConnection.upload to POST
https://node1.nirvanix.com/Upload.ashx?output=json&uploadToken=K1M5rN...
PsCrPeDiVt%7ETaubT1QF7aJ9hKFF_Q&destFolderPath=container HTTP/1.1
2009-10-10 10:43:07,029 DEBUG [org.jclouds.rest.internal.RestClientProxy]
(main) Invoking upload
2009-10-10 10:43:07,213 INFO
[org.jclouds.http.httpnio.pool.NioHttpCommandConnectionPool]
(pool-1-thread-1) Starting NioHttpCommandConnectionPool [ target=
node1.nirvanix.com/206.251.254.17:443, endPoint=https://node1.
nirvanix.com, hashCode=333232100 ]
2009-10-10 10:43:07,431 INFO
[org.jclouds.http.httpnio.pool.NioHttpCommandConnectionPool] (I/O dispatcher
18) Opened:
node1.nirvanix.com/206.251.254.17:443
2009-10-10 10:43:07,431 INFO
[org.jclouds.http.httpnio.pool.NioHttpCommandConnectionPool] (I/O dispatcher
17) Opened:
node1.nirvanix.com/206.251.254.17:443
2009-10-10 10:43:07,431 INFO
[org.jclouds.http.httpnio.pool.NioHttpCommandConnectionPool] (I/O dispatcher
23) Opened:
node1.nirvanix.com/206.251.254.17:443
2009-10-10 10:43:07,432 INFO
[org.jclouds.http.httpnio.pool.NioHttpCommandConnectionPool] (I/O dispatcher
19) Opened:
node1.nirvanix.com/206.251.254.17:443
2009-10-10 10:43:07,432 INFO
[org.jclouds.http.httpnio.pool.NioHttpCommandConnectionPool] (I/O dispatcher
13) Opened:
node1.nirvanix.com/206.251.254.17:443
2009-10-10 10:43:07,432 INFO
[org.jclouds.http.httpnio.pool.NioHttpCommandConnectionPool] (I/O dispatcher
20) Opened:
node1.nirvanix.com/206.251.254.17:443
2009-10-10 10:43:07,432 INFO
[org.jclouds.http.httpnio.pool.NioHttpCommandConnectionPool] (I/O dispatcher
16) Opened:
node1.nirvanix.com/206.251.254.17:443
2009-10-10 10:43:07,432 INFO
[org.jclouds.http.httpnio.pool.NioHttpCommandConnectionPool] (I/O dispatcher
22) Opened:
node1.nirvanix.com/206.251.254.17:443
2009-10-10 10:43:07,433 INFO
[org.jclouds.http.httpnio.pool.NioHttpCommandConnectionPool] (I/O dispatcher
15) Opened:
node1.nirvanix.com/206.251.254.17:443
2009-10-10 10:43:07,433 INFO
[org.jclouds.http.httpnio.pool.NioHttpCommandConnectionPool] (I/O dispatcher
14) Opened:
node1.nirvanix.com/206.251.254.17:443
2009-10-10 10:43:07,433 INFO
[org.jclouds.http.httpnio.pool.NioHttpCommandConnectionPool] (I/O dispatcher
24) Opened:
node1.nirvanix.com/206.251.254.17:443
2009-10-10 10:43:07,433 INFO
[org.jclouds.http.httpnio.pool.NioHttpCommandConnectionPool] (I/O dispatcher
21) Opened:
node1.nirvanix.com/206.251.254.17:443
2009-10-10 10:43:07,719 DEBUG
[org.jclouds.http.httpnio.pool.NioHttpCommandExecutionHandler] (I/O
dispatcher 18) Sending request: POST
https://node1.nirvanix.com/Upload.ashx?output=json&uploadToken=K1M5rN...
G%7EBrlTx6Hn%7EPsCrPeDiVt%7ETaubT1QF7aJ9hKFF_Q&destFolderPath=container&sessionToken=95015e5e-2d47-471d-acd9-13115c4d51e3
HTTP/1.1
2009-10-10 10:43:07,871 DEBUG
[org.jclouds.http.httpnio.pool.NioHttpCommandExecutionHandler] (I/O
dispatcher 18) Receiving response: HTTP/1.1 200 OK
2009-10-10 10:43:07,877 DEBUG [org.jclouds.http.functions.ReturnVoidIf2xx]
(pool-1-thread-2) Processing intermediate result for:
org.jclouds.http.HttpResponse@fa425c
2009-10-10 10:43:07,878 DEBUG [org.jclouds.http.functions.ReturnVoidIf2xx]
(pool-1-thread-2) Processed intermediate result for:
org.jclouds.http.HttpResponse@fa425c
On Sat, Oct 10, 2009 at 1:02 AM, Adrian Cole <adrian.f.cole(a)gmail.com>wrote:
Hi, guys.
I'm polishing up jclouds for release. I'd like some feedback on logging,
especially as relates to integration with other libraries. In this case,
I'm referring to wire logging, where we trace the inputs and outputs to the
cloud service into a separate log file. Wire logging is extremely important
when troubleshooting with cloud vendors, as they can read the stacks without
knowing java. Wire logging is course optional, and removes redundant content
logging from other parts of the code.
The design is largely borrowed from apache hc wire logging. It differs in
implementation, where we make it asynchronous and portable across http
engines. In other words, java, nio, and whatever engines we come up with
next will have identical output like below [1]. This specific logging is
controlled by categories jclouds.http.headers (for headers) and
jclouds.http.wire (for content). Note that these are not org.jclouds
categories on purpose, so as to avoid accidentally turning them on with
wildcards.
Please let me know what you think.
Cheers,
-Adrian
[1]
2009-10-10 00:44:37,566 DEBUG [jclouds.http.headers] (pool-1-thread-2) >>
POST
https://node1.nirvanix.com/Upload.ashx?output=json&uploadToken=40Z0PF...
rPath=container&sessionToken=61b0ca55-3782-44f8-bdf1-177a9d118d28 HTTP/1.1
2009-10-10 00:44:37,566 DEBUG [jclouds.http.headers] (pool-1-thread-2) >>
Content-Length: 141
2009-10-10 00:44:37,566 DEBUG [jclouds.http.headers] (pool-1-thread-2) >>
Content-Type: multipart/form-data; boundary=--JCLOUDS--
2009-10-10 00:44:37,751 DEBUG [jclouds.http.wire] (pool-1-thread-1) >>
"----JCLOUDS--[\r][\n]"
2009-10-10 00:44:37,751 DEBUG [jclouds.http.wire] (pool-1-thread-1) >>
"Content-Disposition: form-data; name="key";
filename="key"[\r][\n]"
2009-10-10 00:44:37,751 DEBUG [jclouds.http.wire] (pool-1-thread-1) >>
"Content-Type: application/octet-stream[\r][\n]"
2009-10-10 00:44:37,751 DEBUG [jclouds.http.wire] (pool-1-thread-1) >>
"[\r][\n]"
2009-10-10 00:44:37,751 DEBUG [jclouds.http.wire] (pool-1-thread-1) >>
"value[\r][\n]"
2009-10-10 00:44:37,751 DEBUG [jclouds.http.wire] (pool-1-thread-1) >>
"----JCLOUDS----[\r][\n]"
2009-10-10 00:44:37,926 DEBUG [jclouds.http.headers] (pool-1-thread-2) <<
HTTP/1.1 200 OK
2009-10-10 00:44:37,926 DEBUG [jclouds.http.headers] (pool-1-thread-2) <<
Content-Length: 152
2009-10-10 00:44:37,926 DEBUG [jclouds.http.headers] (pool-1-thread-2) <<
X-Powered-By: Nirvanix SDN
2009-10-10 00:44:37,926 DEBUG [jclouds.http.headers] (pool-1-thread-2) <<
X-Powered-By:
ASP.NET
2009-10-10 00:44:37,926 DEBUG [jclouds.http.headers] (pool-1-thread-2) <<
Expires: -1
2009-10-10 00:44:37,926 DEBUG [jclouds.http.headers] (pool-1-thread-2) <<
X-AspNet-Version: 2.0.50727
2009-10-10 00:44:37,927 DEBUG [jclouds.http.headers] (pool-1-thread-2) <<
Date: Sat, 10 Oct 2009 07:46:25 GMT
2009-10-10 00:44:37,927 DEBUG [jclouds.http.headers] (pool-1-thread-2) <<
Pragma: no-cache
2009-10-10 00:44:37,927 DEBUG [jclouds.http.headers] (pool-1-thread-2) <<
Content-Type: text/xml; charset=utf-8
2009-10-10 00:44:37,927 DEBUG [jclouds.http.headers] (pool-1-thread-2) <<
Server: Nirvanix IMFS
2009-10-10 00:44:37,927 DEBUG [jclouds.http.headers] (pool-1-thread-2) <<
Server: Microsoft-IIS/6.0
2009-10-10 00:44:37,927 DEBUG [jclouds.http.headers] (pool-1-thread-2) <<
Cache-Control: no-cache