I debugged the issue yesterday. In the build.xml, the sleep time between the
service and reference is only 3 seconds so the reference fails as the
service is fully started yet. We have code to check if the RMI registry is
available by calling the "lookup" method which may take up to 15 seconds
before timeout. We can increase the sleep time to 20 seconds as a
workaround. Ideally, we need to find a way to control the timeout of RMI
calls.
Thanks,
Raymond
--------------------------------------------------
From: "Apache Hudson Server" <[email protected]>
Sent: Sunday, August 09, 2009 6:49 PM
To: <[email protected]>
Subject: Build failed in Hudson: Tuscany-2x » Apache Tuscany SCA iTest
Distribution calculator-rmi #177
See
http://hudson.zones.apache.org/hudson/job/Tuscany-2x/org.apache.tuscany.sca$itest-distribution-calculator-rmi/177/
------------------------------------------
[INFO] ------------------------------------------------------------------------
[INFO] Building Apache Tuscany SCA iTest Distribution calculator-rmi
[INFO] task-segment: [clean, install]
[INFO] ------------------------------------------------------------------------
[INFO] [clean:clean]
[INFO] Deleting directory
http://hudson.zones.apache.org/hudson/job/Tuscany-2x/org.apache.tuscany.sca$itest-distribution-calculator-rmi/ws/target
[INFO] [resources:resources]
[INFO] Using default encoding to copy filtered resources.
[INFO] [compiler:compile]
[INFO] No sources to compile
[INFO] [resources:testResources]
[INFO] Using default encoding to copy filtered resources.
[INFO] [compiler:testCompile]
[INFO] No sources to compile
[INFO] [surefire:test]
[INFO] No tests to run.
[HUDSON] Recording test results
[INFO] [jar:jar]
[INFO] Building jar:
http://hudson.zones.apache.org/hudson/job/Tuscany-2x/org.apache.tuscany.sca$itest-distribution-calculator-rmi/ws/target/itest-distribution-calculator-rmi-2.0-SNAPSHOT.jar
[INFO] [antrun:run {execution: run-samples}]
[INFO] Executing tasks
run:
init:
[mkdir] Created dir:
/export/home/hudson/hudson/jobs/Tuscany-2x/workspace/sca/distribution/all/target/apache-tuscany-sca-all-2.0-SNAPSHOT-dir/tuscany-sca-2.0-SNAPSHOT/samples/calculator-rmi-service/target/classes
compile:
[javac] Compiling 12 source files to
/export/home/hudson/hudson/jobs/Tuscany-2x/workspace/sca/distribution/all/target/apache-tuscany-sca-all-2.0-SNAPSHOT-dir/tuscany-sca-2.0-SNAPSHOT/samples/calculator-rmi-service/target/classes
init:
[mkdir] Created dir:
/export/home/hudson/hudson/jobs/Tuscany-2x/workspace/sca/distribution/all/target/apache-tuscany-sca-all-2.0-SNAPSHOT-dir/tuscany-sca-2.0-SNAPSHOT/samples/calculator-rmi-reference/target/classes
compile:
[javac] Compiling 7 source files to
/export/home/hudson/hudson/jobs/Tuscany-2x/workspace/sca/distribution/all/target/apache-tuscany-sca-all-2.0-SNAPSHOT-dir/tuscany-sca-2.0-SNAPSHOT/samples/calculator-rmi-reference/target/classes
[copy] Copying 2 files to
/export/home/hudson/hudson/jobs/Tuscany-2x/workspace/sca/distribution/all/target/apache-tuscany-sca-all-2.0-SNAPSHOT-dir/tuscany-sca-2.0-SNAPSHOT/samples/calculator-rmi-service/target/classes
[jar] Building jar:
/export/home/hudson/hudson/jobs/Tuscany-2x/workspace/sca/distribution/all/target/apache-tuscany-sca-all-2.0-SNAPSHOT-dir/tuscany-sca-2.0-SNAPSHOT/samples/calculator-rmi-service/target/sample-calculator-rmi-service.jar
run:
[copy] Copying 1 file to
/export/home/hudson/hudson/jobs/Tuscany-2x/workspace/sca/distribution/all/target/apache-tuscany-sca-all-2.0-SNAPSHOT-dir/tuscany-sca-2.0-SNAPSHOT/samples/calculator-rmi-reference/target/classes
[jar] Building jar:
/export/home/hudson/hudson/jobs/Tuscany-2x/workspace/sca/distribution/all/target/apache-tuscany-sca-all-2.0-SNAPSHOT-dir/tuscany-sca-2.0-SNAPSHOT/samples/calculator-rmi-reference/target/sample-calculator-rmi-reference.jar
run:
[java] Aug 10, 2009 1:47:26 AM
org.apache.tuscany.sca.node.impl.NodeImpl start
[java] INFO: Starting node:
http://tuscany.apache.org/sca/1.1/nodes/default0 domain:
tuscany.apache.org
[java] Aug 10, 2009 1:47:26 AM
org.apache.tuscany.sca.node.impl.NodeImpl start
[java] INFO: Starting node:
http://tuscany.apache.org/sca/1.1/nodes/default0 domain:
tuscany.apache.org
[java] 2009-08-10 01:47:29.622::INFO: Logging to STDERR via
org.mortbay.log.StdErrLog
[java] 2009-08-10 01:47:33.158::INFO: Logging to STDERR via
org.mortbay.log.StdErrLog
[java] Aug 10, 2009 1:47:36 AM
org.apache.tuscany.sca.node.impl.NodeFactoryImpl loadContributions
[java] INFO: Loading contribution:
file:/zonestorage/hudson/home/hudson/hudson/jobs/Tuscany-2x/workspace/sca/distribution/all/target/apache-tuscany-sca-all-2.0-SNAPSHOT-dir/tuscany-sca-2.0-SNAPSHOT/samples/calculator-rmi-reference/target/sample-calculator-rmi-reference.jar
[java] Aug 10, 2009 1:47:37 AM
org.apache.tuscany.sca.node.impl.NodeFactoryImpl loadContributions
[java] INFO: Loading contribution:
file:/zonestorage/hudson/home/hudson/hudson/jobs/Tuscany-2x/workspace/sca/distribution/all/target/apache-tuscany-sca-all-2.0-SNAPSHOT-dir/tuscany-sca-2.0-SNAPSHOT/samples/calculator-rmi-service/target/sample-calculator-rmi-service.jar
[java] Aug 10, 2009 1:47:57 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl addEndpoint
[java] INFO: Add endpoint - (@13218198)Endpoint: URI =
CalculatorServiceComponent#service-binding(CalculatorService/CalculatorService)
[java] Aug 10, 2009 1:47:57 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl
addEndpointReference
[java] INFO: Add endpoint reference - (@27916412)EndpointReference:
URI = CalculatorServiceComponent#reference-binding(addService/addService)
RESOLVED_BINDING Target = (@33083972)Endpoint:
[java] Aug 10, 2009 1:47:58 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl
addEndpointReference
[java] INFO: Add endpoint reference - (@18227730)EndpointReference:
URI =
CalculatorServiceComponent#reference-binding(multiplyService/multiplyService)
RESOLVED_BINDING Target = (@1497769)Endpoint:
[java] Aug 10, 2009 1:47:58 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl
addEndpointReference
[java] INFO: Add endpoint reference - (@7182746)EndpointReference:
URI =
CalculatorServiceComponent#reference-binding(divideService/divideService)
RESOLVED_BINDING Target = (@25120699)Endpoint:
[java] Aug 10, 2009 1:47:58 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl
addEndpointReference
[java] INFO: Add endpoint reference - (@21731956)EndpointReference:
URI =
CalculatorServiceComponent#reference-binding(subtractService/subtractService)
RESOLVED_BINDING Target = (@8993129)Endpoint:
[java] Aug 10, 2009 1:48:03 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl
addEndpointReference
[java] INFO: Add endpoint reference - (@1690810)EndpointReference:
URI =
CalculatorServiceComponent#reference-binding($self$.CalculatorService/CalculatorService)
WIRED_TARGET_FOUND_AND_MATCHED Target = (@13218198)Endpoint: URI =
CalculatorServiceComponent#service-binding(CalculatorService/CalculatorService)
[java] Exception in thread "main"
java.lang.reflect.InvocationTargetException
[java] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[java] at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[java] at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[java] at java.lang.reflect.Method.invoke(Method.java:597)
[java] at
org.apache.tuscany.sca.launcher.LauncherMain.invokeMainMethod(LauncherMain.java:114)
[java] at
org.apache.tuscany.sca.launcher.LauncherMain.main(LauncherMain.java:55)
[java] Caused by:
org.apache.tuscany.sca.host.rmi.RMIHostRuntimeException: Connection
refused to host: localhost; nested exception is:
[java] java.net.ConnectException: Connection refused
[java] at
sun.rmi.transport.tcp.TCPEndpoint.newSocket(TCPEndpoint.java:601)
[java] at
sun.rmi.transport.tcp.TCPChannel.createConnection(TCPChannel.java:198)
[java] at
sun.rmi.transport.tcp.TCPChannel.newConnection(TCPChannel.java:184)
[java] at sun.rmi.server.UnicastRef.newCall(UnicastRef.java:322)
[java] at sun.rmi.registry.RegistryImpl_Stub.lookup(Unknown Source)
[java] at
org.apache.tuscany.sca.host.rmi.DefaultRMIHost.findService(DefaultRMIHost.java:111)
[java] at
org.apache.tuscany.sca.host.rmi.ExtensibleRMIHost.findService(ExtensibleRMIHost.java:56)
[java] at
org.apache.tuscany.sca.binding.rmi.provider.RMIBindingInvoker.invokeTarget(RMIBindingInvoker.java:81)
[java] at
org.apache.tuscany.sca.binding.rmi.provider.RMIBindingInvoker.invoke(RMIBindingInvoker.java:54)
[java] at
org.apache.tuscany.sca.core.invocation.impl.JDKInvocationHandler.invoke(JDKInvocationHandler.java:277)
[java] at
org.apache.tuscany.sca.core.invocation.impl.JDKInvocationHandler.invoke(JDKInvocationHandler.java:142)
[java] at $Proxy6.add(Unknown Source)
[java] at
calculator.CalculatorServiceImpl.add(CalculatorServiceImpl.java:54)
[java] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[java] at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[java] at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[java] at java.lang.reflect.Method.invoke(Method.java:597)
[java] at
org.apache.tuscany.sca.implementation.java.invocation.JavaImplementationInvoker.invoke(JavaImplementationInvoker.java:136)
[java] at
org.apache.tuscany.sca.core.databinding.wire.PassByValueInterceptor.invoke(PassByValueInterceptor.java:61)
[java] at
org.apache.tuscany.sca.binding.sca.provider.SCABindingInvoker.invoke(SCABindingInvoker.java:61)
[java] at
org.apache.tuscany.sca.core.databinding.wire.PassByValueInterceptor.invoke(PassByValueInterceptor.java:61)
[java] at
org.apache.tuscany.sca.core.invocation.impl.JDKInvocationHandler.invoke(JDKInvocationHandler.java:277)
[java] at
org.apache.tuscany.sca.core.invocation.impl.JDKInvocationHandler.invoke(JDKInvocationHandler.java:142)
[java] at $Proxy5.add(Unknown Source)
[java] at calculator.CalculatorClient.main(CalculatorClient.java:40)
[java] ... 6 more
[java] Aug 10, 2009 1:48:10 AM
org.apache.tuscany.sca.host.rmi.DefaultRMIHost registerService
[java] INFO: RMI service registered:
rmi://localhost:8099/CalculatorRMIService
[java] Aug 10, 2009 1:48:10 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl addEndpoint
[java] INFO: Add endpoint - (@8604923)Endpoint: URI =
CalculatorServiceComponent#service-binding(CalculatorService/CalculatorService)
[java] Aug 10, 2009 1:48:10 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl
addEndpointReference
[java] INFO: Add endpoint reference - (@3346361)EndpointReference:
URI = CalculatorServiceComponent#reference(addService)
WIRED_TARGET_FOUND_READY_FOR_MATCHING Target = (@5068149)Endpoint: URI =
AddServiceComponent#service(AddServiceImpl) [Unresolved]
[java] Aug 10, 2009 1:48:11 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl
addEndpointReference
[java] INFO: Add endpoint reference - (@8966937)EndpointReference:
URI = CalculatorServiceComponent#reference(multiplyService)
WIRED_TARGET_FOUND_READY_FOR_MATCHING Target = (@14366884)Endpoint: URI
= MultiplyServiceComponent#service(MultiplyServiceImpl) [Unresolved]
[java] Aug 10, 2009 1:48:11 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl
addEndpointReference
[java] INFO: Add endpoint reference - (@6529454)EndpointReference:
URI = CalculatorServiceComponent#reference(divideService)
WIRED_TARGET_FOUND_READY_FOR_MATCHING Target = (@17549717)Endpoint: URI
= DivideServiceComponent#service(DivideServiceImpl) [Unresolved]
[java] Aug 10, 2009 1:48:11 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl
addEndpointReference
[java] INFO: Add endpoint reference - (@14650132)EndpointReference:
URI = CalculatorServiceComponent#reference(subtractService)
WIRED_TARGET_FOUND_READY_FOR_MATCHING Target = (@2347147)Endpoint: URI =
SubtractServiceComponent#service(SubtractServiceImpl) [Unresolved]
[java] Aug 10, 2009 1:48:11 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl addEndpoint
[java] INFO: Add endpoint - (@22056753)Endpoint: URI =
AddServiceComponent#service-binding(AddServiceImpl/AddServiceImpl)
[java] Aug 10, 2009 1:48:11 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl addEndpoint
[java] INFO: Add endpoint - (@32045680)Endpoint: URI =
SubtractServiceComponent#service-binding(SubtractServiceImpl/SubtractServiceImpl)
[java] Aug 10, 2009 1:48:11 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl addEndpoint
[java] INFO: Add endpoint - (@9564382)Endpoint: URI =
MultiplyServiceComponent#service-binding(MultiplyServiceImpl/MultiplyServiceImpl)
[java] Aug 10, 2009 1:48:11 AM
org.apache.tuscany.sca.endpoint.impl.EndpointRegistryImpl addEndpoint
[java] INFO: Add endpoint - (@22844058)Endpoint: URI =
DivideServiceComponent#service-binding(DivideServiceImpl/DivideServiceImpl)
[java] Hit enter to stop node...
[HUDSON] Archiving
http://hudson.zones.apache.org/hudson/job/Tuscany-2x/org.apache.tuscany.sca$itest-distribution-calculator-rmi/ws/pom.xml
to
/export/home/hudson/hudson/jobs/Tuscany-2x/modules/org.apache.tuscany.sca$itest-distribution-calculator-rmi/builds/2009-08-10_00-43-33/archive/org.apache.tuscany.sca/itest-distribution-calculator-rmi/2.0-SNAPSHOT/pom.xml
[HUDSON] Archiving
http://hudson.zones.apache.org/hudson/job/Tuscany-2x/org.apache.tuscany.sca$itest-distribution-calculator-rmi/ws/target/itest-distribution-calculator-rmi-2.0-SNAPSHOT.jar
to
/export/home/hudson/hudson/jobs/Tuscany-2x/modules/org.apache.tuscany.sca$itest-distribution-calculator-rmi/builds/2009-08-10_00-43-33/archive/org.apache.tuscany.sca/itest-distribution-calculator-rmi/2.0-SNAPSHOT/itest-distribution-calculator-rmi-2.0-SNAPSHOT.jar
[INFO] ------------------------------------------------------------------------
[ERROR] BUILD ERROR
[INFO] ------------------------------------------------------------------------
[INFO] An Ant BuildException has occured: The following error occurred
while executing this line:
http://hudson.zones.apache.org/hudson/job/Tuscany-2x/org.apache.tuscany.sca$itest-distribution-calculator-rmi/ws/build.xml
:44: The following error occurred while executing this line:
/export/home/hudson/hudson/jobs/Tuscany-2x/workspace/sca/distribution/all/target/apache-tuscany-sca-all-2.0-SNAPSHOT-dir/tuscany-sca-2.0-SNAPSHOT/samples/calculator-rmi-reference/build.xml:59:
Java returned: 1
[INFO] ------------------------------------------------------------------------
[INFO] For more information, run Maven with the -e switch
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 64 minutes 38 seconds
[INFO] Finished at: Mon Aug 10 01:48:26 UTC 2009
