Debugging WebService errors in ColdFusion

Tuesday, March 24, 2009

Overview

This is an article about the process of debugging a strange error I received while trying to execute an external webservice using ColdFusion 8. The external service is a java service, using Axis2, running in WebSphere. But if you're just searching for an answer b/c maybe you've hit the same problem, scroll to the bottom. Otherwise, enjoy the show.

I was executing the service like so:
<cfset ws = createObject("webservice","http://XXXXX/webservices/services/WFIService?wsdl")>
<cfset result = ws.initiateOrder(IlexCode="enr",OrderXML="<orders/>")>

It Started with this Error Here's the error:

Cannot perform web service invocation initiateOrder. The fault returned when invoking the web service operation is: AxisFault faultCode: {http://www.w3.org/2003/05/soap-envelope}Server.userException faultSubcode: faultString: org.xml.sax.SAXParseException: Invalid encoding name "UTF-8; ACTION="URN:INITIATEORDERRESPONSE"". faultActor: faultNode: faultDetail: {http://xml.apache.org/axis/}stackTrace:org.xml.sax.SAXParseException: Invalid encoding name "UTF-8; ACTION="URN:INITIATEORDERRESPONSE"". at org.apache.xerces.util.ErrorHandlerWrapper.createSAXParseException(Unknown Source) (for the lone bleary-eyed googler trying desperately to solve the same problem, i give you these keywords: faultString: org.xml.sax.SAXParseException: Invalid encoding name "UTF-8; ACTION=" )

Here's what it looked like so you can bask in its awesomeness: Running the service from outside ColdFusion

First, I wanted to be sure that the problem wasn't with the service itself, so I needed to execute it outside of ColdFusion. For me, the simplest way to do this is with the "Web Services Explorer" that comes with Eclipse WST (Google it, it's handy). So I fired that up, saw there were 3 different "Bindings", and I hit the first SOAP one (the Soap11 porttype) just fine.

The SOAP12 binding was unsupported, so I ignored it. I also ignored the HTTP Post binding. So in my head, what I'm thinking is "I can hit the service successfully from outside of CF. Now I'm in black box hell."

Trying to view the SOAP messages with TCPMon

