Forum Discussion

HHaynes's avatar
HHaynes
Contributor
15 years ago

keystore MD5 error when loading soapUI test into agent

Using the latest daily build of 1.5.1 on both client and agents I'm getting a stack trace on the agent side that seems to show some issue with caching the soapUI test on the agent side:
13:09:06,809 INFO  [ControllerImpl] Agent started and listening on cometd!
13:10:29,592 INFO [ControllerImpl] Client connected
13:10:58,655 INFO [ControllerImpl] Loading SceneItem cff28969-cece-4379-b3f0-b9de48269794
13:10:59,389 INFO [HttpClientSupport$Helper] Updating keyStore..
13:10:59,389 INFO [HttpClientSupport$Helper] Updating keyStore..
13:11:02,715 INFO [GroovyComponentClassLoader] Loading dependency: net.sf.opencsv:opencsv
13:11:04,122 INFO [ControllerImpl] Started scene: TestCase
13:11:05,653 INFO [DefaultSoapUICore] Importing preferences from [C:\Documents and Settings\Otto\.l
oadui\fileStorage\d619b0348873e431f4b34606f4f622ae]
13:11:05,700 WARN [DefaultSoapUICore] Failed to load settings from [C:\Documents and Settings\Otto\
.loadui\fileStorage\d619b0348873e431f4b34606f4f622ae:1:1: error: Unexpected element: CDATA], creatin
g new
13:11:05,715 INFO [HttpClientSupport$Helper] Updating keyStore..
13:11:05,715 INFO [DefaultSoapUICore] Importing preferences from [C:\Documents and Settings\Otto\.l
oadui\fileStorage\d619b0348873e431f4b34606f4f622ae]
13:11:05,715 WARN [DefaultSoapUICore] Failed to load settings from [C:\Documents and Settings\Otto\
.loadui\fileStorage\d619b0348873e431f4b34606f4f622ae:1:1: error: Unexpected element: CDATA], creatin
g new
13:11:05,731 INFO [HttpClientSupport$Helper] Updating keyStore..
13:11:12,403 ERROR [ReferenceToFileConverter] File transfered with MD5 hash: d75e8f8f5a2e7d0189a15ab
74838f6bb, should be fe97623d50105d25f9b373909a2d989c. Retrying...
13:11:19,200 ERROR [ReferenceToFileConverter] File transfered with MD5 hash: 75607f7e9ea1a9e46c951b9
0035833b6, should be fe97623d50105d25f9b373909a2d989c. Retrying...
13:11:25,997 ERROR [ReferenceToFileConverter] File transfered with MD5 hash: 6a42f19e65e7ae14eba0c23
42f2a3d52, should be fe97623d50105d25f9b373909a2d989c. Retrying...
13:11:33,403 INFO [SoapUIProjectLoader] Caching soapUI project at [C:\Documents and Settings\Otto\.
loadui\fileStorage\fe97623d50105d25f9b373909a2d989c]
13:11:33,528 INFO [WsdlProject] Loaded project from [file:/C:/Documents%20and%20Settings/Otto/.load
ui/fileStorage/fe97623d50105d25f9b373909a2d989c]
13:11:34,168 WARN [SoapUIProGroovyScriptEngineFactory] Missing scripts folder [C:\Program Files\evi
ware\loadUI-Agent-1.5.0-SNAPSHOT\scripts]
13:11:55,231 ERROR [WsdlSubmit] Exception in request: java.net.SocketException: Socket Closed
13:11:55,231 ERROR [SoapUI] An error occured [Socket Closed], see error log for details
java.net.SocketException: Socket Closed
at java.net.PlainSocketImpl.setOption(Unknown Source)
at java.net.Socket.setTcpNoDelay(Unknown Source)
at com.sun.net.ssl.internal.ssl.BaseSSLSocketImpl.setTcpNoDelay(Unknown Source)
at org.apache.commons.httpclient.HttpConnection.open(HttpConnection.java:721)
at com.eviware.soapui.impl.wsdl.support.http.SoapUIMultiThreadedHttpConnectionManager$HttpCo
nnectionAdapter.open(SoapUIMultiThreadedHttpConnectionManager.java:1637)
at org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java
:387)
at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:17
1)
at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397)
at com.eviware.soapui.impl.wsdl.submit.transports.http.HttpClientRequestTransport.sendReques
t(HttpClientRequestTransport.java:202)
at com.eviware.soapui.impl.wsdl.WsdlSubmit.run(WsdlSubmit.java:123)
at com.eviware.soapui.impl.wsdl.WsdlSubmit.submitRequest(WsdlSubmit.java:76)
at com.eviware.soapui.impl.wsdl.WsdlRequest.submit(WsdlRequest.java:238)
at com.eviware.soapui.impl.wsdl.teststeps.WsdlTestRequestStep.run(WsdlTestRequestStep.java:3
66)
at com.eviware.soapui.impl.wsdl.support.AbstractTestCaseRunner.runTestStep(AbstractTestCaseR
unner.java:232)
at com.eviware.soapui.impl.wsdl.testcase.WsdlTestCaseRunner.runCurrentTestStep(WsdlTestCaseR
unner.java:48)
at com.eviware.soapui.impl.wsdl.support.AbstractTestCaseRunner.internalRun(AbstractTestCaseR
unner.java:141)
at com.eviware.soapui.impl.wsdl.support.AbstractTestCaseRunner.internalRun(AbstractTestCaseR
unner.java:42)
at com.eviware.soapui.impl.wsdl.support.AbstractTestRunner.run(AbstractTestRunner.java:135)
at com.eviware.loadui.components.soapui.SoapUISamplerComponent$SoapUITestCaseRunner.run(Soap
UISamplerComponent.java:905)
at com.eviware.loadui.components.soapui.SoapUISamplerComponent.sample(SoapUISamplerComponent
.java:761)
at com.eviware.loadui.impl.component.categories.RunnerBase.doSample(RunnerBase.java:482)
at com.eviware.loadui.impl.component.categories.RunnerBase.access$700(RunnerBase.java:68)
at com.eviware.loadui.impl.component.categories.RunnerBase$Worker.run(RunnerBase.java:759)
at com.eviware.loadui.util.dispatch.CustomThreadPoolExecutor$Worker.run(CustomThreadPoolExec
utor.java:188)
at java.lang.Thread.run(Unknown Source)
13:12:15,826 INFO [ControllerImpl] Client disconnected
13:12:15,826 INFO [ControllerImpl] Stopping scene: TestCase
13:12:15,888 INFO [SoapUIProjectLoader] Releasing soapUI project [TAP-ProdVerification]

