« DevCentral Article on Anonymous Human Authentication | Main | Recent Updates »

12/03/2009

Configuring "Wire" Logging in Groovy HTTPBuilder

Enabling Debug mode in log4j within HTTPBuilder gives me the ability to, as a novice, figure out what the heck I was thinking when I constructed an http request the way I did.  Take this script for example, which makes use of the FeedBurner Awareness API and its intention is to display the number of subscribers to my blog (thank you all, by the way!) based on a specified date:

!/usr/bin/env groovy

import groovyx.net.http.RESTClient
import groovy.util.slurpersupport.GPathResult
import static groovyx.net.http.ContentType.URLENC

def stats = new RESTClient( 'https://feedburner.google.com/api/awareness/1.0/GetFeedData?uri=BloggingTechstacks' )
  
def resp = stats.get( dates: '2009-11-01' )
 resp.data instanceof GPathResult

println "${resp.data.feed.@uri}"
println "${resp.data.feed.entry.@circulation}"

Every time I execute this script and specify a date range of 11/01 through 11/30, instead of getting what I wanted, I get the number of subscribers from yesterday. Clearly, there is something wrong. I can't inspect the request and response with wireshark because it is ssl encrypted and I do not think that Google would provide me a copy of their key so I can decrypt that traffic. Log4J, though, can give me most of what I need to figure out what is wrong.

The documentation link makes it sound so simple yet with every new release of Groovy I install, I always forget to do something and it takes me a while to remember how to get it all working again.  The Groovy module HTTPBuilder supports log4j and even provides a sample configuration file to get started. This file should go to the ${groovy.home}/conf/ directory and this is the part that I always overlook. To enable debug logging, change the values of categories org.apache.http.headers and org.apache.http.wire from INFO to DEBUG. When I re-execute the script, I get the following:

./test.groovy
2009-12-03 09:39:23,142 DEBUG RESTClient - GET https://feedburner.google.com/api/awareness/1.0/GetFeedData?uri=BloggingTechstacks
2009-12-03 09:39:25,019 DEBUG wire - >> "GET /api/awareness/1.0/GetFeedData?uri=BloggingTechstacks HTTP/1.1[EOL]"
2009-12-03 09:39:25,021 DEBUG wire - >> "Accept: */*[EOL]"
2009-12-03 09:39:25,022 DEBUG wire - >> "Host: feedburner.google.com[EOL]"
2009-12-03 09:39:25,022 DEBUG wire - >> "Connection: Keep-Alive[EOL]"
2009-12-03 09:39:25,022 DEBUG wire - >> "User-Agent: Apache-HttpClient/4.0-beta1 (java 1.4)[EOL]"
2009-12-03 09:39:25,022 DEBUG wire - >> "Accept-Encoding: gzip,deflate[EOL]"
2009-12-03 09:39:25,023 DEBUG wire - >> "[EOL]"
2009-12-03 09:39:25,023 DEBUG headers - >> GET /api/awareness/1.0/GetFeedData?uri=BloggingTechstacks HTTP/1.1
2009-12-03 09:39:25,023 DEBUG headers - >> Accept: */*
2009-12-03 09:39:25,023 DEBUG headers - >> Host: feedburner.google.com
2009-12-03 09:39:25,024 DEBUG headers - >> Connection: Keep-Alive
2009-12-03 09:39:25,024 DEBUG headers - >> User-Agent: Apache-HttpClient/4.0-beta1 (java 1.4)
2009-12-03 09:39:25,024 DEBUG headers - >> Accept-Encoding: gzip,deflate
2009-12-03 09:39:25,084 DEBUG wire - << "HTTP/1.1 200 OK[EOL]"
2009-12-03 09:39:25,087 DEBUG wire - << "Content-Type: application/xml; charset=utf-8[EOL]"
2009-12-03 09:39:25,087 DEBUG wire - << "Date: Thu, 03 Dec 2009 14:39:24 GMT[EOL]"
2009-12-03 09:39:25,087 DEBUG wire - << "Expires: Thu, 03 Dec 2009 14:39:24 GMT[EOL]"
2009-12-03 09:39:25,087 DEBUG wire - << "Cache-Control: private, max-age=0[EOL]"
2009-12-03 09:39:25,087 DEBUG wire - << "X-Content-Type-Options: nosniff[EOL]"
2009-12-03 09:39:25,087 DEBUG wire - << "X-XSS-Protection: 0[EOL]"
2009-12-03 09:39:25,087 DEBUG wire - << "X-Frame-Options: SAMEORIGIN[EOL]"
2009-12-03 09:39:25,087 DEBUG wire - << "Content-Length: 366[EOL]"
2009-12-03 09:39:25,087 DEBUG wire - << "Server: GFE/2.0[EOL]"
2009-12-03 09:39:25,088 DEBUG headers - << HTTP/1.1 200 OK
2009-12-03 09:39:25,088 DEBUG headers - << Content-Type: application/xml; charset=utf-8
2009-12-03 09:39:25,088 DEBUG headers - << Date: Thu, 03 Dec 2009 14:39:24 GMT
2009-12-03 09:39:25,088 DEBUG headers - << Expires: Thu, 03 Dec 2009 14:39:24 GMT
2009-12-03 09:39:25,088 DEBUG headers - << Cache-Control: private, max-age=0
2009-12-03 09:39:25,088 DEBUG headers - << X-Content-Type-Options: nosniff
2009-12-03 09:39:25,088 DEBUG headers - << X-XSS-Protection: 0
2009-12-03 09:39:25,089 DEBUG headers - << X-Frame-Options: SAMEORIGIN
2009-12-03 09:39:25,089 DEBUG headers - << Content-Length: 366
2009-12-03 09:39:25,089 DEBUG headers - << Server: GFE/2.0
2009-12-03 09:39:25,094 DEBUG RESTClient - Response code: 200; found handler: org.codehaus.groovy.runtime.MethodClosure@24bb6086
2009-12-03 09:39:25,096 DEBUG RESTClient - Parsing response as: application/xml
2009-12-03 09:39:25,104 DEBUG wire - << "[\r][\n]"
2009-12-03 09:39:25,104 DEBUG wire - << "[\r][\n]"
2009-12-03 09:39:25,105 DEBUG wire - << " [\r][\n]"
2009-12-03 09:39:25,105 DEBUG wire - << " [\r][\n]"
2009-12-03 09:39:25,105 DEBUG wire - << "  [\r][\n]"
2009-12-03 09:39:25,106 DEBUG wire - << " [\r][\n]"
2009-12-03 09:39:25,106 DEBUG wire - << "[\r][\n]"
2009-12-03 09:39:25,106 DEBUG wire - << "[\r][\n]"
2009-12-03 09:39:25,129 DEBUG RESTClient - Parsed data to instance of: class groovy.util.slurpersupport.NodeChild
BloggingTechstacks
43

My problem is right there in the first line of the log output. My dates argument is not getting passed in the request URI.

As an aside, to include SSL debug output within the console log, (in order to troubleshoot those "unrecognized certificate" issues, for example), add the -Djava.net.debug=ssl statement to the script's startup properties, right after the shebang.

TrackBack

TrackBack URL for this entry:
http://www.typepad.com/services/trackback/6a01156fbc6fe6970c012875fec062970c

Listed below are links to weblogs that reference Configuring "Wire" Logging in Groovy HTTPBuilder:

Comments