First, I needed to find out what differed between the SOAP being sent by the Web Services Explorer and the SOAP being sent by ColdFusion. Having done a fair amount of development with Apache Axis back in 2002/2003, and more recently while developing the MXUnit Eclipse plugin, I was familiar with using TCPMon for doing this kind of debugging. However, I never tried to use it for debugging remote services, only local ones. (And after spending a half hour or so with it yesterday, I still don't know how to use it for debugging remote services. If you know, please tell me!). Eventually, because all I was really interested in was seeing the SOAP envelope and the http headers being sent, I just copied the wsdl from the remote services, stuck it in an xml file on my computer, and pointed my webservice call in Scribble pad to the new URL: http://localhost:8124/playground/WFIService.xml?wsdl. I then fired up TCPMon and added a listener at Port 8124

  1. from command line, navigate to C:\jrun4\servers\cfusion\cfusion-ear\cfusion-war\WEB-INF\cfusion\lib
  2. type java -cp axis.jar org.apache.axis.utils.tcpmon
  3. The swing app pops up
  4. Type 8124 into Listen Port (this is arbitrary!)
  5. Target Port = 80 (though in my case, it doesn't matter anyway)
  6. Click "add"

I then executed my local version of the service like so:

<cfset ws = createObject("webservice","http://localhost:8124/playground/WFIService.xml?wsdl")>
<cfset result = ws.initiateOrder(IlexCode="enr",OrderXML="<orders/>")>
Again, This wouldn't actually "work work", but CF would at least try to send a soap request to this address, so I'd be able to see what was being sent to the remote server. Honestly, this didn't pan out. Based on the original error, I suspected the problem wasn't with the SOAP envelope but with the headers. If you'll remember from the original error message, it displayed: Invalid encoding name "UTF-8; ACTION="URN:INITIATEORDERRESPONSE"". I suspected the problem was with the Content-Type header being sent to the service, but when I looked at it in tcpmon, it showed up like so: POST /webservices/services/WFIService HTTP/1.0 Content-Type: application/soap+xml; charset=UTF-8 Accept: application/soap+xml, application/dime, multipart/related, text/* User-Agent: Axis/1.2.1 And I had expected to see this in that header: "UTF-8; ACTION="URN:INITIATEORDERRESPONSE"" For the screenshot lovers, it looked like this: So as of that moment, I was kind of perplexed. I'm sure folk with more experience consuming web services from a variety of external producers would know exactly what was going on. I, however, did not. Me + TCPMon = Fail.

Debugging with the Generated Java stubs

Some time back I had read Nathan Mische's excellent article in FusionAuthority Quarterly Update on using complex datatypes in CF web services. In the article, he mentions something new in CF8: the ability to easily view the generated java stubs created by axis (this is how CF works under the hood: it uses the wsdl2java tool from axis to dynamically generate bindings based on the WSDL). I change my web service invocation like so:

<cfset args = {refreshWSDL=true,savejava=true}>
<cfset ws = createObject("webservice","http://XXXXX/webservices/services/WFIService?wsdl",args)>
<cfset result = ws.initiateOrder(IlexCode="enr",OrderXML="<orders/>")>
So I run the service again, get the error, and traipse on down to the stubs directory (in my case: C:\jrun4\servers\cfusion\cfusion-ear\cfusion-war\WEB-INF\cfusion\stubs) and open up the most recent directory. Navigate on down, and there are the java files. I decided that I wanted to see if I could execute the service from outside of CF but using these source files, so I opened up my java playground project in Eclipse (you DO have at least one playground/sandbox/scratch project, right?!), added a new package, and dropped the source files in there. The screenshot below shows the eclipse directory where I copied the generated java files on the left; on the right is the stubs directory that ColdFusion creates. Note that it's a mix of java and class files. Normally, the java files aren't in there, but the "savejava=true" key in the arguments struct that I'm now passing to CF in the createobject() call ensures the java files stay there. When I first copied the files over into my new Eclipse package, I naturally got a bunch of errors. First, I needed to change the package declaration in the source files (alternately, I could've simply renamed my package). Second, I needed to add jar files to the the build path so that the source files would compile. This is simple: In Eclipse, in the project's "lib" directory, I created a new subfolder called "axis12". I did this b/c I didn't want to pollute my existing lib directory, and at the time I had suspected that maybe the problem was with CF using axis 1.2 and not 1.4 (I use 1.4 for the Eclipse plugin, so I had thought maybe I'd end up running these sources files under both axis 1.2 and 1.4 and therein would've lied the bug... turned out that's not what it was at all). Then, in C:\JRun4\servers\cfusion\cfusion-ear\cfusion-war\WEB-INF\cfusion\lib, I copied a whole bunch of jar files that looked like they'd be required. in the end, I copied all the ones you see highlighted in the "referenced libraries" from the screenshot below. I didn't need all of these to get the java to compile, but I did need them to get it to run without getting NoClassDefFound errors when actually running the code.

In addition, I created a new JUnit TestCase for executing the generated code (simply a start... no assertions, just something to run the code):

WFIServiceTest.java: package marc.axis; ...imports... public class WFIServiceTest extends TestCase { public void testCompleteOrder() throws RemoteException, ServiceException, MalformedURLException { WFIServiceLocator locator = new WFIServiceLocator(); System.out.println(locator.getWFIServiceSOAP11port_http().initiateOrder("enr", "<orders/>")); } }

After doing this stuff, the damn test case didn't error! Confound it all Samwise Gamgee! I had hoped against hope that by running the service using the stubs generated from CF that I'd hit the same error that I was hitting inside of CF. This way, I could at least step through it in the debugger and have a fighting chance of getting inside the black box to figure out how to fix this. Alas, this was not to be. It was time to take a break. Distance Every programmer knows that one of the worst things you can do when faced with a hard-to-get-at problem of this type is to stare and obsess over it endlessly. You get tired. Your eyes hurt. Your brain turns to mush. Your shoulders ache. I really, really wanted to keep at this. Thankfully, in the background I hear my wife yell at my daughter, my daughter has a low-grade conniption (she's 5 and of late prone to such outbursts...), and Daddy has to swoop in and save the day. Being a dad always comes first. About an hour after the meltdown, it's tubby time. Afterward, I'm drying my daughter's hair, my brain's still working on the problem, and it hits me: it's the other bindings! Remember the ones from when I executed the service successfully in the Web Services Explorer (the Soap11 binding worked fine)? And remember how the Soap12 binding was unsupported, and I ignored the HTTP Post binding? Well.... they stuck in my head. And they had to be in the generated sources. So as I'm drying my daughter's hair, I'm thinking... what if CF is using one of those other bindings, and that's why I'm getting the error? It's all about the PortName

Now, at this point, I can think of nothing else. I HAVE to get downstairs and see if that's it. Problem is, I have a wet-headed kid. So I race through that, hand her off to my sweet wife (who's busy with our littlest daughter), and hit the computer again. I change this line in my test case like so: from System.out.println(locator.getWFIServiceSOAP11port_http().initiateOrder("enr", "<orders/>")); to System.out.println(locator.getWFIServiceSOAP12port_http().initiateOrder("enr", "<orders/>"));

Sweet, sweet stack trace:

AxisFault faultCode: {http://www.w3.org/2003/05/soap-envelope}Server.userException faultSubcode: faultString: org.xml.sax.SAXParseException: Invalid encoding name "UTF-8; ACTION="URN:INITIATEORDERRESPONSE"". faultActor: faultNode: faultDetail: {http://xml.apache.org/axis/}stackTrace:org.xml.sax.SAXParseException: Invalid encoding name "UTF-8; ACTION="URN:INITIATEORDERRESPONSE"". at org.apache.xerces.util.ErrorHandlerWrapper.createSAXParseException(Unknown Source) at org.apache.xerces.util.ErrorHandlerWrapper.fatalError(Unknown Source) at org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source) at org.apache.xerces.impl.XMLErrorReporter.reportError(Unknown Source) at org.apache.xerces.impl.XMLEntityManager.createReader(Unknown Source) at org.apache.xerces.impl.XMLEntityManager.setupCurrentEntity(Unknown Source) at org.apache.xerces.impl.XMLVersionDetector.determineDocVersion(Unknown Source) at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source) at org.apache.xerces.parsers.XML11Configuration.parse(Unknown Source) .....

That was it... CF was using the Soap12 binding instead of the Soap11 binding. So all I needed to do was get CF to use the correct binding, and my problem would be solved. How to do that? I remember reading in the docs that you could use the "portname" attribute to force CF to use a specific binding, so that's what I needed to do. Now... what's the portname to use? It's simple to discover what is available to you. Just look in the WSDL, scroll to the bottom, and find stuff that looks like this:

<wsdl:service name="WFIService">
<wsdl:port name="WFIServiceSOAP11port_http" binding="ns0:WFIServiceSOAP11Binding">
<soap:address location="http://XXX/webservices/services/WFIService"/>
</wsdl:port>
<wsdl:port name="WFIServiceSOAP12port_http" binding="ns0:WFIServiceSOAP12Binding">
<soap12:address location="http://XXX/webservices/services/WFIService"/>
</wsdl:port>
<wsdl:port name="WFIServiceHttpport" binding="ns0:WFIServiceHttpBinding">
<http:address location="http://XXX/webservices/services/WFIService"/>
</wsdl:port>
</wsdl:service>
The names available to you for use in the portname attribute are the names in the wsdl:port elements. So I took the Soap11 portname, added it to the webservice invocation like so, and bam... problem solved:
<cfset ws = createObject("webservice","http://XXXXX/webservices/services/WFIService?wsdl","WFIServiceSOAP11port_http")>
<cfset result = ws.initiateOrder(IlexCode="enr",OrderXML="<orders/>")>
What I still don't understand According to the CF Documentation, if you don't specify the portname, then CF will pick the first one it finds. Looking at the WSDL, the first element is the Soap11 binding. Why is CF using the Soap12 binding? I don't get it. There's another lesson here, aside from the fact that portname is scalded into my brain. It's a lesson about struggle. I believe that struggle is key to learning deep. You have to be willing to fight for your answers. Sure, I tried googling for the answer first! But when I didn't find it, I didn't stop there. You have to do the same thing. If you resort to the mailing lists or forums and paste in your 1000 lines of code, you're not just annoying the people who would otherwise try to help you; you're doing yourself a great disservice. Learning is hard; it takes time; it's even worse when you're under deadline pressure and you just gotta get this thing done. Still, if you want to grow, you gotta welcome the pain.

2 comments:

Anonymous said...

Same error, fixed changing

getxxxxHttpSoap12Endpoint()
to
getxxxxHttpSoap11Endpoint()

Thank you so much!

bchesley said...

Came across this chasing a similar problem - very helpful. Yes, the struggle is the thing!