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,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[\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 - << "
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.