analyze of my logfiles
|
View:
New views
1 Messages
—
Rating Filter:
Alert me
|
 |
analyze of my logfiles
by Pär Malmqvist
::
Rate this Message:
Some parts of this message have been removed.
Learn more about Nabble's security policy.
I have problems with my testclient that run thousands of calls to a service called getDrugByDrugId. The client sends a different drugId value for each call. If the drugId in the response object differs from the drugId that was sent in the request something is wrong. That is unfortunately what has happened here. When the client has done some thousands of requests something strange happens. The last request, drugId = 19980123000089, never appears in the log on the server side, but stil the client logs a SOAPMessage it thinks is the reply. But that SOAPMessage was the reply from the request just before, drugId = 20040607010594. I really appreciate if I can get help with analyzing my Axis2 log files below. (The service has a LogHandler added that logs soap messages at the same phases as the SOAPMonitor.) ________________________________________________________________________________________________________________ Environment: I have a client and a service installed on my Windows XP laptop. The client uses Axis2 1.5.1 with a generated xmlbeans client stub and running Java 1.5. The service uses Axis2 1.5.1 with an adb genenerated skeleton deployed on a Tomcat 6.0.20 running Java 1.6. ________________________________________________________________________________________________________________ Regards. Pär Malmqvist CLIENT LOG ************************************************************************************************************** . . . 2009-10-26 16:47:41,916 [main] DEBUG httpclient.wire.content - >> "158[\r][\n]" 2009-10-26 16:47:41,916 [main] DEBUG httpclient.wire.content - >> "<?xml version='1.0' encoding='UTF-8'?><soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"><soapenv:Body><main:getDrugByDrugId xmlns:main="http://main.axis2.sil"><main:param0>20040607010594</main:param0><main:param1>false</main:param1><main:param2>-1</main:param2></main:getDrugByDrugId></soapenv:Body></soapenv:Envelope>" 2009-10-26 16:47:41,916 [main] DEBUG httpclient.wire.content - >> "[\r][\n]" 2009-10-26 16:47:41,916 [main] DEBUG httpclient.wire.content - >> "0" 2009-10-26 16:47:41,916 [main] DEBUG httpclient.wire.content - >> "[\r][\n]" 2009-10-26 16:47:41,916 [main] DEBUG httpclient.wire.content - >> "[\r][\n]" 2009-10-26 16:47:41,916 [main] DEBUG org.apache.commons.httpclient.methods.EntityEnclosingMethod - Request body sent 2009-10-26 16:47:41,916 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.flushRequestOutputStream() 2009-10-26 16:47:41,916 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.readResponse(HttpState, HttpConnection) 2009-10-26 16:47:41,916 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.readStatusLine(HttpState, HttpConnection) 2009-10-26 16:47:41,916 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.readLine() 2009-10-26 16:47:41,916 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:47:41,916 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.header - << "HTTP/1.1 200 OK[\r][\n]" 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.header - << "HTTP/1.1 200 OK[\r][\n]" 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.readResponseHeaders(HttpState,HttpConnection) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.getResponseInputStream() 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HeaderParser.parseHeaders(InputStream, String) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.header - << "Server: Apache-Coyote/1.1[\r][\n]" 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.header - << "Content-Type: text/xml;charset=UTF-8[\r][\n]" 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.header - << "Transfer-Encoding: chunked[\r][\n]" 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.header - << "Date: Mon, 26 Oct 2009 15:47:41 GMT[\r][\n]" 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.header - << "[\r][\n]" 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.processResponseHeaders(HttpState, HttpConnection) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.processCookieHeaders(Header[], HttpState, HttpConnection) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.readResponseBody(HttpState, HttpConnection) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.readResponseBody(HttpConnection) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.getResponseInputStream() 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.canResponseHaveBody(int) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HeaderElement - enter HeaderElement.parseElements(String) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HeaderElement - enter HeaderElement.parseElements(char[]) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.isResponseAvailable(int) 2009-10-26 16:48:02,806 [main] TRACE org.apache.axis2.transport.http.HTTPSender - Handling response - 200 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HeaderElement - enter HeaderElement.parseElements(String) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HeaderElement - enter HeaderElement.parseElements(char[]) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HeaderElement - enter HeaderElement.getParameterByName(String) 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572102976] Invoking flowComplete() in Phase "Security" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572102976] Invoking flowComplete() in Phase "MessageOut" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572102976] Invoking flowComplete() in Phase "PolicyDetermination" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572102976] Invoking flowComplete() in Phase "RMPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572102976] Invoking flowComplete() in Phase "OperationOutPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.transport.TransportUtils - createSOAPEnvelope using Builder (class org.apache.axis2.builder.SOAPBuilder) selected from type (text/xml) 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "6" 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "2" 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "9" 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "[\r]" 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "[\n]" 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "<?xm" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.builder.BuilderUtil - char set encoding set from default =UTF-8 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "l version='1.0' encoding='UTF-8'?><soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"><soapenv:Body><ns1:getDrugByDrugIdResponse xmlns:ns1="http://main.axis2.sil"><ns1:return><ns1:drugId>20040607010594</ns1:drugId><ns1:tradeName>Ramipril Durascan</ns1:tradeName><ns1:strengthNumeric>1.25</ns1:strengthNumeric><ns1:strengthNumericUnit>mg</ns1:strengthNumericUnit><ns1:strengthText>1,25 mg</ns1:strengthText><ns1:drugFormCode>CAPHAR</ns1:drugFormCode><ns1:drugFormTextSv>Kapsel, h[0xc3][0xa5]rd</ns1:drugFormTextSv><ns1:drugClassificationCode>-</ns1:drugClassificationCode><ns1:controlClassCode>0</ns1:controlClassCode><ns1:routeOfAdministrationCodes>-</ns1:routeOfAdministrationCodes><ns1:prescriberCodes>1</ns1:prescriberCodes><ns1:interchangeableFlag>N</ns1:interchangeableFlag><ns1:substanceGroupId>0</ns1:substanceGroupId><ns1:substanceGroupName></ns1:substanceGroupName><ns1:strengthGroupId>0</ns1:strengthGroupId><ns1:strengthGroupName></ns1:strengthGroupName><ns1:pharmaceuticalFormGroupId>0</ns1:pharmaceuticalFormGroupId><ns1:pharmaceuticalFormGroupName></ns1:pharmaceuticalFormGroupName><ns1:lactationGroup>?</ns1:lactationGroup><ns1:pregnancyCategory>?</ns1:pregnancyCategory><ns1:interactionStatus>1</ns1:interactionStatus><ns1:productTypeCode>MEP</ns1:productTypeCode><ns1:prescriptionCode>1</ns1:prescriptionCode><ns1:withdrawalDate>2005-02-28</ns1:withdrawalDate><ns1:hasRecommendedArticle>false</ns1:hasRecommendedArticle><ns1:silDeviationCode></ns1:silDeviationCode></ns1:return></ns1:getDrugByDrugIdResponse></soapenv:Body></soapenv:Envelope>" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axiom.om.util.StAXUtils - XMLStreamReader is com.ctc.wstx.sr.ValidatingStreamReader 2009-10-26 16:48:02,806 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:48:02,806 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://schemas.xmlsoap.org/soap/envelope/}Envelope 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Starting to process SOAP 1.1 message 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement Envelope by the StaxSOAPModelBuilder 2009-10-26 16:48:02,806 [main] TRACE org.apache.axis2.engine.AxisEngine - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] receive:urn:uuid:D19A3745E4C2A334441256572102975 2009-10-26 16:48:02,806 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:48:02,806 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://schemas.xmlsoap.org/soap/envelope/}Body 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement Body by the StaxSOAPModelBuilder 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking pre-condition for Phase "Transport" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking phase "Transport" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking Handler 'RequestURIBasedDispatcher' in Phase 'Transport' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking Handler 'SOAPActionBasedDispatcher' in Phase 'Transport' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking post-conditions for phase "Transport" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking pre-condition for Phase "Addressing" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking phase "Addressing" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking Handler 'AddressingBasedDispatcher' in Phase 'Addressing' 2009-10-26 16:48:02,806 [main] TRACE org.apache.axis2.dispatchers.AddressingBasedDispatcher - invoke: IS_ADDR_INFO_ALREADY_PROCESSED=null 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking post-conditions for phase "Addressing" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking pre-condition for Phase "Security" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking phase "Security" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking post-conditions for phase "Security" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking pre-condition for Phase "PreDispatch" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking phase "PreDispatch" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking post-conditions for phase "PreDispatch" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking pre-condition for Phase "Dispatch" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking phase "Dispatch" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking Handler 'RequestURIBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking Handler 'SOAPActionBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking Handler 'RequestURIOperationDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking Handler 'SOAPMessageBodyBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking Handler 'HTTPLocationBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking post-conditions for phase "Dispatch" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking pre-condition for Phase "RMPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking phase "RMPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking post-conditions for phase "RMPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking pre-condition for Phase "OperationInPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking phase "OperationInPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Checking post-conditions for phase "OperationInPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() in Phase "OperationInPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() in Phase "RMPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() in Phase "Dispatch" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() for Handler 'HTTPLocationBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() for Handler 'SOAPMessageBodyBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() for Handler 'RequestURIOperationDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() for Handler 'SOAPActionBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() for Handler 'RequestURIBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() in Phase "PreDispatch" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() in Phase "Security" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() in Phase "Addressing" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() for Handler 'AddressingBasedDispatcher' in Phase 'Addressing' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() in Phase "Transport" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() for Handler 'SOAPActionBasedDispatcher' in Phase 'Transport' 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123882] Invoking flowComplete() for Handler 'RequestURIBasedDispatcher' in Phase 'Transport' 2009-10-26 16:48:02,806 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:48:02,806 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://main.axis2.sil}getDrugByDrugIdResponse 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement getDrugByDrugIdResponse by the StaxSOAPModelBuilder 2009-10-26 16:48:02,806 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:48:02,806 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://main.axis2.sil}return 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement return by the StaxSOAPModelBuilder 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "[\r]" 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "[\n]" 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "0" 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "[\r]" 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "[\n]" 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HeaderParser.parseHeaders(InputStream, String) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "[\r]" 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.content - << "[\n]" 2009-10-26 16:48:02,806 [main] DEBUG httpclient.wire.header - << "[\r][\n]" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.commons.httpclient.HttpMethodBase - Resorting to protocol version default close connection policy 2009-10-26 16:48:02,806 [main] DEBUG org.apache.commons.httpclient.HttpMethodBase - Should NOT close connection, using HTTP/1.1 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.isResponseAvailable() 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.releaseConnection() 2009-10-26 16:48:02,806 [main] DEBUG org.apache.commons.httpclient.HttpConnection - Releasing connection back to connection manager. 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.MultiThreadedHttpConnectionManager - enter HttpConnectionManager.releaseConnection(HttpConnection) 2009-10-26 16:48:02,806 [main] DEBUG org.apache.commons.httpclient.MultiThreadedHttpConnectionManager - Freeing connection, hostConfig=HostConfiguration[host=http://192.168.18.18:8080] 2009-10-26 16:48:02,806 [main] TRACE org.apache.commons.httpclient.MultiThreadedHttpConnectionManager - enter HttpConnectionManager.ConnectionPool.getHostPool(HostConfiguration) 2009-10-26 16:48:02,806 [main] DEBUG org.apache.commons.httpclient.util.IdleConnectionHandler - Adding connection at: 1256572082806 2009-10-26 16:48:02,806 [main] DEBUG org.apache.commons.httpclient.MultiThreadedHttpConnectionManager - Notifying no-one, there are no waiting threads 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.description.AxisService - Get operation for {http://main.axis2.sil}getDrugByDrugId 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.description.AxisService - Found axis operation: org.apache.axis2.description.OutInAxisOperation@1bd2664 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.context.ConfigurationContext - registerOperationContext (false): org.apache.axis2.context.OperationContext@8b61a3 with key: urn:uuid:D19A3745E4C2A334441256572123883 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.description.OutInAxisOperationClient - Entry: OutInAxisOperationClient::execute, true 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.description.OutInAxisOperationClient - OutInAxisOperationClient: useAsyncOption null 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.context.ConfigurationContext - registerOperationContext (false): org.apache.axis2.context.OperationContext@8b61a3 with key: urn:uuid:D19A3745E4C2A334441256572123883 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.context.ConfigurationContext - msgContext: [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] action: http://main.axis2.sil/SilDB2/getDrugByDrugIdRequest 2009-10-26 16:48:02,806 [main] TRACE org.apache.axis2.engine.AxisEngine - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] send:urn:uuid:D19A3745E4C2A334441256572123883 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Checking pre-condition for Phase "OperationOutPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Invoking phase "OperationOutPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Checking post-conditions for phase "OperationOutPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Checking pre-condition for Phase "RMPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Invoking phase "RMPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Checking post-conditions for phase "RMPhase" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Checking pre-condition for Phase "PolicyDetermination" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Invoking phase "PolicyDetermination" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Checking post-conditions for phase "PolicyDetermination" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Checking pre-condition for Phase "MessageOut" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Invoking phase "MessageOut" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Checking post-conditions for phase "MessageOut" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Checking pre-condition for Phase "Security" 2009-10-26 16:48:02,806 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Invoking phase "Security" 2009-10-26 16:48:02,822 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Checking post-conditions for phase "Security" 2009-10-26 16:48:02,822 [main] TRACE org.apache.axis2.addressing.EndpointReference - hasAnonymousAddress: http://192.168.18.18:8080/axis2/services/SilDB2 is Anonymous: false 2009-10-26 16:48:02,822 [main] TRACE org.apache.axis2.addressing.EndpointReference - hasNoneAddress: http://192.168.18.18:8080/axis2/services/SilDB2 is None: false 2009-10-26 16:48:02,822 [main] DEBUG org.apache.commons.httpclient.params.DefaultHttpParams - Set parameter http.connection.timeout = 99999999 2009-10-26 16:48:02,822 [main] DEBUG org.apache.commons.httpclient.params.DefaultHttpParams - Set parameter http.socket.timeout = 99999999 2009-10-26 16:48:02,822 [main] DEBUG org.apache.commons.httpclient.params.DefaultHttpParams - Set parameter http.socket.timeout = 99999999 2009-10-26 16:48:02,822 [main] TRACE org.apache.axis2.transport.http.HTTPSender - Thread[main,5,main] PostMethod org.apache.commons.httpclient.methods.PostMethod@b7501b / org.apache.commons.httpclient.HttpClient@a2220f 2009-10-26 16:48:02,822 [main] DEBUG org.apache.axiom.om.OMOutputFormat - Start getContentType: OMOutputFormat [ mimeBoundary =null rootContentId=null doOptimize=false doingSWA=false isSOAP11=true charSetEncoding=UTF-8 xmlVersion=null contentType=null ignoreXmlDeclaration=false autoCloseWriter=false actionProperty=null optimizedThreshold=0] 2009-10-26 16:48:02,822 [main] DEBUG org.apache.axiom.om.OMOutputFormat - getContentType= {text/xml} OMOutputFormat [ mimeBoundary =null rootContentId=null doOptimize=false doingSWA=false isSOAP11=true charSetEncoding=UTF-8 xmlVersion=null contentType=text/xml ignoreXmlDeclaration=false autoCloseWriter=false actionProperty=null optimizedThreshold=0] 2009-10-26 16:48:02,822 [main] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - contentType from the OMOutputFormat =text/xml 2009-10-26 16:48:02,822 [main] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - contentType returned =text/xml; charset=UTF-8 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.methods.PostMethod - enter PostMethod.clearRequestBody() 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.methods.EntityEnclosingMethod - enter EntityEnclosingMethod.clearRequestBody() 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpClient - enter HttpClient.executeMethod(HostConfiguration,HttpMethod) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpClient - enter HttpClient.executeMethod(HostConfiguration,HttpMethod,HttpState) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.MultiThreadedHttpConnectionManager - enter HttpConnectionManager.getConnectionWithTimeout(HostConfiguration, long) 2009-10-26 16:48:02,822 [main] DEBUG org.apache.commons.httpclient.MultiThreadedHttpConnectionManager - HttpConnectionManager.getConnection: config = HostConfiguration[host=http://192.168.18.18:8080], timeout = 30000 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.MultiThreadedHttpConnectionManager - enter HttpConnectionManager.ConnectionPool.getHostPool(HostConfiguration) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.MultiThreadedHttpConnectionManager - enter HttpConnectionManager.ConnectionPool.getHostPool(HostConfiguration) 2009-10-26 16:48:02,822 [main] DEBUG org.apache.commons.httpclient.MultiThreadedHttpConnectionManager - Getting free connection, hostConfig=HostConfiguration[host=http://192.168.18.18:8080] 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpMethodDirector - Attempt number 1 to process request 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.execute(HttpState, HttpConnection) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.writeRequest(HttpState, HttpConnection) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.writeRequestLine(HttpState, HttpConnection) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.generateRequestLine(HttpConnection, String, String, String, String) 2009-10-26 16:48:02,822 [main] DEBUG httpclient.wire.header - >> "POST /axis2/services/SilDB2 HTTP/1.1[\r][\n]" 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.print(String) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[]) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[], int, int) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.writeRequestHeaders(HttpState,HttpConnection) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.methods.EntityEnclosingMethod - enter EntityEnclosingMethod.addRequestHeaders(HttpState, HttpConnection) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.methods.ExpectContinueMethod - enter ExpectContinueMethod.addRequestHeaders(HttpState, HttpConnection) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.addRequestHeaders(HttpState, HttpConnection) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.addUserAgentRequestHeaders(HttpState, HttpConnection) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.addHostRequestHeader(HttpState, HttpConnection) 2009-10-26 16:48:02,822 [main] DEBUG org.apache.commons.httpclient.HttpMethodBase - Adding Host request header 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.addCookieRequestHeader(HttpState, HttpConnection) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpState - enter HttpState.getCookies() 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.cookie.CookieSpec - enter CookieSpecBase.match(String, int, String, boolean, Cookie[]) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.addProxyConnectionHeader(HttpState, HttpConnection) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.methods.EntityEnclosingMethod - enter EntityEnclosingMethod.addContentLengthRequestHeader(HttpState, HttpConnection) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.methods.EntityEnclosingMethod - enter EntityEnclosingMethod.getRequestContentLength() 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.methods.PostMethod - enter PostMethod.hasRequestContent() 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.methods.EntityEnclosingMethod - enter EntityEnclosingMethod.hasRequestContent() 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - HttpMethodBase.addRequestHeader(Header) 2009-10-26 16:48:02,822 [main] DEBUG httpclient.wire.header - >> "Content-Type: text/xml; charset=UTF-8[\r][\n]" 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.print(String) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[]) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[], int, int) 2009-10-26 16:48:02,822 [main] DEBUG httpclient.wire.header - >> "SOAPAction: "http://main.axis2.sil/SilDB2/getDrugByDrugIdRequest"[\r][\n]" 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.print(String) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[]) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[], int, int) 2009-10-26 16:48:02,822 [main] DEBUG httpclient.wire.header - >> "User-Agent: Axis2[\r][\n]" 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.print(String) 2009-10-26 16:48:02,822 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[]) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[], int, int) 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.header - >> "Host: 192.168.18.18:8080[\r][\n]" 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.print(String) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[]) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[], int, int) 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.header - >> "Transfer-Encoding: chunked[\r][\n]" 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.print(String) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[]) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[], int, int) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.writeLine() 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[]) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.write(byte[], int, int) 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.header - >> "[\r][\n]" 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.methods.EntityEnclosingMethod - enter EntityEnclosingMethod.writeRequestBody(HttpState, HttpConnection) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.methods.PostMethod - enter PostMethod.hasRequestContent() 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.methods.EntityEnclosingMethod - enter EntityEnclosingMethod.hasRequestContent() 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.methods.EntityEnclosingMethod - enter EntityEnclosingMethod.getRequestContentLength() 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.methods.PostMethod - enter PostMethod.hasRequestContent() 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.methods.EntityEnclosingMethod - enter EntityEnclosingMethod.hasRequestContent() 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.getRequestOutputStream() 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - start writeTo() 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - preserve=false 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - isOptimized=false 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - isDoingSWA=false 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.util.Utils - MTOM optimized Threshold value =0 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - OutputStream =class org.apache.commons.httpclient.ChunkedOutputStream 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - OMFormat = OMOutputFormat [ mimeBoundary =null rootContentId=null doOptimize=false doingSWA=false isSOAP11=true charSetEncoding=UTF-8 xmlVersion=null contentType=text/xml ignoreXmlDeclaration=false autoCloseWriter=false actionProperty=null optimizedThreshold=0] 2009-10-26 16:48:02,837 [main] TRACE org.apache.axiom.om.impl.MTOMXMLStreamWriter - Call Stack =DEBUG_FRAME = org.apache.axiom.om.util.CommonUtils.callStackToString(CommonUtils.java:80) DEBUG_FRAME = org.apache.axiom.om.impl.MTOMXMLStreamWriter.<init>(MTOMXMLStreamWriter.java:94) DEBUG_FRAME = org.apache.axiom.om.impl.llom.OMNodeImpl.serializeAndConsume(OMNodeImpl.java:485) DEBUG_FRAME = org.apache.axis2.transport.http.SOAPMessageFormatter.writeTo(SOAPMessageFormatter.java:79) DEBUG_FRAME = org.apache.axis2.transport.http.AxisRequestEntity.writeRequest(AxisRequestEntity.java:84) DEBUG_FRAME = org.apache.commons.httpclient.methods.EntityEnclosingMethod.writeRequestBody(EntityEnclosingMethod.java:499) DEBUG_FRAME = org.apache.commons.httpclient.HttpMethodBase.writeRequest(HttpMethodBase.java:2114) DEBUG_FRAME = org.apache.commons.httpclient.HttpMethodBase.execute(HttpMethodBase.java:1096) DEBUG_FRAME = org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:398) DEBUG_FRAME = org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:171) DEBUG_FRAME = org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397) DEBUG_FRAME = org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:346) DEBUG_FRAME = org.apache.axis2.transport.http.AbstractHTTPSender.executeMethod(AbstractHTTPSender.java:542) DEBUG_FRAME = org.apache.axis2.transport.http.HTTPSender.sendViaPost(HTTPSender.java:199) DEBUG_FRAME = org.apache.axis2.transport.http.HTTPSender.send(HTTPSender.java:76) DEBUG_FRAME = org.apache.axis2.transport.http.CommonsHTTPTransportSender.writeMessageWithCommons(CommonsHTTPTransportSender.java:400) DEBUG_FRAME = org.apache.axis2.transport.http.CommonsHTTPTransportSender.invoke(CommonsHTTPTransportSender.java:225) DEBUG_FRAME = org.apache.axis2.engine.AxisEngine.send(AxisEngine.java:435) DEBUG_FRAME = org.apache.axis2.description.OutInAxisOperationClient.send(OutInAxisOperation.java:402) DEBUG_FRAME = org.apache.axis2.description.OutInAxisOperationClient.executeImpl(OutInAxisOperation.java:229) DEBUG_FRAME = org.apache.axis2.client.OperationClient.execute(OperationClient.java:165) DEBUG_FRAME = sil.axis2.client.main.SilDB2Stub.getDrugByDrugId(Unknown Source) DEBUG_FRAME = silor.prot.SilApiAxis2Handler.getDrugByDrugId(Unknown Source) DEBUG_FRAME = silor.cases.DrugBasic.DrugBasic20070821000(Unknown Source) DEBUG_FRAME = sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) DEBUG_FRAME = sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) DEBUG_FRAME = sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) DEBUG_FRAME = java.lang.reflect.Method.invoke(Method.java:585) DEBUG_FRAME = silor.main.Mexecute.execute(Unknown Source) DEBUG_FRAME = silor.main.CaseExecutor.run(Unknown Source) DEBUG_FRAME = silor.main.Main.init(Unknown Source) DEBUG_FRAME = silor.main.Main.main(Unknown Source) 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axiom.om.util.StAXUtils - XMLStreamWriter is com.ctc.wstx.sw.SimpleNsStreamWriter 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axiom.om.impl.llom.OMSourcedElementImpl - serialize {http://main.axis2.sil}getDrugByDrugId to XMLStreamWriter 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - Returning access to the original output stream: org.apache.commons.httpclient.ChunkedOutputStream@ec5359 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - Calling MTOMXMLStreamWriter.flush 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - Returning access to the original output stream: org.apache.commons.httpclient.ChunkedOutputStream@ec5359 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - Calling MTOMXMLStreamWriter.flush 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - Calling MTOMXMLStreamWriter.flush 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - end writeTo() 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.content - >> "158[\r][\n]" 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.content - >> "<?xml version='1.0' encoding='UTF-8'?><soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"><soapenv:Body><main:getDrugByDrugId xmlns:main="http://main.axis2.sil"><main:param0>19980123000089</main:param0><main:param1>false</main:param1><main:param2>-1</main:param2></main:getDrugByDrugId></soapenv:Body></soapenv:Envelope>" 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.content - >> "[\r][\n]" 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.content - >> "0" 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.content - >> "[\r][\n]" 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.content - >> "[\r][\n]" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.commons.httpclient.methods.EntityEnclosingMethod - Request body sent 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.flushRequestOutputStream() 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.readResponse(HttpState, HttpConnection) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.readStatusLine(HttpState, HttpConnection) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.readLine() 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.header - << "HTTP/1.1 200 OK[\r][\n]" 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.header - << "HTTP/1.1 200 OK[\r][\n]" 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.readResponseHeaders(HttpState,HttpConnection) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.getResponseInputStream() 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HeaderParser.parseHeaders(InputStream, String) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.header - << "Server: Apache-Coyote/1.1[\r][\n]" 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.header - << "Content-Type: text/xml;charset=UTF-8[\r][\n]" 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.header - << "Transfer-Encoding: chunked[\r][\n]" 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.header - << "Date: Mon, 26 Oct 2009 15:47:41 GMT[\r][\n]" 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.header - << "[\r][\n]" 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.processResponseHeaders(HttpState, HttpConnection) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.processCookieHeaders(Header[], HttpState, HttpConnection) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.readResponseBody(HttpState, HttpConnection) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.readResponseBody(HttpConnection) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.getResponseInputStream() 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpMethodBase - enter HttpMethodBase.canResponseHaveBody(int) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HeaderElement - enter HeaderElement.parseElements(String) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HeaderElement - enter HeaderElement.parseElements(char[]) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.isResponseAvailable(int) 2009-10-26 16:48:02,837 [main] TRACE org.apache.axis2.transport.http.HTTPSender - Handling response - 200 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HeaderElement - enter HeaderElement.parseElements(String) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HeaderElement - enter HeaderElement.parseElements(char[]) 2009-10-26 16:48:02,837 [main] TRACE org.apache.commons.httpclient.HeaderElement - enter HeaderElement.getParameterByName(String) 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Invoking flowComplete() in Phase "Security" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Invoking flowComplete() in Phase "MessageOut" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Invoking flowComplete() in Phase "PolicyDetermination" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Invoking flowComplete() in Phase "RMPhase" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123884] Invoking flowComplete() in Phase "OperationOutPhase" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.transport.TransportUtils - createSOAPEnvelope using Builder (class org.apache.axis2.builder.SOAPBuilder) selected from type (text/xml) 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.content - << "6" 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.content - << "2" 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.content - << "9" 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.content - << "[\r]" 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.content - << "[\n]" 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.content - << "<?xm" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.builder.BuilderUtil - char set encoding set from default =UTF-8 2009-10-26 16:48:02,837 [main] DEBUG httpclient.wire.content - << "l version='1.0' encoding='UTF-8'?><soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"><soapenv:Body><ns1:getDrugByDrugIdResponse xmlns:ns1="http://main.axis2.sil"><ns1:return><ns1:drugId>20040607010594</ns1:drugId><ns1:tradeName>Ramipril Durascan</ns1:tradeName><ns1:strengthNumeric>1.25</ns1:strengthNumeric><ns1:strengthNumericUnit>mg</ns1:strengthNumericUnit><ns1:strengthText>1,25 mg</ns1:strengthText><ns1:drugFormCode>CAPHAR</ns1:drugFormCode><ns1:drugFormTextSv>Kapsel, h[0xc3][0xa5]rd</ns1:drugFormTextSv><ns1:drugClassificationCode>-</ns1:drugClassificationCode><ns1:controlClassCode>0</ns1:controlClassCode><ns1:routeOfAdministrationCodes>-</ns1:routeOfAdministrationCodes><ns1:prescriberCodes>1</ns1:prescriberCodes><ns1:interchangeableFlag>N</ns1:interchangeableFlag><ns1:substanceGroupId>0</ns1:substanceGroupId><ns1:substanceGroupName></ns1:substanceGroupName><ns1:strengthGroupId>0</ns1:strengthGroupId><ns1:strengthGroupName></ns1:strengthGroupName><ns1:pharmaceuticalFormGroupId>0</ns1:pharmaceuticalFormGroupId><ns1:pharmaceuticalFormGroupName></ns1:pharmaceuticalFormGroupName><ns1:lactationGroup>?</ns1:lactationGroup><ns1:pregnancyCategory>?</ns1:pregnancyCategory><ns1:interactionStatus>1</ns1:interactionStatus><ns1:productTypeCode>MEP</ns1:productTypeCode><ns1:prescriptionCode>1</ns1:prescriptionCode><ns1:withdrawalDate>2005-02-28</ns1:withdrawalDate><ns1:hasRecommendedArticle>false</ns1:hasRecommendedArticle><ns1:silDeviationCode></ns1:silDeviationCode></ns1:return></ns1:getDrugByDrugIdResponse></soapenv:Body></soapenv:Envelope>" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axiom.om.util.StAXUtils - XMLStreamReader is com.ctc.wstx.sr.ValidatingStreamReader 2009-10-26 16:48:02,837 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:48:02,837 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://schemas.xmlsoap.org/soap/envelope/}Envelope 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Starting to process SOAP 1.1 message 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement Envelope by the StaxSOAPModelBuilder 2009-10-26 16:48:02,837 [main] TRACE org.apache.axis2.engine.AxisEngine - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] receive:urn:uuid:D19A3745E4C2A334441256572123883 2009-10-26 16:48:02,837 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:48:02,837 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://schemas.xmlsoap.org/soap/envelope/}Body 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement Body by the StaxSOAPModelBuilder 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking pre-condition for Phase "Transport" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking phase "Transport" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking Handler 'RequestURIBasedDispatcher' in Phase 'Transport' 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking Handler 'SOAPActionBasedDispatcher' in Phase 'Transport' 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking post-conditions for phase "Transport" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking pre-condition for Phase "Addressing" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking phase "Addressing" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking Handler 'AddressingBasedDispatcher' in Phase 'Addressing' 2009-10-26 16:48:02,837 [main] TRACE org.apache.axis2.dispatchers.AddressingBasedDispatcher - invoke: IS_ADDR_INFO_ALREADY_PROCESSED=null 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking post-conditions for phase "Addressing" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking pre-condition for Phase "Security" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking phase "Security" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking post-conditions for phase "Security" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking pre-condition for Phase "PreDispatch" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking phase "PreDispatch" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking post-conditions for phase "PreDispatch" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking pre-condition for Phase "Dispatch" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking phase "Dispatch" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking Handler 'RequestURIBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking Handler 'SOAPActionBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking Handler 'RequestURIOperationDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking Handler 'SOAPMessageBodyBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking Handler 'HTTPLocationBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking post-conditions for phase "Dispatch" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking pre-condition for Phase "RMPhase" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking phase "RMPhase" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking post-conditions for phase "RMPhase" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking pre-condition for Phase "OperationInPhase" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking phase "OperationInPhase" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Checking post-conditions for phase "OperationInPhase" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() in Phase "OperationInPhase" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() in Phase "RMPhase" 2009-10-26 16:48:02,837 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() in Phase "Dispatch" 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() for Handler 'HTTPLocationBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() for Handler 'SOAPMessageBodyBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() for Handler 'RequestURIOperationDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() for Handler 'SOAPActionBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() for Handler 'RequestURIBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() in Phase "PreDispatch" 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() in Phase "Security" 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() in Phase "Addressing" 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() for Handler 'AddressingBasedDispatcher' in Phase 'Addressing' 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() in Phase "Transport" 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() for Handler 'SOAPActionBasedDispatcher' in Phase 'Transport' 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:D19A3745E4C2A334441256572123916] Invoking flowComplete() for Handler 'RequestURIBasedDispatcher' in Phase 'Transport' 2009-10-26 16:48:02,853 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:48:02,853 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://main.axis2.sil}getDrugByDrugIdResponse 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement getDrugByDrugIdResponse by the StaxSOAPModelBuilder 2009-10-26 16:48:02,853 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:48:02,853 [main] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://main.axis2.sil}return 2009-10-26 16:48:02,853 [main] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement return by the StaxSOAPModelBuilder 2009-10-26 16:48:02,853 [main] DEBUG httpclient.wire.content - << "[\r]" 2009-10-26 16:48:02,853 [main] DEBUG httpclient.wire.content - << "[\n]" 2009-10-26 16:48:02,853 [main] DEBUG httpclient.wire.content - << "0" 2009-10-26 16:48:02,853 [main] DEBUG httpclient.wire.content - << "[\r]" 2009-10-26 16:48:02,853 [main] DEBUG httpclient.wire.content - << "[\n]" 2009-10-26 16:48:02,853 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HeaderParser.parseHeaders(InputStream, String) 2009-10-26 16:48:02,853 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readLine(InputStream, String) 2009-10-26 16:48:02,853 [main] TRACE org.apache.commons.httpclient.HttpParser - enter HttpParser.readRawLine() 2009-10-26 16:48:02,853 [main] DEBUG httpclient.wire.content - << "[\r]" 2009-10-26 16:48:02,853 [main] DEBUG httpclient.wire.content - << "[\n]" 2009-10-26 16:48:02,853 [main] DEBUG httpclient.wire.header - << "[\r][\n]" 2009-10-26 16:48:02,853 [main] DEBUG org.apache.commons.httpclient.HttpMethodBase - Resorting to protocol version default close connection policy 2009-10-26 16:48:02,853 [main] DEBUG org.apache.commons.httpclient.HttpMethodBase - Should NOT close connection, using HTTP/1.1 2009-10-26 16:48:02,853 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.isResponseAvailable() 2009-10-26 16:48:02,853 [main] TRACE org.apache.commons.httpclient.HttpConnection - enter HttpConnection.releaseConnection() 2009-10-26 16:48:02,853 [main] DEBUG org.apache.commons.httpclient.HttpConnection - Releasing connection back to connection manager. 2009-10-26 16:48:02,853 [main] TRACE org.apache.commons.httpclient.MultiThreadedHttpConnectionManager - enter HttpConnectionManager.releaseConnection(HttpConnection) 2009-10-26 16:48:02,853 [main] DEBUG org.apache.commons.httpclient.MultiThreadedHttpConnectionManager - Freeing connection, hostConfig=HostConfiguration[host=http://192.168.18.18:8080] 2009-10-26 16:48:02,853 [main] TRACE org.apache.commons.httpclient.MultiThreadedHttpConnectionManager - enter HttpConnectionManager.ConnectionPool.getHostPool(HostConfiguration) 2009-10-26 16:48:02,853 [main] DEBUG org.apache.commons.httpclient.util.IdleConnectionHandler - Adding connection at: 1256572082853 2009-10-26 16:48:02,853 [main] DEBUG org.apache.commons.httpclient.MultiThreadedHttpConnectionManager - Notifying no-one, there are no waiting threads ********************************************************************************************************************* SERVER LOG: . . . 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.builder.BuilderUtil - Input contentType (text/xml; charset=UTF-8) 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.builder.BuilderUtil - CharSetEncoding from content-type (UTF-8) 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.transport.TransportUtils - createSOAPEnvelope using Builder (class org.apache.axis2.builder.SOAPBuilder) selected from type (text/xml) 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.builder.BuilderUtil - char set encoding set from default =UTF-8 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axiom.om.util.StAXUtils - XMLStreamReader is com.ctc.wstx.sr.ValidatingStreamReader 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://schemas.xmlsoap.org/soap/envelope/}Envelope 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Starting to process SOAP 1.1 message 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement Envelope by the StaxSOAPModelBuilder 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axis2.engine.AxisEngine - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] receive:null 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://schemas.xmlsoap.org/soap/envelope/}Body 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement Body by the StaxSOAPModelBuilder 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking pre-condition for Phase "Transport" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking phase "Transport" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'RequestURIBasedDispatcher' in Phase 'Transport' 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.dispatchers.RequestURIBasedServiceDispatcher - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking for Service using target endpoint address : http://192.168.18.18:8080/axis2/services/SilDB2 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.util.Utils - parseRequestURLForServiceAndOperation : [http://192.168.18.18:8080/axis2/services/SilDB2][/axis2/services] 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.i18n.ProjectResourceBundle - org.apache.axis2.i18n.resource::handleGetObject(servicefound) 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.AbstractDispatcher - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Found AxisService : SilDB2 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'SOAPActionBasedDispatcher' in Phase 'Transport' 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.dispatchers.ActionBasedOperationDispatcher - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking for Operation using Action : http://main.axis2.sil/SilDB2/getDrugByDrugIdRequest 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.description.AxisService - getOperationBySOAPAction: Operation (org.apache.axis2.description.InOutAxisOperation@1469658,{http://main.axis2.sil}getDrugByDrugId) for soapAction: http://main.axis2.sil/SilDB2/getDrugByDrugIdRequest found in action map. 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.i18n.ProjectResourceBundle - org.apache.axis2.i18n.resource::handleGetObject(operationfound) 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.AbstractDispatcher - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Found AxisOperation : getDrugByDrugId 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking post-conditions for phase "Transport" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking pre-condition for Phase "Addressing" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking phase "Addressing" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'AddressingInHandler' in Phase 'Addressing' 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'AddressingBasedDispatcher' in Phase 'Addressing' 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axis2.dispatchers.AddressingBasedDispatcher - invoke: IS_ADDR_INFO_ALREADY_PROCESSED=false 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking post-conditions for phase "Addressing" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking pre-condition for Phase "Security" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking phase "Security" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking post-conditions for phase "Security" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking pre-condition for Phase "PreDispatch" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking phase "PreDispatch" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking post-conditions for phase "PreDispatch" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking pre-condition for Phase "Dispatch" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking phase "Dispatch" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'RequestURIBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'SOAPActionBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'RequestURIOperationDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'SOAPMessageBodyBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'AddressingValidationHandler' in Phase 'Dispatch' 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axis2.handlers.addressing.AddressingValidationHandler - invoke: IS_ADDR_INFO_ALREADY_PROCESSED=false 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.addressing.AddressingHelper - getAddressingRequirementParemeterValue: value: 'null' 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axis2.handlers.addressing.AddressingValidationHandler - checkUsingAddressing: WSAddressingFlag=unspecified 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.addressing.AddressingHelper - getInvocationPatternParameterValue: value: 'null' 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axis2.handlers.addressing.AddressingValidationHandler - checkWSAMInvocationPattern: value=both 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'HTTPLocationBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'GenericProviderDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'MustUnderstandValidationDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.jaxws.dispatchers.MustUnderstandValidationDispatcher - JAXWS MustUnderstandValidationDispatcher.invoke on AxisService SilDB2; AxisOperation org.apache.axis2.description.InOutAxisOperation@1469658 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking post-conditions for phase "Dispatch" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.addressing.AddressingHelper - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] isReplyRedirected: ReplyTo is null. Returning false 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking pre-condition for Phase "RMPhase" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking phase "RMPhase" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking post-conditions for phase "RMPhase" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking pre-condition for Phase "OperationInPhase" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking phase "OperationInPhase" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'MustUnderstandChecker' in Phase 'OperationInPhase' 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking post-conditions for phase "OperationInPhase" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking pre-condition for Phase "soapmonitorPhase" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking phase "soapmonitorPhase" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking post-conditions for phase "soapmonitorPhase" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking pre-condition for Phase "loggingPhase" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking phase "loggingPhase" 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking Handler 'null' in Phase 'loggingPhase' 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axiom.om.util.StAXUtils - XMLStreamWriter is com.ctc.wstx.sw.SimpleNsStreamWriter 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.MTOMXMLStreamWriter - Call Stack =DEBUG_FRAME = org.apache.axiom.om.util.CommonUtils.callStackToString(CommonUtils.java:80) DEBUG_FRAME = org.apache.axiom.om.impl.MTOMXMLStreamWriter.<init>(MTOMXMLStreamWriter.java:74) DEBUG_FRAME = org.apache.axiom.om.impl.llom.OMNodeImpl.serialize(OMNodeImpl.java:384) DEBUG_FRAME = org.apache.axiom.om.impl.llom.OMElementImpl.toString(OMElementImpl.java:1106) DEBUG_FRAME = userguide.loggingmodule.LogHandler.invoke(Unknown Source) DEBUG_FRAME = org.apache.axis2.engine.Phase.invoke(Phase.java:318) DEBUG_FRAME = org.apache.axis2.engine.AxisEngine.invoke(AxisEngine.java:251) DEBUG_FRAME = org.apache.axis2.engine.AxisEngine.receive(AxisEngine.java:160) DEBUG_FRAME = org.apache.axis2.transport.http.HTTPTransportUtils.processHTTPPostRequest(HTTPTransportUtils.java:167) DEBUG_FRAME = org.apache.axis2.transport.http.AxisServlet.doPost(AxisServlet.java:142) DEBUG_FRAME = javax.servlet.http.HttpServlet.service(HttpServlet.java:637) DEBUG_FRAME = javax.servlet.http.HttpServlet.service(HttpServlet.java:717) DEBUG_FRAME = org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) DEBUG_FRAME = org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) DEBUG_FRAME = org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) DEBUG_FRAME = org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) DEBUG_FRAME = org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128) DEBUG_FRAME = org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) DEBUG_FRAME = org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) DEBUG_FRAME = org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) DEBUG_FRAME = org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:849) DEBUG_FRAME = org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583) DEBUG_FRAME = org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:454) DEBUG_FRAME = java.lang.Thread.run(Thread.java:619) 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://main.axis2.sil}getDrugByDrugId 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement getDrugByDrugId by the StaxSOAPModelBuilder 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://main.axis2.sil}param0 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement param0 by the StaxSOAPModelBuilder 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - CHARACTERS: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - END_ELEMENT: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://main.axis2.sil}param0 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://main.axis2.sil}param1 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement param1 by the StaxSOAPModelBuilder 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - CHARACTERS: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - END_ELEMENT: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://main.axis2.sil}param1 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - START_ELEMENT: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://main.axis2.sil}param2 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axiom.soap.impl.builder.StAXSOAPModelBuilder - Build the OMElement param2 by the StaxSOAPModelBuilder 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - CHARACTERS: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - END_ELEMENT: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://main.axis2.sil}param2 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - END_ELEMENT: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://main.axis2.sil}getDrugByDrugId 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - END_ELEMENT: 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axiom.om.impl.builder.StAXOMBuilder - QName: {http://schemas.xmlsoap.org/soap/envelope/}Body 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - Calling MTOMXMLStreamWriter.flush 2009-10-26 16:47:41,916 [http-8080-1] INFO userguide.loggingmodule.LogHandler - <?xml version='1.0' encoding='utf-8'?><soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"><soapenv:Body><main:getDrugByDrugId xmlns:main="http://main.axis2.sil"><main:param0>20040607010594</main:param0><main:param1>false</main:param1><main:param2>-1</main:param2></main:getDrugByDrugId></soapenv:Body></soapenv:Envelope> 2009-10-26 16:47:41,916 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Checking post-conditions for phase "loggingPhase" 2009-10-26 16:47:41,916 [http-8080-1] TRACE org.apache.axis2.addressing.EndpointReference - hasAnonymousAddress: http://www.w3.org/2005/08/addressing/anonymous is Anonymous: true 2009-10-26 16:47:41,932 [http-8080-1] TRACE org.apache.axis2.addressing.EndpointReference - hasAnonymousAddress: http://www.w3.org/2005/08/addressing/anonymous is Anonymous: true 2009-10-26 16:47:41,932 [http-8080-1] DEBUG org.apache.axis2.context.ConfigurationContext - messageID is null. 2009-10-26 16:47:41,932 [http-8080-1] DEBUG org.apache.axiom.om.util.OMXMLStreamReaderValidator - An END_ELEMENT event for {http://main.axis2.sil}getDrugByDrugId was encountered. But this does match the corresponding START_ELEMENT {http://main.axis2.sil}param2 event. 2009-10-26 16:47:41,995 [http-8080-1] TRACE org.apache.axis2.engine.AxisEngine - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] send:null 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking pre-condition for Phase "loggingPhase" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking phase "loggingPhase" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking Handler 'null' in Phase 'loggingPhase' 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axiom.om.util.StAXUtils - XMLStreamWriter is com.ctc.wstx.sw.SimpleNsStreamWriter 2009-10-26 16:47:41,995 [http-8080-1] TRACE org.apache.axiom.om.impl.MTOMXMLStreamWriter - Call Stack =DEBUG_FRAME = org.apache.axiom.om.util.CommonUtils.callStackToString(CommonUtils.java:80) DEBUG_FRAME = org.apache.axiom.om.impl.MTOMXMLStreamWriter.<init>(MTOMXMLStreamWriter.java:74) DEBUG_FRAME = org.apache.axiom.om.impl.llom.OMNodeImpl.serialize(OMNodeImpl.java:384) DEBUG_FRAME = org.apache.axiom.om.impl.llom.OMElementImpl.toString(OMElementImpl.java:1106) DEBUG_FRAME = userguide.loggingmodule.LogHandler.invoke(Unknown Source) DEBUG_FRAME = org.apache.axis2.engine.Phase.invoke(Phase.java:318) DEBUG_FRAME = org.apache.axis2.engine.AxisEngine.invoke(AxisEngine.java:251) DEBUG_FRAME = org.apache.axis2.engine.AxisEngine.send(AxisEngine.java:416) DEBUG_FRAME = org.apache.axis2.receivers.AbstractInOutMessageReceiver.invokeBusinessLogic(AbstractInOutMessageReceiver.java:43) DEBUG_FRAME = org.apache.axis2.receivers.AbstractMessageReceiver.receive(AbstractMessageReceiver.java:114) DEBUG_FRAME = org.apache.axis2.engine.AxisEngine.receive(AxisEngine.java:173) DEBUG_FRAME = org.apache.axis2.transport.http.HTTPTransportUtils.processHTTPPostRequest(HTTPTransportUtils.java:167) DEBUG_FRAME = org.apache.axis2.transport.http.AxisServlet.doPost(AxisServlet.java:142) DEBUG_FRAME = javax.servlet.http.HttpServlet.service(HttpServlet.java:637) DEBUG_FRAME = javax.servlet.http.HttpServlet.service(HttpServlet.java:717) DEBUG_FRAME = org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) DEBUG_FRAME = org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) DEBUG_FRAME = org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) DEBUG_FRAME = org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) DEBUG_FRAME = org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128) DEBUG_FRAME = org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) DEBUG_FRAME = org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) DEBUG_FRAME = org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) DEBUG_FRAME = org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:849) DEBUG_FRAME = org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583) DEBUG_FRAME = org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:454) DEBUG_FRAME = java.lang.Thread.run(Thread.java:619) 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - Calling MTOMXMLStreamWriter.flush 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - Calling MTOMXMLStreamWriter.flush 2009-10-26 16:47:41,995 [http-8080-1] INFO userguide.loggingmodule.LogHandler - <?xml version='1.0' encoding='utf-8'?><soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"><soapenv:Body><ns1:getDrugByDrugIdResponse xmlns:ns1="http://main.axis2.sil"><ns1:return><ns1:drugId>20040607010594</ns1:drugId><ns1:tradeName>Ramipril Durascan</ns1:tradeName><ns1:strengthNumeric>1.25</ns1:strengthNumeric><ns1:strengthNumericUnit>mg</ns1:strengthNumericUnit><ns1:strengthText>1,25 mg</ns1:strengthText><ns1:drugFormCode>CAPHAR</ns1:drugFormCode><ns1:drugFormTextSv>Kapsel, hård</ns1:drugFormTextSv><ns1:drugClassificationCode>-</ns1:drugClassificationCode><ns1:controlClassCode>0</ns1:controlClassCode><ns1:routeOfAdministrationCodes>-</ns1:routeOfAdministrationCodes><ns1:prescriberCodes>1</ns1:prescriberCodes><ns1:interchangeableFlag>N</ns1:interchangeableFlag><ns1:substanceGroupId>0</ns1:substanceGroupId><ns1:substanceGroupName></ns1:substanceGroupName><ns1:strengthGroupId>0</ns1:strengthGroupId><ns1:strengthGroupName></ns1:strengthGroupName><ns1:pharmaceuticalFormGroupId>0</ns1:pharmaceuticalFormGroupId><ns1:pharmaceuticalFormGroupName></ns1:pharmaceuticalFormGroupName><ns1:lactationGroup>?</ns1:lactationGroup><ns1:pregnancyCategory>?</ns1:pregnancyCategory><ns1:interactionStatus>1</ns1:interactionStatus><ns1:productTypeCode>MEP</ns1:productTypeCode><ns1:prescriptionCode>1</ns1:prescriptionCode><ns1:withdrawalDate>2005-02-28</ns1:withdrawalDate><ns1:hasRecommendedArticle>false</ns1:hasRecommendedArticle><ns1:silDeviationCode></ns1:silDeviationCode></ns1:return></ns1:getDrugByDrugIdResponse></soapenv:Body></soapenv:Envelope> 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking post-conditions for phase "loggingPhase" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking pre-condition for Phase "soapmonitorPhase" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking phase "soapmonitorPhase" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking post-conditions for phase "soapmonitorPhase" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking pre-condition for Phase "OperationOutPhase" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking phase "OperationOutPhase" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking Handler 'DispatchOperationHandler' in Phase 'OperationOutPhase' 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking post-conditions for phase "OperationOutPhase" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking pre-condition for Phase "RMPhase" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking phase "RMPhase" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking post-conditions for phase "RMPhase" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking pre-condition for Phase "PolicyDetermination" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking phase "PolicyDetermination" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking post-conditions for phase "PolicyDetermination" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking pre-condition for Phase "MessageOut" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking phase "MessageOut" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking Handler 'AddressingOutHandler' in Phase 'MessageOut' 2009-10-26 16:47:41,995 [http-8080-1] TRACE org.apache.axis2.handlers.addressing.AddressingOutHandler - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Addressing is disabled. Not adding WS-Addressing headers. 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking post-conditions for phase "MessageOut" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking pre-condition for Phase "Security" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking phase "Security" 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Checking post-conditions for phase "Security" 2009-10-26 16:47:41,995 [http-8080-1] TRACE org.apache.axis2.addressing.EndpointReference - hasAnonymousAddress: http://www.w3.org/2005/08/addressing/anonymous is Anonymous: true 2009-10-26 16:47:41,995 [http-8080-1] DEBUG org.apache.axiom.om.OMOutputFormat - Start getContentType: OMOutputFormat [ mimeBoundary =null rootContentId=null doOptimize=false doingSWA=false isSOAP11=true charSetEncoding=UTF-8 xmlVersion=null contentType=null ignoreXmlDeclaration=false autoCloseWriter=true actionProperty=null optimizedThreshold=0] 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axiom.om.OMOutputFormat - getContentType= {text/xml} OMOutputFormat [ mimeBoundary =null rootContentId=null doOptimize=false doingSWA=false isSOAP11=true charSetEncoding=UTF-8 xmlVersion=null contentType=text/xml ignoreXmlDeclaration=false autoCloseWriter=true actionProperty=null optimizedThreshold=0] 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - contentType from the OMOutputFormat =text/xml 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - contentType returned =text/xml; charset=UTF-8 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - start writeTo() 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - preserve=false 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - isOptimized=false 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - isDoingSWA=false 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.util.Utils - MTOM optimized Threshold value =0 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - OutputStream =class java.io.BufferedOutputStream 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - OMFormat = OMOutputFormat [ mimeBoundary =null rootContentId=null doOptimize=false doingSWA=false isSOAP11=true charSetEncoding=UTF-8 xmlVersion=null contentType=text/xml ignoreXmlDeclaration=false autoCloseWriter=true actionProperty=null optimizedThreshold=0] 2009-10-26 16:47:42,010 [http-8080-1] TRACE org.apache.axiom.om.impl.MTOMXMLStreamWriter - Call Stack =DEBUG_FRAME = org.apache.axiom.om.util.CommonUtils.callStackToString(CommonUtils.java:80) DEBUG_FRAME = org.apache.axiom.om.impl.MTOMXMLStreamWriter.<init>(MTOMXMLStreamWriter.java:94) DEBUG_FRAME = org.apache.axiom.om.impl.llom.OMNodeImpl.serializeAndConsume(OMNodeImpl.java:485) DEBUG_FRAME = org.apache.axis2.transport.http.SOAPMessageFormatter.writeTo(SOAPMessageFormatter.java:79) DEBUG_FRAME = org.apache.axis2.transport.http.CommonsHTTPTransportSender.sendUsingOutputStream(CommonsHTTPTransportSender.java:358) DEBUG_FRAME = org.apache.axis2.transport.http.CommonsHTTPTransportSender.invoke(CommonsHTTPTransportSender.java:235) DEBUG_FRAME = org.apache.axis2.engine.AxisEngine.send(AxisEngine.java:435) DEBUG_FRAME = org.apache.axis2.receivers.AbstractInOutMessageReceiver.invokeBusinessLogic(AbstractInOutMessageReceiver.java:43) DEBUG_FRAME = org.apache.axis2.receivers.AbstractMessageReceiver.receive(AbstractMessageReceiver.java:114) DEBUG_FRAME = org.apache.axis2.engine.AxisEngine.receive(AxisEngine.java:173) DEBUG_FRAME = org.apache.axis2.transport.http.HTTPTransportUtils.processHTTPPostRequest(HTTPTransportUtils.java:167) DEBUG_FRAME = org.apache.axis2.transport.http.AxisServlet.doPost(AxisServlet.java:142) DEBUG_FRAME = javax.servlet.http.HttpServlet.service(HttpServlet.java:637) DEBUG_FRAME = javax.servlet.http.HttpServlet.service(HttpServlet.java:717) DEBUG_FRAME = org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) DEBUG_FRAME = org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) DEBUG_FRAME = org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) DEBUG_FRAME = org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) DEBUG_FRAME = org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128) DEBUG_FRAME = org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) DEBUG_FRAME = org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) DEBUG_FRAME = org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) DEBUG_FRAME = org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:849) DEBUG_FRAME = org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583) DEBUG_FRAME = org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:454) DEBUG_FRAME = java.lang.Thread.run(Thread.java:619) 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axiom.om.util.StAXUtils - XMLStreamWriter is com.ctc.wstx.sw.SimpleNsStreamWriter 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axiom.om.impl.llom.OMSourcedElementImpl - serialize {http://main.axis2.sil}getDrugByDrugIdResponse to XMLStreamWriter 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - Calling MTOMXMLStreamWriter.flush 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - Calling MTOMXMLStreamWriter.flush 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axiom.om.impl.MTOMXMLStreamWriter - close 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.transport.http.SOAPMessageFormatter - end writeTo() 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.transport.TransportUtils - Found RequestResponseTransport setting response written 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking flowComplete() in Phase "Security" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking flowComplete() in Phase "MessageOut" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking flowComplete() for Handler 'AddressingOutHandler' in Phase 'MessageOut' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking flowComplete() in Phase "PolicyDetermination" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking flowComplete() in Phase "RMPhase" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking flowComplete() in Phase "OperationOutPhase" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking flowComplete() for Handler 'DispatchOperationHandler' in Phase 'OperationOutPhase' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking flowComplete() in Phase "soapmonitorPhase" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking flowComplete() in Phase "loggingPhase" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089525] Invoking flowComplete() for Handler 'null' in Phase 'loggingPhase' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() in Phase "loggingPhase" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'null' in Phase 'loggingPhase' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() in Phase "soapmonitorPhase" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() in Phase "OperationInPhase" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'MustUnderstandChecker' in Phase 'OperationInPhase' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() in Phase "RMPhase" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() in Phase "Dispatch" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'MustUnderstandValidationDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'GenericProviderDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'HTTPLocationBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'AddressingValidationHandler' in Phase 'Dispatch' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'SOAPMessageBodyBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'RequestURIOperationDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'SOAPActionBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'RequestURIBasedDispatcher' in Phase 'Dispatch' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() in Phase "PreDispatch" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() in Phase "Security" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() in Phase "Addressing" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'AddressingBasedDispatcher' in Phase 'Addressing' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'AddressingInHandler' in Phase 'Addressing' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() in Phase "Transport" 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'SOAPActionBasedDispatcher' in Phase 'Transport' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.engine.Phase - [MessageContext: logID=urn:uuid:64F72C5F5C41FBA2071256572089445] Invoking flowComplete() for Handler 'RequestURIBasedDispatcher' in Phase 'Transport' 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.transport.TransportUtils - Found RequestResponseTransport returning isResponseWritten() 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.transport.TransportUtils - Entering deleteAttachments() 2009-10-26 16:47:42,010 [http-8080-1] DEBUG org.apache.axis2.transport.TransportUtils - Exiting deleteAttachments() Windows Live: Keep your friends up to date with what you do online. |
| Free embeddable forum powered by Nabble | Forum Help |