24 Replies

  • Hi,

    Could you try updating to the latest nightly build again and testing it once more? Hopefully it will run better now.

    Regards,
    Dain
    eviware.com
  • Looks like the latest loadUI-agent-1.5.0-SNAPSHOT (13/06/2011) completely corrects the MD 5 errors:

    10:20:56,051 INFO [ControllerImpl] Client connected
    10:20:58,752 INFO [ControllerImpl] Loading SceneItem cff28969-cece-4379-b3f0-b9de48269794
    10:20:59,599 INFO [HttpClientSupport$Helper] Updating keyStore..
    10:20:59,601 INFO [HttpClientSupport$Helper] Updating keyStore..
    10:21:02,054 INFO [GroovyComponentClassLoader] Loading dependency: net.sf.opencsv:opencsv
    10:21:03,426 INFO [ControllerImpl] Started scene: AddTicketCancelCart
    10:21:05,907 INFO [DefaultSoapUICore] Importing preferences from [/home/test/.loadui/fileStorage/ec4d46fd203c81de45f7ec3f1df783d2]
    10:21:05,914 INFO [DefaultSoapUICore] initialized soapui-settings from [/home/test/.loadui/fileStorage/ec4d46fd203c81de45f7ec3f1df783d2]
    10:21:05,932 INFO [HttpClientSupport$Helper] Updating keyStore..
    10:21:05,932 INFO [HttpClientSupport$Helper] Initializing KeyStore
    10:21:05,932 INFO [DefaultSoapUICore] Importing preferences from [/home/test/.loadui/fileStorage/ec4d46fd203c81de45f7ec3f1df783d2]
    10:21:05,934 INFO [HttpClientSupport$Helper] Updating keyStore..
    10:21:05,934 INFO [HttpClientSupport$Helper] Initializing KeyStore
    10:21:05,940 INFO [SoapUIProjectLoader] Caching soapUI project at [/home/test/.loadui/fileStorage/d8e1f45c42883e8b85e1cf9ddae99104_working_copy/TAP-ProdVerification-soapui-project.xml]
    10:21:06,193 INFO [WsdlProject] Loaded project from [file:/home/test/.loadui/fileStorage/d8e1f45c42883e8b85e1cf9ddae99104_working_copy/TAP-ProdVerification-soapui-project.xml]
    10:21:06,543 WARN [SoapUIProGroovyScriptEngineFactory] Missing scripts folder [/home/test/.loadui/custom-soapui-scripts]
    10:21:17,570 INFO [log] [53] SCENARIO START
    10:21:17,571 INFO [log] [53] AuthToken and AuthData set
    10:21:17,571 INFO [log] [56] SCENARIO START
    10:21:17,572 INFO [log] [56] AuthToken and AuthData set
    10:21:17,573 INFO [log] [58] SCENARIO START
    10:21:17,573 INFO [log] [58] AuthToken and AuthData set
    10:21:17,595 INFO [log] [56] User value set [tap.la.testuser+1@gmail.com].
    10:21:17,597 INFO [log] [53] User value set [tap.la.testuser+6@gmail.com].
    10:21:17,618 INFO [log] [58] User value set [tap.la.testuser+3@gmail.com].
    10:21:17,683 INFO [log] [53] randomMarketID set [36]
    10:21:17,706 INFO [log] [58] randomMarketID set [17]
    10:21:17,717 INFO [log] [56] randomMarketID set [10]
    10:21:19,182 INFO [log] [62] SCENARIO START
    10:21:19,182 INFO [log] [62] AuthToken and AuthData set
    10:21:19,183 INFO [log] [62] User value set [tap.la.testuser+4@gmail.com].
    10:21:19,186 INFO [log] [62] randomMarketID set [3]
    10:21:20,918 INFO [log] [58] events in Spotlight/Popular response [10] targetedEvent [1] eventID [2200454BB0E4422F]
    10:21:23,149 INFO [log] [62] events in Spotlight/Popular response [10] targetedEvent [9] eventID [0400467EFC235857]
    10:21:23,820 INFO [log] [53] events in Spotlight/Popular response [10] targetedEvent [2] eventID [1900459500612595]
    10:21:24,115 INFO [log] [58] eventArtist [857535] eventVenue [278910]
    10:21:25,329 INFO [log] [56] events in Spotlight/Popular response [10] targetedEvent [7] eventID [0E004661A74198EA]
    10:21:25,984 INFO [log] [62] eventArtist [762799] eventVenue [32837]
    10:21:26,197 INFO [log] [58] Get VenueDetails Complete. Going to Add TicketsNewCart
    10:21:26,960 INFO [log] [53] eventArtist [807344] eventVenue [205079]
    10:21:27,934 INFO [log] [62] Get VenueDetails Complete. Going to Add TicketsNewCart
    10:21:28,031 INFO [log] [58] Ticket price 141.21. Going to GetCart1.
    10:21:28,639 INFO [log] [53] Get VenueDetails Complete. Going to Add TicketsNewCart
    10:21:28,922 INFO [log] [56] eventArtist [748766] eventVenue [115485]
    10:21:29,406 INFO [log] [58] GetCart1 Complete. Going to GetUpsells
    10:21:29,711 INFO [log] [58] No upsells available for event. Going to Delay5.
    10:21:31,112 INFO [log] [58] GetCart2 Complete. Going to GetDeliveryInstruction
    10:21:31,149 INFO [log] [56] Get VenueDetails Complete. Going to Add TicketsNewCart
    10:21:31,442 INFO [log] [58] Going to addDeliveryInstruction
    10:21:31,721 INFO [log] [62] Ticket price 79.50. Going to GetCart1.
    10:21:31,796 INFO [log] [53] Ticket price 88.10. Going to GetCart1.
    10:21:32,845 INFO [log] [56] Ticket price 78.20. Going to GetCart1.
    10:21:32,873 INFO [log] [58] Delivery exists. Going to GetMethodsofPayment.
    10:21:32,983 INFO [log] [62] GetCart1 Complete. Going to GetUpsells
    10:21:33,161 INFO [log] [58] GetMethodsOfPayment Complete. Going to CancelCart
    10:21:33,380 INFO [log] [53] GetCart1 Complete. Going to GetUpsells
    10:21:33,406 INFO [log] [58] CancelCart complete. Going to Delay6 and then GetClearedCart.
    10:21:33,522 INFO [log] [62] Upsell e1852138b38658c7b9c7290280ccef8a stored. Going to Delay4.
    10:21:34,180 INFO [log] [53] Upsell fea1ad867ca2b84393fddfb23682b7af stored. Going to Delay4.
    10:21:34,632 INFO [log] [56] GetCart1 Complete. Going to GetUpsells
    10:21:34,811 INFO [log] [58] AddTicketCancelCart completed in 21.657 seconds with status [FINISHED].
    10:21:34,914 INFO [log] [56] No upsells available for event. Going to Delay5.
    10:21:36,381 INFO [log] [56] GetCart2 Complete. Going to GetDeliveryInstruction
    10:21:36,666 INFO [log] [56] Going to addDeliveryInstruction
    10:21:37,653 INFO [log] [56] Delivery exists. Going to GetMethodsofPayment.
    10:21:37,913 INFO [log] [56] GetMethodsOfPayment Complete. Going to CancelCart
    10:21:37,934 INFO [log] [62] Upsell added. Going to Delay5.
    10:21:38,189 INFO [log] [56] CancelCart complete. Going to Delay6 and then GetClearedCart.
    10:21:38,886 INFO [log] [53] AddUpsell error. Going to Delay5.
    10:21:39,803 INFO [log] [62] GetCart2 Complete. Going to GetDeliveryInstruction
    10:21:39,867 INFO [log] [56] AddTicketCancelCart completed in 23.074 seconds with status [FINISHED].
    10:21:40,184 INFO [log] [62] Going to addDeliveryInstruction
    10:21:40,237 INFO [log] [53] GetCart2 Complete. Going to GetDeliveryInstruction
    10:21:40,534 INFO [log] [53] Going to addDeliveryInstruction
    10:21:42,510 INFO [log] [53] Delivery exists. Going to GetMethodsofPayment.
    10:21:42,770 INFO [log] [53] GetMethodsOfPayment Complete. Going to CancelCart
    10:21:42,993 INFO [log] [53] CancelCart complete. Going to Delay6 and then GetClearedCart.
    10:21:43,498 INFO [log] [62] Delivery exists. Going to GetMethodsofPayment.
    10:21:43,757 INFO [log] [62] GetMethodsOfPayment Complete. Going to CancelCart
    10:21:43,984 INFO [log] [62] CancelCart complete. Going to Delay6 and then GetClearedCart.
    10:21:44,574 INFO [log] [53] AddTicketCancelCart completed in 29.196 seconds with status [FINISHED].
    10:21:45,209 INFO [log] [62] AddTicketCancelCart completed in 26.361 seconds with status [FINISHED].


    Everything is going through very smoothly. Thank you for your help with this.
  • Sorry to inform this issue is still happening in last version (1.5.0):

    11:24:56,396 INFO [ControllerImpl] Client connected
    11:25:13,445 INFO [ControllerImpl] Loading SceneItem 50c9543f-0903-45a8-9c09-072200602a5f
    11:25:13,911 INFO [HttpClientSupport$Helper] Updating keyStore..
    11:25:13,912 INFO [HttpClientSupport$Helper] Updating keyStore..
    11:25:14,597 INFO [ControllerImpl] Started scene: initialization
    11:25:20,019 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775800 dropped!
    11:25:24,992 INFO [ControllerImpl] Client disconnected
    11:25:24,992 INFO [ControllerImpl] Stopping scene: initialization
    11:25:25,022 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775797 dropped!
    11:25:25,839 INFO [ControllerImpl] Client connected
    11:25:30,025 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775795 dropped!
    11:25:30,998 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775808 dropped!
    11:25:30,998 INFO [ControllerImpl] Loading SceneItem 50c9543f-0903-45a8-9c09-072200602a5f
    11:25:31,483 INFO [HttpClientSupport$Helper] Updating keyStore..
    11:25:31,483 INFO [HttpClientSupport$Helper] Updating keyStore..
    11:25:32,079 INFO [ControllerImpl] Started scene: initialization
    11:25:35,027 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775793 dropped!
    11:25:37,544 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775709 dropped!
    11:25:40,029 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775790 dropped!
    11:25:42,917 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775701 dropped!
    11:25:45,031 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775787 dropped!
    11:25:50,033 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775785 dropped!
    11:25:55,036 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775783 dropped!
    11:26:00,040 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775781 dropped!
    11:26:05,043 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775778 dropped!
    11:26:36,569 ERROR [BayeuxServiceServerEndpoint] Message with SEQ: -9223372036854775708 dropped!


    Apart from these message, the simple project I'm using looks like stuck (Fixed rate doesn't seem to throw request to the agent or they get lost).

    Any additional information just contact me.

    Best regards,

    Alejandro.
  • twinkiman's avatar
    twinkiman
    Occasional Contributor
    I am also experiencing the same problems with the latest nightly builds.